From 8a09d77037024b80e4efc6df53bf8cd1d36b14eb Mon Sep 17 00:00:00 2001 From: Aras Abbasi Date: Tue, 27 Aug 2024 17:07:05 +0200 Subject: [PATCH] fix: refactor fast timers, fix UND_ERR_CONNECT_TIMEOUT on event loop blocking (#3495) * fix: refactor fast timers, fix UND_ERR_CONNECT_TIMEOUT on event loop blocking * also test native timers * improve the commentary of fasttimers * revert changes in client-h1.js * make fasttimers independent from performance.now * less flaky? --- benchmarks/timers/compare-timer-getters.mjs | 18 + lib/core/connect.js | 63 ++-- lib/dispatcher/client-h1.js | 14 +- lib/util/timers.js | 368 +++++++++++++++++--- test/issue-3410.js | 88 +++++ test/socket-timeout.js | 7 - test/timers.js | 198 +++++++++++ test/util.js | 78 ----- test/utils/event-loop-blocker.js | 10 + test/utils/hello-world-server.js | 30 ++ 10 files changed, 714 insertions(+), 160 deletions(-) create mode 100644 benchmarks/timers/compare-timer-getters.mjs create mode 100644 test/issue-3410.js create mode 100644 test/timers.js create mode 100644 test/utils/event-loop-blocker.js create mode 100644 test/utils/hello-world-server.js diff --git a/benchmarks/timers/compare-timer-getters.mjs b/benchmarks/timers/compare-timer-getters.mjs new file mode 100644 index 00000000000..aadff558f1f --- /dev/null +++ b/benchmarks/timers/compare-timer-getters.mjs @@ -0,0 +1,18 @@ +import { bench, group, run } from 'mitata' + +group('timers', () => { + bench('Date.now()', () => { + Date.now() + }) + bench('performance.now()', () => { + performance.now() + }) + bench('Math.trunc(performance.now())', () => { + Math.trunc(performance.now()) + }) + bench('process.uptime()', () => { + process.uptime() + }) +}) + +await run() diff --git a/lib/core/connect.js b/lib/core/connect.js index b388f022298..e40fb90d81c 100644 --- a/lib/core/connect.js +++ b/lib/core/connect.js @@ -4,6 +4,7 @@ const net = require('node:net') const assert = require('node:assert') const util = require('./util') const { InvalidArgumentError, ConnectTimeoutError } = require('./errors') +const timers = require('../util/timers') let tls // include tls conditionally since it is not always available @@ -130,12 +131,12 @@ function buildConnector ({ allowH2, maxCachedSessions, socketPath, timeout, sess socket.setKeepAlive(true, keepAliveInitialDelay) } - const cancelTimeout = setupTimeout(() => onConnectTimeout(socket), timeout) + const cancelConnectTimeout = setupConnectTimeout(new WeakRef(socket), timeout) socket .setNoDelay(true) .once(protocol === 'https:' ? 'secureConnect' : 'connect', function () { - cancelTimeout() + cancelConnectTimeout() if (callback) { const cb = callback @@ -144,7 +145,7 @@ function buildConnector ({ allowH2, maxCachedSessions, socketPath, timeout, sess } }) .on('error', function (err) { - cancelTimeout() + cancelConnectTimeout() if (callback) { const cb = callback @@ -157,30 +158,44 @@ function buildConnector ({ allowH2, maxCachedSessions, socketPath, timeout, sess } } -function setupTimeout (onConnectTimeout, timeout) { - if (!timeout) { - return () => {} - } +const setupConnectTimeout = process.platform === 'win32' + ? (socket, timeout) => { + if (!timeout) { + return () => { } + } - let s1 = null - let s2 = null - const timeoutId = setTimeout(() => { - // setImmediate is added to make sure that we prioritize socket error events over timeouts - s1 = setImmediate(() => { - if (process.platform === 'win32') { + let s1 = null + let s2 = null + const timer = timers.setTimeout(() => { + // setImmediate is added to make sure that we prioritize socket error events over timeouts + s1 = setImmediate(() => { // Windows needs an extra setImmediate probably due to implementation differences in the socket logic - s2 = setImmediate(() => onConnectTimeout()) - } else { - onConnectTimeout() + s2 = setImmediate(() => onConnectTimeout(socket.deref())) + }) + }, timeout) + return () => { + timers.clearTimeout(timer) + clearImmediate(s1) + clearImmediate(s2) } - }) - }, timeout) - return () => { - clearTimeout(timeoutId) - clearImmediate(s1) - clearImmediate(s2) - } -} + } + : (socket, timeout) => { + if (!timeout) { + return () => { } + } + + let s1 = null + const timer = timers.setTimeout(() => { + // setImmediate is added to make sure that we prioritize socket error events over timeouts + s1 = setImmediate(() => { + onConnectTimeout(socket.deref()) + }) + }, timeout) + return () => { + timers.clearTimeout(timer) + clearImmediate(s1) + } + } function onConnectTimeout (socket) { let message = 'Connect Timeout Error' diff --git a/lib/dispatcher/client-h1.js b/lib/dispatcher/client-h1.js index fc7b962e06d..e4bcc082e7e 100644 --- a/lib/dispatcher/client-h1.js +++ b/lib/dispatcher/client-h1.js @@ -162,12 +162,12 @@ class Parser { this.maxResponseSize = client[kMaxResponseSize] } - setTimeout (value, type) { + setTimeout (delay, type) { this.timeoutType = type - if (value !== this.timeoutValue) { - timers.clearTimeout(this.timeout) - if (value) { - this.timeout = timers.setTimeout(onParserTimeout, value, new WeakRef(this)) + if (delay !== this.timeoutValue) { + this.timeout && timers.clearTimeout(this.timeout) + if (delay) { + this.timeout = timers.setTimeout(onParserTimeout, delay, new WeakRef(this)) // istanbul ignore else: only for jest if (this.timeout.unref) { this.timeout.unref() @@ -175,7 +175,7 @@ class Parser { } else { this.timeout = null } - this.timeoutValue = value + this.timeoutValue = delay } else if (this.timeout) { // istanbul ignore else: only for jest if (this.timeout.refresh) { @@ -286,7 +286,7 @@ class Parser { this.llhttp.llhttp_free(this.ptr) this.ptr = null - timers.clearTimeout(this.timeout) + this.timeout && timers.clearTimeout(this.timeout) this.timeout = null this.timeoutValue = null this.timeoutType = null diff --git a/lib/util/timers.js b/lib/util/timers.js index d0091cc15f7..8fa3ac56b7b 100644 --- a/lib/util/timers.js +++ b/lib/util/timers.js @@ -1,99 +1,379 @@ 'use strict' -const TICK_MS = 499 +/** + * This module offers an optimized timer implementation designed for scenarios + * where high precision is not critical. + * + * The timer achieves faster performance by using a low-resolution approach, + * with an accuracy target of within 500ms. This makes it particularly useful + * for timers with delays of 1 second or more, where exact timing is less + * crucial. + * + * It's important to note that Node.js timers are inherently imprecise, as + * delays can occur due to the event loop being blocked by other operations. + * Consequently, timers may trigger later than their scheduled time. + */ -let fastNow = Date.now() +const nativeSetTimeout = global.setTimeout +const nativeClearTimeout = global.clearTimeout + +/** + * The fastNow variable contains the internal fast timer clock value. + * + * @type {number} + */ +let fastNow = 0 + +/** + * RESOLUTION_MS represents the target resolution time in milliseconds. + * + * @type {number} + * @default 1000 + */ +const RESOLUTION_MS = 1e3 + +/** + * TICK_MS defines the desired interval in milliseconds between each tick. + * The target value is set to half the resolution time, minus 1 ms, to account + * for potential event loop overhead. + * + * @type {number} + * @default 499 + */ +const TICK_MS = (RESOLUTION_MS >> 1) - 1 + +/** + * fastNowTimeout is a Node.js timer used to manage and process + * the FastTimers stored in the `fastTimers` array. + * + * @type {NodeJS.Timeout} + */ let fastNowTimeout +/** + * The kFastTimer symbol is used to identify FastTimer instances. + * + * @type {Symbol} + */ +const kFastTimer = Symbol('kFastTimer') + +/** + * The fastTimers array contains all active FastTimers. + * + * @type {FastTimer[]} + */ const fastTimers = [] -function onTimeout () { - fastNow = Date.now() +/** + * These constants represent the various states of a FastTimer. + */ - let len = fastTimers.length +/** + * The `NOT_IN_LIST` constant indicates that the FastTimer is not included + * in the `fastTimers` array. Timers with this status will not be processed + * during the next tick by the `onTick` function. + * + * A FastTimer can be re-added to the `fastTimers` array by invoking the + * `refresh` method on the FastTimer instance. + * + * @type {-2} + */ +const NOT_IN_LIST = -2 + +/** + * The `TO_BE_CLEARED` constant indicates that the FastTimer is scheduled + * for removal from the `fastTimers` array. A FastTimer in this state will + * be removed in the next tick by the `onTick` function and will no longer + * be processed. + * + * This status is also set when the `clear` method is called on the FastTimer instance. + * + * @type {-1} + */ +const TO_BE_CLEARED = -1 + +/** + * The `PENDING` constant signifies that the FastTimer is awaiting processing + * in the next tick by the `onTick` function. Timers with this status will have + * their `_idleStart` value set and their status updated to `ACTIVE` in the next tick. + * + * @type {0} + */ +const PENDING = 0 + +/** + * The `ACTIVE` constant indicates that the FastTimer is active and waiting + * for its timer to expire. During the next tick, the `onTick` function will + * check if the timer has expired, and if so, it will execute the associated callback. + * + * @type {1} + */ +const ACTIVE = 1 + +/** + * The onTick function processes the fastTimers array. + * + * @returns {void} + */ +function onTick () { + /** + * Increment the fastNow value by the TICK_MS value, despite the actual time + * that has passed since the last tick. This approach ensures independence + * from the system clock and delays caused by a blocked event loop. + * + * @type {number} + */ + fastNow += TICK_MS + + /** + * The `idx` variable is used to iterate over the `fastTimers` array. + * Expired timers are removed by replacing them with the last element in the array. + * Consequently, `idx` is only incremented when the current element is not removed. + * + * @type {number} + */ let idx = 0 + + /** + * The len variable will contain the length of the fastTimers array + * and will be decremented when a FastTimer should be removed from the + * fastTimers array. + * + * @type {number} + */ + let len = fastTimers.length + while (idx < len) { + /** + * @type {FastTimer} + */ const timer = fastTimers[idx] - if (timer.state === 0) { - timer.state = fastNow + timer.delay - TICK_MS - } else if (timer.state > 0 && fastNow >= timer.state) { - timer.state = -1 - timer.callback(timer.opaque) + // If the timer is in the ACTIVE state and the timer has expired, it will + // be processed in the next tick. + if (timer._state === PENDING) { + // Set the _idleStart value to the fastNow value minus the TICK_MS value + // to account for the time the timer was in the PENDING state. + timer._idleStart = fastNow - TICK_MS + timer._state = ACTIVE + } else if ( + timer._state === ACTIVE && + fastNow >= timer._idleStart + timer._idleTimeout + ) { + timer._state = TO_BE_CLEARED + timer._idleStart = -1 + timer._onTimeout(timer._timerArg) } - if (timer.state === -1) { - timer.state = -2 - if (idx !== len - 1) { - fastTimers[idx] = fastTimers.pop() - } else { - fastTimers.pop() + if (timer._state === TO_BE_CLEARED) { + timer._state = NOT_IN_LIST + + // Move the last element to the current index and decrement len if it is + // not the only element in the array. + if (--len !== 0) { + fastTimers[idx] = fastTimers[len] } - len -= 1 } else { - idx += 1 + ++idx } } - if (fastTimers.length > 0) { + // Set the length of the fastTimers array to the new length and thus + // removing the excess FastTimers elements from the array. + fastTimers.length = len + + // If there are still active FastTimers in the array, refresh the Timer. + // If there are no active FastTimers, the timer will be refreshed again + // when a new FastTimer is instantiated. + if (fastTimers.length !== 0) { refreshTimeout() } } function refreshTimeout () { - if (fastNowTimeout?.refresh) { + // If the fastNowTimeout is already set, refresh it. + if (fastNowTimeout) { fastNowTimeout.refresh() + // fastNowTimeout is not instantiated yet, create a new Timer. } else { clearTimeout(fastNowTimeout) - fastNowTimeout = setTimeout(onTimeout, TICK_MS) + fastNowTimeout = setTimeout(onTick, TICK_MS) + + // If the Timer has an unref method, call it to allow the process to exit if + // there are no other active handles. if (fastNowTimeout.unref) { fastNowTimeout.unref() } } } -class Timeout { - constructor (callback, delay, opaque) { - this.callback = callback - this.delay = delay - this.opaque = opaque +/** + * The `FastTimer` class is a data structure designed to store and manage + * timer information. + */ +class FastTimer { + [kFastTimer] = true + + /** + * The state of the timer, which can be one of the following: + * - NOT_IN_LIST (-2) + * - TO_BE_CLEARED (-1) + * - PENDING (0) + * - ACTIVE (1) + * + * @type {-2|-1|0|1} + * @private + */ + _state = NOT_IN_LIST + + /** + * The number of milliseconds to wait before calling the callback. + * + * @type {number} + * @private + */ + _idleTimeout = -1 + + /** + * The time in milliseconds when the timer was started. This value is used to + * calculate when the timer should expire. + * + * @type {number} + * @default -1 + * @private + */ + _idleStart = -1 + + /** + * The function to be executed when the timer expires. + * @type {Function} + * @private + */ + _onTimeout + + /** + * The argument to be passed to the callback when the timer expires. + * + * @type {*} + * @private + */ + _timerArg - // -2 not in timer list - // -1 in timer list but inactive - // 0 in timer list waiting for time - // > 0 in timer list waiting for time to expire - this.state = -2 + /** + * @constructor + * @param {Function} callback A function to be executed after the timer + * expires. + * @param {number} delay The time, in milliseconds that the timer should wait + * before the specified function or code is executed. + * @param {*} arg + */ + constructor (callback, delay, arg) { + this._onTimeout = callback + this._idleTimeout = delay + this._timerArg = arg this.refresh() } + /** + * Sets the timer's start time to the current time, and reschedules the timer + * to call its callback at the previously specified duration adjusted to the + * current time. + * Using this on a timer that has already called its callback will reactivate + * the timer. + * + * @returns {void} + */ refresh () { - if (this.state === -2) { + // In the special case that the timer is not in the list of active timers, + // add it back to the array to be processed in the next tick by the onTick + // function. + if (this._state === NOT_IN_LIST) { fastTimers.push(this) - if (!fastNowTimeout || fastTimers.length === 1) { - refreshTimeout() - } } - this.state = 0 + // If the timer is the only active timer, refresh the fastNowTimeout for + // better resolution. + if (!fastNowTimeout || fastTimers.length === 1) { + refreshTimeout() + } + + // Setting the state to PENDING will cause the timer to be reset in the + // next tick by the onTick function. + this._state = PENDING } + /** + * The `clear` method cancels the timer, preventing it from executing. + * + * @returns {void} + * @private + */ clear () { - this.state = -1 + // Set the state to TO_BE_CLEARED to mark the timer for removal in the next + // tick by the onTick function. + this._state = TO_BE_CLEARED + + // Reset the _idleStart value to -1 to indicate that the timer is no longer + // active. + this._idleStart = -1 } } +/** + * This module exports a setTimeout and clearTimeout function that can be + * used as a drop-in replacement for the native functions. + */ module.exports = { - setTimeout (callback, delay, opaque) { - return delay <= 1e3 - ? setTimeout(callback, delay, opaque) - : new Timeout(callback, delay, opaque) + /** + * The setTimeout() method sets a timer which executes a function once the + * timer expires. + * @param {Function} callback A function to be executed after the timer + * expires. + * @param {number} delay The time, in milliseconds that the timer should + * wait before the specified function or code is executed. + * @param {*} [arg] An optional argument to be passed to the callback function + * when the timer expires. + * @returns {NodeJS.Timeout|FastTimer} + */ + setTimeout (callback, delay, arg) { + // If the delay is less than or equal to the RESOLUTION_MS value return a + // native Node.js Timer instance. + return delay <= RESOLUTION_MS + ? nativeSetTimeout(callback, delay, arg) + : new FastTimer(callback, delay, arg) }, + /** + * The clearTimeout method cancels an instantiated Timer previously created + * by calling setTimeout. + * + * @param {FastTimer} timeout + */ clearTimeout (timeout) { - if (timeout instanceof Timeout) { + // If the timeout is a FastTimer, call its own clear method. + if (timeout[kFastTimer]) { + /** + * @type {FastTimer} + */ timeout.clear() + // Otherwise it is an instance of a native NodeJS.Timeout, so call the + // Node.js native clearTimeout function. } else { - clearTimeout(timeout) + nativeClearTimeout(timeout) } - } + }, + /** + * The now method returns the value of the internal fast timer clock. + * + * @returns {number} + */ + now () { + return fastNow + }, + /** + * Exporting for testing purposes only. + * Marking as deprecated to discourage any use outside of testing. + * @deprecated + */ + kFastTimer } diff --git a/test/issue-3410.js b/test/issue-3410.js new file mode 100644 index 00000000000..d5bb8093ef2 --- /dev/null +++ b/test/issue-3410.js @@ -0,0 +1,88 @@ +'use strict' + +const { tspl } = require('@matteo.collina/tspl') +const { fork } = require('node:child_process') +const { resolve: pathResolve } = require('node:path') +const { describe, test } = require('node:test') +const { Agent, fetch, setGlobalDispatcher } = require('..') +const { eventLoopBlocker } = require('./utils/event-loop-blocker') + +describe('https://github.com/nodejs/undici/issues/3410', () => { + test('FastTimers', async (t) => { + t = tspl(t, { plan: 1 }) + + // Spawn a server in a new process to avoid effects from the blocking event loop + const { + serverProcess, + address + } = await new Promise((resolve, reject) => { + const childProcess = fork( + pathResolve(__dirname, './utils/hello-world-server.js'), + [], + { windowsHide: true } + ) + + childProcess.on('message', (address) => { + resolve({ + serverProcess: childProcess, + address + }) + }) + childProcess.on('error', err => { + reject(err) + }) + }) + + const connectTimeout = 2000 + setGlobalDispatcher(new Agent({ connectTimeout })) + + const fetchPromise = fetch(address) + + eventLoopBlocker(3000) + + const response = await fetchPromise + + t.equal(await response.text(), 'Hello World') + + serverProcess.kill('SIGKILL') + }) + + test('native Timers', async (t) => { + t = tspl(t, { plan: 1 }) + + // Spawn a server in a new process to avoid effects from the blocking event loop + const { + serverProcess, + address + } = await new Promise((resolve, reject) => { + const childProcess = fork( + pathResolve(__dirname, './utils/hello-world-server.js'), + [], + { windowsHide: true } + ) + + childProcess.on('message', (address) => { + resolve({ + serverProcess: childProcess, + address + }) + }) + childProcess.on('error', err => { + reject(err) + }) + }) + + const connectTimeout = 900 + setGlobalDispatcher(new Agent({ connectTimeout })) + + const fetchPromise = fetch(address) + + eventLoopBlocker(1500) + + const response = await fetchPromise + + t.equal(await response.text(), 'Hello World') + + serverProcess.kill('SIGKILL') + }) +}) diff --git a/test/socket-timeout.js b/test/socket-timeout.js index 5be62fe4119..43ee1576615 100644 --- a/test/socket-timeout.js +++ b/test/socket-timeout.js @@ -3,7 +3,6 @@ const { tspl } = require('@matteo.collina/tspl') const { test, after } = require('node:test') const { Client, errors } = require('..') -const timers = require('../lib/util/timers') const { createServer } = require('node:http') const FakeTimers = require('@sinonjs/fake-timers') @@ -68,12 +67,6 @@ test('Disable socket timeout', async (t) => { const clock = FakeTimers.install() after(clock.uninstall.bind(clock)) - const orgTimers = { ...timers } - Object.assign(timers, { setTimeout, clearTimeout }) - after(() => { - Object.assign(timers, orgTimers) - }) - server.once('request', (req, res) => { setTimeout(() => { res.end('hello') diff --git a/test/timers.js b/test/timers.js new file mode 100644 index 00000000000..621e1aa74bb --- /dev/null +++ b/test/timers.js @@ -0,0 +1,198 @@ +'use strict' + +const { tspl } = require('@matteo.collina/tspl') +const { describe, test } = require('node:test') + +const timers = require('../lib/util/timers') +const { eventLoopBlocker } = require('./utils/event-loop-blocker') + +describe('timers', () => { + test('timers exports a clearTimeout', (t) => { + t = tspl(t, { plan: 1 }) + + t.ok(typeof timers.clearTimeout === 'function') + }) + + test('timers exports a setTimeout', (t) => { + t = tspl(t, { plan: 1 }) + + t.ok(typeof timers.setTimeout === 'function') + }) + + test('setTimeout instantiates a native NodeJS.Timeout when delay is lower or equal 1e3 ms', (t) => { + t = tspl(t, { plan: 2 }) + + t.strictEqual(timers.setTimeout(() => { }, 999)[timers.kFastTimer], undefined) + t.strictEqual(timers.setTimeout(() => { }, 1e3)[timers.kFastTimer], undefined) + }) + + test('setTimeout instantiates a FastTimer when delay is smaller than 1e3 ms', (t) => { + t = tspl(t, { plan: 1 }) + + const timeout = timers.setTimeout(() => { }, 1001) + t.strictEqual(timeout[timers.kFastTimer], true) + }) + + test('clearTimeout can clear a node native Timeout', (t) => { + t = tspl(t, { plan: 3 }) + + const nativeTimeoutId = setTimeout(() => { }, 1e6) + t.equal(nativeTimeoutId._idleTimeout, 1e6) + t.ok(timers.clearTimeout(nativeTimeoutId) === undefined) + t.equal(nativeTimeoutId._idleTimeout, -1) + }) + + test('a FastTimer will get a _idleStart value after short time', async (t) => { + t = tspl(t, { plan: 3 }) + + const timer = timers.setTimeout(() => { + t.fail('timer should not have fired') + }, 1e4) + + t.strictEqual(timer[timers.kFastTimer], true) + t.strictEqual(timer._idleStart, -1) + await new Promise((resolve) => setTimeout(resolve, 750)) + t.notStrictEqual(timer._idleStart, -1) + + timers.clearTimeout(timer) + }) + + test('a cleared FastTimer will reset the _idleStart value to -1', async (t) => { + t = tspl(t, { plan: 4 }) + + const timer = timers.setTimeout(() => { + t.fail('timer should not have fired') + }, 1e4) + + t.strictEqual(timer[timers.kFastTimer], true) + t.strictEqual(timer._idleStart, -1) + await new Promise((resolve) => setTimeout(resolve, 750)) + t.notStrictEqual(timer._idleStart, -1) + timers.clearTimeout(timer) + t.strictEqual(timer._idleStart, -1) + }) + + test('a FastTimer can be cleared', async (t) => { + t = tspl(t, { plan: 3 }) + + const timer = timers.setTimeout(() => { + t.fail('timer should not have fired') + }, 1001) + + t.strictEqual(timer[timers.kFastTimer], true) + timers.clearTimeout(timer) + + t.strictEqual(timer._idleStart, -1) + await new Promise((resolve) => setTimeout(resolve, 750)) + t.strictEqual(timer._idleStart, -1) + }) + + test('a cleared FastTimer can be refreshed', async (t) => { + t = tspl(t, { plan: 2 }) + + const timer = timers.setTimeout(() => { + t.ok('pass') + }, 1001) + + t.strictEqual(timer[timers.kFastTimer], true) + timers.clearTimeout(timer) + timer.refresh() + await new Promise((resolve) => setTimeout(resolve, 2000)) + timers.clearTimeout(timer) + }) + + const getDelta = (start, target) => { + const end = process.hrtime.bigint() + const actual = (end - start) / 1_000_000n + return actual - BigInt(target) + } + + // timers.setTimeout implements a low resolution timer with a 500 ms granularity + // It is expected that in the worst case, a timer will fire about 500 ms after the + // intended amount of time, an extra 200 ms is added to account event loop overhead + // Timers should never fire excessively early, 1ms early is tolerated + const ACCEPTABLE_DELTA = 700n + + test('meet acceptable resolution time', async (t) => { + const testTimeouts = [0, 1, 499, 500, 501, 990, 999, 1000, 1001, 1100, 1400, 1499, 1500, 4000, 5000] + + t = tspl(t, { plan: 1 + testTimeouts.length * 2 }) + + const start = process.hrtime.bigint() + + for (const target of testTimeouts) { + timers.setTimeout(() => { + const delta = getDelta(start, target) + + t.ok(delta >= -1n, `${target}ms fired early`) + t.ok(delta < ACCEPTABLE_DELTA, `${target}ms fired late, got difference of ${delta}ms`) + }, target) + } + + setTimeout(() => t.ok(true), 6000) + await t.completed + }) + + test('refresh correctly with timeout < TICK_MS', async (t) => { + t = tspl(t, { plan: 3 }) + + const start = process.hrtime.bigint() + + const timeout = timers.setTimeout(() => { + // 400 ms timer was refreshed after 600ms; total target is 1000 + const delta = getDelta(start, 1000) + + t.ok(delta >= -1n, 'refreshed timer fired early') + t.ok(delta < ACCEPTABLE_DELTA, 'refreshed timer fired late') + }, 400) + + setTimeout(() => timeout.refresh(), 200) + setTimeout(() => timeout.refresh(), 400) + setTimeout(() => timeout.refresh(), 600) + + setTimeout(() => t.ok(true), 1500) + await t.completed + }) + + test('refresh correctly with timeout > TICK_MS', async (t) => { + t = tspl(t, { plan: 3 }) + + const start = process.hrtime.bigint() + + const timeout = timers.setTimeout(() => { + // 501ms timer was refreshed after 1250ms; total target is 1751 + const delta = getDelta(start, 1751) + + t.ok(delta >= -1n, 'refreshed timer fired early') + t.ok(delta < ACCEPTABLE_DELTA, 'refreshed timer fired late') + }, 501) + + setTimeout(() => timeout.refresh(), 250) + setTimeout(() => timeout.refresh(), 750) + setTimeout(() => timeout.refresh(), 1250) + + setTimeout(() => t.ok(true), 3000) + await t.completed + }) + + test('a FastTimer will only increment by the defined TICK_MS value', async (t) => { + t = tspl(t, { plan: 2 }) + + const startInternalClock = timers.now() + + // The long running FastTimer will ensure that the internal clock is + // incremented by the TICK_MS value in the onTick function + const longRunningFastTimer = timers.setTimeout(() => {}, 1e10) + + eventLoopBlocker(1000) + + // wait to ensure the timer has fired in the next loop + await new Promise((resolve) => setTimeout(resolve, 1)) + + t.strictEqual(timers.now() - startInternalClock, 499) + await new Promise((resolve) => setTimeout(resolve, 1000)) + t.ok(timers.now() - startInternalClock <= 1497) + + timers.clearTimeout(longRunningFastTimer) + }) +}) diff --git a/test/util.js b/test/util.js index f646ec4ff25..b3e1193e506 100644 --- a/test/util.js +++ b/test/util.js @@ -1,12 +1,10 @@ 'use strict' -const { tspl } = require('@matteo.collina/tspl') const { strictEqual, throws, doesNotThrow } = require('node:assert') const { test, describe } = require('node:test') const { isBlobLike, parseURL, isHttpOrHttpsPrefixed, isValidPort } = require('../lib/core/util') const { Blob, File } = require('node:buffer') const { InvalidArgumentError } = require('../lib/core/errors') -const timers = require('../lib/util/timers') describe('isBlobLike', () => { test('buffer', () => { @@ -255,79 +253,3 @@ describe('parseURL', () => { }) }) }) - -describe('timers', () => { - const getDelta = (start, target) => { - const end = process.hrtime.bigint() - const actual = (end - start) / 1_000_000n - return actual - BigInt(target) - } - - // timers.setTimeout implements a low resolution timer with a 500 ms granularity - // It is expected that in the worst case, a timer will fire about 500 ms after the - // intended amount of time, an extra 200 ms is added to account event loop overhead - // Timers should never fire excessively early, 1ms early is tolerated - const ACCEPTABLE_DELTA = 700n - - test('meet acceptable resolution time', async (t) => { - const testTimeouts = [0, 1, 499, 500, 501, 990, 999, 1000, 1001, 1100, 1400, 1499, 1500, 4000, 5000] - - t = tspl(t, { plan: 1 + testTimeouts.length * 2 }) - - const start = process.hrtime.bigint() - - for (const target of testTimeouts) { - timers.setTimeout(() => { - const delta = getDelta(start, target) - - t.ok(delta >= -1n, `${target}ms fired early`) - t.ok(delta < ACCEPTABLE_DELTA, `${target}ms fired late`) - }, target) - } - - setTimeout(() => t.ok(true), 6000) - await t.completed - }) - - test('refresh correctly with timeout < TICK_MS', async (t) => { - t = tspl(t, { plan: 3 }) - - const start = process.hrtime.bigint() - - const timeout = timers.setTimeout(() => { - // 400 ms timer was refreshed after 600ms; total target is 1000 - const delta = getDelta(start, 1000) - - t.ok(delta >= -1n, 'refreshed timer fired early') - t.ok(delta < ACCEPTABLE_DELTA, 'refreshed timer fired late') - }, 400) - - setTimeout(() => timeout.refresh(), 200) - setTimeout(() => timeout.refresh(), 400) - setTimeout(() => timeout.refresh(), 600) - - setTimeout(() => t.ok(true), 1500) - await t.completed - }) - - test('refresh correctly with timeout > TICK_MS', async (t) => { - t = tspl(t, { plan: 3 }) - - const start = process.hrtime.bigint() - - const timeout = timers.setTimeout(() => { - // 501ms timer was refreshed after 1250ms; total target is 1751 - const delta = getDelta(start, 1751) - - t.ok(delta >= -1n, 'refreshed timer fired early') - t.ok(delta < ACCEPTABLE_DELTA, 'refreshed timer fired late') - }, 501) - - setTimeout(() => timeout.refresh(), 250) - setTimeout(() => timeout.refresh(), 750) - setTimeout(() => timeout.refresh(), 1250) - - setTimeout(() => t.ok(true), 3000) - await t.completed - }) -}) diff --git a/test/utils/event-loop-blocker.js b/test/utils/event-loop-blocker.js new file mode 100644 index 00000000000..9c2ec5075f0 --- /dev/null +++ b/test/utils/event-loop-blocker.js @@ -0,0 +1,10 @@ +'use strict' + +function eventLoopBlocker (ms) { + const nil = new Int32Array(new SharedArrayBuffer(4)) + Atomics.wait(nil, 0, 0, ms) +} + +module.exports = { + eventLoopBlocker +} diff --git a/test/utils/hello-world-server.js b/test/utils/hello-world-server.js new file mode 100644 index 00000000000..520ed3a734d --- /dev/null +++ b/test/utils/hello-world-server.js @@ -0,0 +1,30 @@ +'use strict' + +const { createServer } = require('node:http') +const hostname = '127.0.0.1' + +const server = createServer(async (req, res) => { + res.statusCode = 200 + res.setHeader('Content-Type', 'text/plain') + + await sendInDelayedChunks(res, 'Hello World', 125) + res.end() +}) + +async function sendInDelayedChunks (res, payload, delay) { + const chunks = payload.split('') + + for (const chunk of chunks) { + await new Promise(resolve => setTimeout(resolve, delay)) + + res.write(chunk) + } +} + +server.listen(0, hostname, () => { + if (process.send) { + process.send(`http://${hostname}:${server.address().port}/`) + } else { + console.log(`http://${hostname}:${server.address().port}/`) + } +})