Skip to content

Commit 36ebc73

Browse files
[test optimization] Use real timers in test framework instrumentations (#7971)
1 parent 8f81db6 commit 36ebc73

17 files changed

Lines changed: 263 additions & 14 deletions

File tree

Lines changed: 22 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,22 @@
1+
'use strict'
2+
3+
const assert = require('assert')
4+
const sinon = require('sinon')
5+
6+
const sum = require('./dependency')
7+
8+
describe('dynamic-instrumentation-fake-timers', () => {
9+
let clock
10+
11+
beforeEach(function () {
12+
clock = sinon.useFakeTimers()
13+
})
14+
15+
afterEach(function () {
16+
clock.restore()
17+
})
18+
19+
it('retries with DI and fake timers', function () {
20+
assert.strictEqual(sum(11, 3), 14)
21+
})
22+
})
Lines changed: 25 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,25 @@
1+
'use strict'
2+
3+
const assert = require('assert')
4+
const { When, Then, BeforeAll, AfterAll } = require('@cucumber/cucumber')
5+
const sinon = require('sinon')
6+
const sum = require('../../features-di/support/sum')
7+
8+
let clock
9+
10+
BeforeAll(function () {
11+
clock = sinon.useFakeTimers()
12+
})
13+
14+
AfterAll(function () {
15+
clock.restore()
16+
})
17+
18+
When('the greeter says hello', function () {
19+
this.whatIHeard = 'hello'
20+
})
21+
22+
Then('I should have heard {string}', function (expectedResponse) {
23+
sum(11, 3)
24+
assert.equal(this.whatIHeard, expectedResponse)
25+
})
Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,6 @@
1+
2+
Feature: Greeting with fake timers
3+
4+
Scenario: Say hello with fake timers
5+
When the greeter says hello
6+
Then I should have heard "hello"
Lines changed: 26 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,26 @@
1+
'use strict'
2+
3+
const assert = require('assert')
4+
5+
describe('test-fake-timers', () => {
6+
beforeAll(() => {
7+
jest.useFakeTimers()
8+
})
9+
10+
afterEach(() => {
11+
// This pattern (from @testing-library/react's enableFakeTimers helper)
12+
// clears all pending timers after each test but BEFORE test_done fires.
13+
// If dd-trace scheduled a setTimeout in test_done, clearAllTimers
14+
// destroys it, orphaning the promise and deadlocking the process.
15+
jest.runOnlyPendingTimers()
16+
jest.clearAllTimers()
17+
})
18+
19+
afterAll(() => {
20+
jest.useRealTimers()
21+
})
22+
23+
it('can retry failed tests with fake timers', () => {
24+
assert.deepStrictEqual(1, 2)
25+
})
26+
})
Lines changed: 18 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,18 @@
1+
import { describe, test, expect, beforeAll, afterAll, vi } from 'vitest'
2+
import { sum } from './bad-sum'
3+
4+
describe('dynamic instrumentation fake timers', () => {
5+
// Install fake timers in beforeAll — they persist through test finish hooks,
6+
// which is the pattern that triggers the deadlock with DI's setTimeout.
7+
beforeAll(() => {
8+
vi.useFakeTimers()
9+
})
10+
11+
afterAll(() => {
12+
vi.useRealTimers()
13+
})
14+
15+
test('can sum with fake timers', () => {
16+
expect(sum(11, 2)).to.equal(13)
17+
})
18+
})

integration-tests/cucumber/cucumber.spec.js

Lines changed: 31 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -97,7 +97,7 @@ describe(`cucumber@${version} commonJS`, () => {
9797

9898
let cwd, receiver, childProcess, testOutput
9999

100-
useSandbox([`@cucumber/cucumber@${version}`, 'assert', 'nyc'], true)
100+
useSandbox([`@cucumber/cucumber@${version}`, 'assert', 'nyc', 'sinon'], true)
101101

102102
before(function () {
103103
cwd = sandboxCwd()
@@ -2160,6 +2160,36 @@ describe(`cucumber@${version} commonJS`, () => {
21602160
})
21612161
})
21622162

2163+
onlyLatestIt('does not hang when tests use fake timers and Failed Test Replay is enabled', async () => {
2164+
receiver.setSettings({
2165+
flaky_test_retries_enabled: true,
2166+
di_enabled: true,
2167+
})
2168+
2169+
const eventsPromise = receiver
2170+
.gatherPayloadsMaxTimeout(({ url }) => url.endsWith('/api/v2/citestcycle'), (payloads) => {
2171+
const events = payloads.flatMap(({ payload }) => payload.events)
2172+
const tests = events.filter(event => event.type === 'test').map(event => event.content)
2173+
assert.strictEqual(tests.length, 2)
2174+
const retriedTests = tests.filter(
2175+
t => t.meta[TEST_RETRY_REASON] === TEST_RETRY_REASON_TYPES.atr
2176+
)
2177+
assert.strictEqual(retriedTests.length, 1)
2178+
})
2179+
2180+
const featurePath = 'ci-visibility/features-di-fake-timers/test-hit-breakpoint.feature'
2181+
childProcess = exec(
2182+
`./node_modules/.bin/cucumber-js ${featurePath} --retry 1`,
2183+
{
2184+
cwd,
2185+
env: envVars,
2186+
}
2187+
)
2188+
2189+
const [[exitCode]] = await Promise.all([once(childProcess, 'exit'), eventsPromise])
2190+
assert.strictEqual(exitCode, 1)
2191+
})
2192+
21632193
onlyLatestIt('does not crash if the retry does not hit the breakpoint', (done) => {
21642194
receiver.setSettings({
21652195
flaky_test_retries_enabled: true,

integration-tests/jest/jest.spec.js

Lines changed: 30 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -996,6 +996,36 @@ describe(`jest@${JEST_VERSION} commonJS`, () => {
996996
}).catch(done)
997997
})
998998
})
999+
1000+
onlyLatestIt('does not hang when tests use fake timers and Failed Test Replay is enabled', async () => {
1001+
receiver.setSettings({
1002+
flaky_test_retries_enabled: true,
1003+
di_enabled: true,
1004+
})
1005+
1006+
const eventsPromise = receiver
1007+
.gatherPayloadsMaxTimeout(({ url }) => url.endsWith('/api/v2/citestcycle'), (payloads) => {
1008+
const events = payloads.flatMap(({ payload }) => payload.events)
1009+
const tests = events.filter(event => event.type === 'test').map(event => event.content)
1010+
// Must have 2 tests: 1 original + 1 ATR retry
1011+
assert.strictEqual(tests.length, 2)
1012+
const retriedTests = tests.filter(t => t.meta[TEST_IS_RETRY] === 'true')
1013+
assert.strictEqual(retriedTests.length, 1)
1014+
})
1015+
1016+
childProcess = exec(runTestsCommand, {
1017+
cwd,
1018+
env: {
1019+
...getCiVisAgentlessConfig(receiver.port),
1020+
TESTS_TO_RUN: 'jest-flaky/fake-timers-flaky-fails',
1021+
DD_CIVISIBILITY_FLAKY_RETRY_COUNT: '1',
1022+
SHOULD_CHECK_RESULTS: '1',
1023+
},
1024+
})
1025+
1026+
const [[exitCode]] = await Promise.all([once(childProcess, 'exit'), eventsPromise])
1027+
assert.strictEqual(exitCode, 1)
1028+
})
9991029
})
10001030

10011031
context('when jest is using worker threads', () => {

integration-tests/mocha/mocha.spec.js

Lines changed: 36 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -105,6 +105,7 @@ describe(`mocha@${MOCHA_VERSION}`, function () {
105105
'nyc',
106106
'mocha-each',
107107
'workerpool',
108+
'sinon',
108109
],
109110
true
110111
)
@@ -3811,6 +3812,41 @@ describe(`mocha@${MOCHA_VERSION}`, function () {
38113812
})
38123813
})
38133814

3815+
onlyLatestIt('does not hang when tests use fake timers and Failed Test Replay is enabled', async () => {
3816+
receiver.setSettings({
3817+
flaky_test_retries_enabled: true,
3818+
di_enabled: true,
3819+
})
3820+
3821+
const eventsPromise = receiver
3822+
.gatherPayloadsMaxTimeout(({ url }) => url.endsWith('/api/v2/citestcycle'), (payloads) => {
3823+
const events = payloads.flatMap(({ payload }) => payload.events)
3824+
const tests = events.filter(event => event.type === 'test').map(event => event.content)
3825+
assert.strictEqual(tests.length, 2)
3826+
const retriedTests = tests.filter(
3827+
t => t.meta[TEST_IS_RETRY] === 'true'
3828+
)
3829+
assert.strictEqual(retriedTests.length, 1)
3830+
})
3831+
3832+
childProcess = exec(
3833+
runTestsCommand,
3834+
{
3835+
cwd,
3836+
env: {
3837+
...getCiVisAgentlessConfig(receiver.port),
3838+
TESTS_TO_RUN: JSON.stringify([
3839+
'./dynamic-instrumentation/fake-timers-test-hit-breakpoint',
3840+
]),
3841+
DD_CIVISIBILITY_FLAKY_RETRY_COUNT: '1',
3842+
},
3843+
}
3844+
)
3845+
3846+
const [[exitCode]] = await Promise.all([once(childProcess, 'exit'), eventsPromise])
3847+
assert.strictEqual(exitCode, 0)
3848+
})
3849+
38143850
it('tags new tests with dynamic names and logs a warning', async () => {
38153851
receiver.setKnownTests({ mocha: {} })
38163852
receiver.setSettings({

integration-tests/vitest/vitest.spec.js

Lines changed: 31 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1639,6 +1639,37 @@ versions.forEach((version) => {
16391639
}).catch(done)
16401640
})
16411641
})
1642+
1643+
it('does not hang when tests use fake timers and Failed Test Replay is enabled', async () => {
1644+
receiver.setSettings({
1645+
flaky_test_retries_enabled: true,
1646+
di_enabled: true,
1647+
})
1648+
1649+
const eventsPromise = receiver
1650+
.gatherPayloadsMaxTimeout(({ url }) => url === '/api/v2/citestcycle', (payloads) => {
1651+
const events = payloads.flatMap(({ payload }) => payload.events)
1652+
const tests = events.filter(event => event.type === 'test').map(event => event.content)
1653+
assert.strictEqual(tests.length, 2)
1654+
const retriedTests = tests.filter(t => t.meta[TEST_IS_RETRY] === 'true')
1655+
assert.strictEqual(retriedTests.length, 1)
1656+
})
1657+
1658+
childProcess = exec(
1659+
'./node_modules/.bin/vitest run --retry=1',
1660+
{
1661+
cwd,
1662+
env: {
1663+
...getCiVisAgentlessConfig(receiver.port),
1664+
TEST_DIR: 'ci-visibility/vitest-tests/fake-timers-di*',
1665+
NODE_OPTIONS: '--import dd-trace/register.js -r dd-trace/ci/init',
1666+
},
1667+
}
1668+
)
1669+
1670+
const [[exitCode]] = await Promise.all([once(childProcess, 'exit'), eventsPromise])
1671+
assert.strictEqual(exitCode, 1)
1672+
})
16421673
})
16431674
}
16441675

packages/datadog-instrumentations/src/jest.js

Lines changed: 5 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,8 @@
11
'use strict'
22

3+
// Capture real timers at module load time, before any test can install fake timers.
4+
const realSetTimeout = setTimeout
5+
36
const path = require('path')
47
const shimmer = require('../../datadog-shimmer')
58
const log = require('../../dd-trace/src/log')
@@ -781,7 +784,7 @@ function getWrappedEnvironment (BaseEnvironment, jestVersion) {
781784
// This means that tests retried with DI are BREAKPOINT_HIT_GRACE_PERIOD_MS slower at least.
782785
if (status === 'fail' && mightHitBreakpoint) {
783786
await new Promise(resolve => {
784-
setTimeout(() => {
787+
realSetTimeout(() => {
785788
resolve()
786789
}, BREAKPOINT_HIT_GRACE_PERIOD_MS)
787790
})
@@ -1351,7 +1354,7 @@ function getCliWrapper (isNewJestVersion) {
13511354
})
13521355

13531356
const timeoutPromise = new Promise((resolve) => {
1354-
timeoutId = setTimeout(() => {
1357+
timeoutId = realSetTimeout(() => {
13551358
resolve('timeout')
13561359
}, FLUSH_TIMEOUT).unref()
13571360
})

0 commit comments

Comments
 (0)