diff --git a/test/js/bun/test/test-timers-dns-resolver-fixture.ts b/test/js/bun/test/test-timers-dns-resolver-fixture.ts new file mode 100644 index 000000000000..80838e89f179 --- /dev/null +++ b/test/js/bun/test/test-timers-dns-resolver-fixture.ts @@ -0,0 +1,68 @@ +import { afterAll, beforeAll, jest, test } from "bun:test"; +import dgram from "node:dgram"; +import { promises as dnsPromises } from "node:dns"; +import { once } from "node:events"; + +// c-ares expires queries on its own real clock; Bun's per-resolver poll timer +// (EventLoopTimer tag DNSResolver) only exists to call back into c-ares so it +// notices. Both tests run with fake timers installed and print one JSON line +// each, which test-timers.test.ts asserts on. + +// Nothing answers on this port, so a query stays in flight until c-ares gives +// up on it or it is cancelled. +const server = dgram.createSocket("udp4"); +let nameserver: string; + +beforeAll(async () => { + server.bind(0, "127.0.0.1"); + await once(server, "listening"); + nameserver = `127.0.0.1:${server.address().port}`; +}); + +afterAll(() => server.close()); + +test("runAllTimers() returns while a query is in flight", async () => { + // With the poll timer in the fake heap, every pop re-arms it one fake second + // later and runAllTimers() spins until c-ares gives the query up, so keep the + // query alive well past the parent's spawn timeout: c-ares caps a single try + // at 5s (MAX_TIMEOUT_MS in ares_metrics.c), hence the retries. + const resolver = new dnsPromises.Resolver({ timeout: 5_000, tries: 10 }); + resolver.setServers([nameserver]); + + jest.useFakeTimers(); + try { + const outcome = resolver.resolve4("silent.test").then( + () => "resolved", + e => e.code, + ); + const timerCount = jest.getTimerCount(); + jest.runAllTimers(); + resolver.cancel(); + console.log(JSON.stringify({ test: "runAllTimers", timerCount, outcome: await outcome })); + } finally { + jest.useRealTimers(); + } +}); + +test("the poll timer is armed against the real clock", async () => { + const resolver = new dnsPromises.Resolver({ timeout: 100, tries: 1 }); + resolver.setServers([nameserver]); + + jest.useFakeTimers(); + try { + // Same trick as test-timers-gc-spin-fixture.ts: push the mocked monotonic + // clock past any plausible machine uptime. A deadline derived from it would + // sit years out in the real heap and the query would never be failed. + for (let i = 0; i < 100; i++) jest.advanceTimersByTime(40 * 24 * 3600 * 1000); + + // Fake time stands still from here on, so the rejection has to come from + // the poll timer firing on the real clock. + const outcome = await resolver.resolve4("silent.test").then( + () => "resolved", + e => e.code, + ); + console.log(JSON.stringify({ test: "realClock", outcome })); + } finally { + jest.useRealTimers(); + } +}); diff --git a/test/js/bun/test/test-timers.test.ts b/test/js/bun/test/test-timers.test.ts index 8d40f210634c..3dc7a5d34342 100644 --- a/test/js/bun/test/test-timers.test.ts +++ b/test/js/bun/test/test-timers.test.ts @@ -1,4 +1,7 @@ import { bunEnv, bunExe } from "harness"; +import dgram from "node:dgram"; +import { promises as dnsPromises } from "node:dns"; +import { once } from "node:events"; import path from "node:path"; test("we can go back in time", () => { @@ -114,3 +117,70 @@ test("real timer heap is ticked against the real clock under useFakeTimers", asy expect(proc.signalCode).toBeNull(); expect(exitCode).toBe(0); }); + +describe("c-ares poll timer under useFakeTimers", () => { + test("an in-flight dns.resolve*() query is not counted, and survives useRealTimers()", async () => { + // Nothing answers on this port, so the query stays in flight until c-ares + // times it out (c-ares floors the timeout at 250ms; the poll runs every 1s). + const server = dgram.createSocket("udp4"); + server.bind(0, "127.0.0.1"); + await once(server, "listening"); + try { + const resolver = new dnsPromises.Resolver({ timeout: 100, tries: 1 }); + resolver.setServers([`127.0.0.1:${server.address().port}`]); + + let outcome: Promise; + let timerCount: number; + jest.useFakeTimers(); + try { + outcome = resolver.resolve4("silent.test").then( + () => "resolved", + e => e.code, + ); + timerCount = jest.getTimerCount(); + } finally { + jest.useRealTimers(); + } + expect(timerCount).toBe(0); + + // useRealTimers() discarded every node in the fake heap. Pre-fix the poll + // timer was one of them and this query stayed pending forever. + expect(await outcome).toBe("ETIMEOUT"); + } finally { + server.close(); + } + }); + + // A passing child spends about a second of real time waiting for ETIMEOUT on + // top of its startup; pre-fix it never gets out of runAllTimers() (100% CPU) + // and has to be reaped by the spawn timeout before the test's own timeout. + const childTimeout = 20_000; + const testTimeout = 30_000; + + test( + "runAllTimers() returns, and the query still times out on the real clock", + async () => { + await using proc = Bun.spawn({ + cmd: [bunExe(), "test", path.join(import.meta.dir, "test-timers-dns-resolver-fixture.ts")], + env: bunEnv, + stdout: "pipe", + stderr: "pipe", + timeout: childTimeout, + }); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); + if (exitCode !== 0) console.error(stderr); + const results = stdout + .split("\n") + .filter(line => line.startsWith("{")) + .map(line => JSON.parse(line)); + expect(results).toEqual([ + { test: "runAllTimers", timerCount: 0, outcome: "ECANCELLED" }, + { test: "realClock", outcome: "ETIMEOUT" }, + ]); + // null => exited on its own; non-null => killed by the spawn timeout (spun). + expect(proc.signalCode).toBeNull(); + expect(exitCode).toBe(0); + }, + testTimeout, + ); +});