From d1b576fa0beece689f2212a2944cd7a43e2ee2f7 Mon Sep 17 00:00:00 2001 From: Matt Weber Date: Sun, 21 Apr 2024 17:53:51 -0400 Subject: [PATCH 1/4] fix: tweak keep-alive timeout implementation Closes nodejs/undici#3141 --- docs/docs/api/Client.md | 2 +- lib/dispatcher/client.js | 2 +- lib/util/timers.js | 12 +++---- test/util.js | 78 ++++++++++++++++++++++++++++++++++++++++ 4 files changed, 86 insertions(+), 8 deletions(-) diff --git a/docs/docs/api/Client.md b/docs/docs/api/Client.md index 6e21751ecab..2276f737c36 100644 --- a/docs/docs/api/Client.md +++ b/docs/docs/api/Client.md @@ -23,7 +23,7 @@ Returns: `Client` * **headersTimeout** `number | null` (optional) - Default: `300e3` - The amount of time, in milliseconds, the parser will wait to receive the complete HTTP headers while not sending the request. Defaults to 300 seconds. * **keepAliveMaxTimeout** `number | null` (optional) - Default: `600e3` - The maximum allowed `keepAliveTimeout`, in milliseconds, when overridden by *keep-alive* hints from the server. Defaults to 10 minutes. * **keepAliveTimeout** `number | null` (optional) - Default: `4e3` - The timeout, in milliseconds, after which a socket without active requests will time out. Monitors time between activity on a connected socket. This value may be overridden by *keep-alive* hints from the server. See [MDN: HTTP - Headers - Keep-Alive directives](https://developer.mozilla.org/en-US/docs/Web/HTTP/Headers/Keep-Alive#directives) for more details. Defaults to 4 seconds. -* **keepAliveTimeoutThreshold** `number | null` (optional) - Default: `1e3` - A number of milliseconds subtracted from server *keep-alive* hints when overriding `keepAliveTimeout` to account for timing inaccuracies caused by e.g. transport latency. Defaults to 1 second. +* **keepAliveTimeoutThreshold** `number | null` (optional) - Default: `2e3` - A number of milliseconds subtracted from server *keep-alive* hints when overriding `keepAliveTimeout` to account for timing inaccuracies caused by e.g. transport latency. Defaults to 2 seconds. * **maxHeaderSize** `number | null` (optional) - Default: `--max-http-header-size` or `16384` - The maximum length of request headers in bytes. Defaults to Node.js' --max-http-header-size or 16KiB. * **maxResponseSize** `number | null` (optional) - Default: `-1` - The maximum length of response body in bytes. Set to `-1` to disable. * **pipelining** `number | null` (optional) - Default: `1` - The amount of concurrent requests to be sent over the single TCP/TLS connection according to [RFC7230](https://tools.ietf.org/html/rfc7230#section-6.3.2). Carefully consider your workload and environment before enabling concurrent requests as pipelining may reduce performance if used incorrectly. Pipelining is sensitive to network stack settings as well as head of line blocking caused by e.g. long running requests. Set to `0` to disable keep-alive connections. diff --git a/lib/dispatcher/client.js b/lib/dispatcher/client.js index 7d6f5fd351f..cb61206b1ed 100644 --- a/lib/dispatcher/client.js +++ b/lib/dispatcher/client.js @@ -226,7 +226,7 @@ class Client extends DispatcherBase { this[kMaxHeadersSize] = maxHeaderSize || http.maxHeaderSize this[kKeepAliveDefaultTimeout] = keepAliveTimeout == null ? 4e3 : keepAliveTimeout this[kKeepAliveMaxTimeout] = keepAliveMaxTimeout == null ? 600e3 : keepAliveMaxTimeout - this[kKeepAliveTimeoutThreshold] = keepAliveTimeoutThreshold == null ? 1e3 : keepAliveTimeoutThreshold + this[kKeepAliveTimeoutThreshold] = keepAliveTimeoutThreshold == null ? 2e3 : keepAliveTimeoutThreshold this[kKeepAliveTimeoutValue] = this[kKeepAliveDefaultTimeout] this[kServerName] = null this[kLocalAddress] = localAddress != null ? localAddress : null diff --git a/lib/util/timers.js b/lib/util/timers.js index 23a6d2b5223..dac7ba0fe7c 100644 --- a/lib/util/timers.js +++ b/lib/util/timers.js @@ -1,5 +1,7 @@ 'use strict' +const TICK_MS = 500 + let fastNow = Date.now() let fastNowTimeout @@ -13,9 +15,7 @@ function onTimeout () { while (idx < len) { const timer = fastTimers[idx] - if (timer.state === 0) { - timer.state = fastNow + timer.delay - } else if (timer.state > 0 && fastNow >= timer.state) { + if (timer.state > 0 && fastNow >= timer.state) { timer.state = -1 timer.callback(timer.opaque) } @@ -43,7 +43,7 @@ function refreshTimeout () { fastNowTimeout.refresh() } else { clearTimeout(fastNowTimeout) - fastNowTimeout = setTimeout(onTimeout, 1e3) + fastNowTimeout = setTimeout(onTimeout, TICK_MS) if (fastNowTimeout.unref) { fastNowTimeout.unref() } @@ -73,7 +73,7 @@ class Timeout { } } - this.state = 0 + this.state = Date.now() + this.delay } clear () { @@ -83,7 +83,7 @@ class Timeout { module.exports = { setTimeout (callback, delay, opaque) { - return delay < 1e3 + return delay < TICK_MS ? setTimeout(callback, delay, opaque) : new Timeout(callback, delay, opaque) }, diff --git a/test/util.js b/test/util.js index b3e1193e506..f14ccf6bf7e 100644 --- a/test/util.js +++ b/test/util.js @@ -1,10 +1,12 @@ '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', () => { @@ -253,3 +255,79 @@ 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 impelements 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 + }) +}) From efcaa90acfaf8f67e159760068fd650b847aa157 Mon Sep 17 00:00:00 2001 From: Matt Weber Date: Mon, 22 Apr 2024 11:26:30 -0400 Subject: [PATCH 2/4] fix test impacted by default keepAliveTimeoutThreshold change --- test/node-test/balanced-pool.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/node-test/balanced-pool.js b/test/node-test/balanced-pool.js index bacae5a9282..d51d4a5cbb2 100644 --- a/test/node-test/balanced-pool.js +++ b/test/node-test/balanced-pool.js @@ -491,7 +491,7 @@ describe('weighted round robin', () => { const urls = servers.map(server => `http://localhost:${server.port}`) // add upstreams - const client = new BalancedPool(urls[0], { maxWeightPerServer, errorPenalty }) + const client = new BalancedPool(urls[0], { maxWeightPerServer, errorPenalty, keepAliveTimeoutThreshold: 100 }) urls.slice(1).map(url => client.addUpstream(url)) let connectionRefusedErrors = 0 From bb5cb6c8ff6ac9ea5f5f12a68f558007fe1756f1 Mon Sep 17 00:00:00 2001 From: Matt Weber Date: Mon, 22 Apr 2024 11:57:53 -0400 Subject: [PATCH 3/4] adjust timer registration strategy --- lib/util/timers.js | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/lib/util/timers.js b/lib/util/timers.js index dac7ba0fe7c..f4c7c5a6055 100644 --- a/lib/util/timers.js +++ b/lib/util/timers.js @@ -1,6 +1,6 @@ 'use strict' -const TICK_MS = 500 +const TICK_MS = 499 let fastNow = Date.now() let fastNowTimeout @@ -15,7 +15,9 @@ function onTimeout () { while (idx < len) { const timer = fastTimers[idx] - if (timer.state > 0 && fastNow >= timer.state) { + 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) } @@ -73,7 +75,7 @@ class Timeout { } } - this.state = Date.now() + this.delay + this.state = 0 } clear () { From cc2d298b2c51b8d54458dd9225c1b64693e25b23 Mon Sep 17 00:00:00 2001 From: Matt Weber Date: Mon, 22 Apr 2024 13:12:11 -0400 Subject: [PATCH 4/4] only use fast timers with delay > 1000ms --- lib/util/timers.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/util/timers.js b/lib/util/timers.js index f4c7c5a6055..d0091cc15f7 100644 --- a/lib/util/timers.js +++ b/lib/util/timers.js @@ -85,7 +85,7 @@ class Timeout { module.exports = { setTimeout (callback, delay, opaque) { - return delay < TICK_MS + return delay <= 1e3 ? setTimeout(callback, delay, opaque) : new Timeout(callback, delay, opaque) },