diff --git a/CHANGELOG.md b/CHANGELOG.md index edcf65ca..1e2baf5a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -9,6 +9,7 @@ and this project adheres to [Semantic Versioning](http://semver.org/spec/v2.0.0. ### Breaking Change ### Fixed +- Fixed `end` (and the promise returned by `Multi#perform`) not being delivered on Node.js 26 until some other JavaScript callback ran, which made requests awaited one at a time take ~1s each (libcurl's multi timer period) or never complete in an otherwise idle process. `Multi::OnSocket` and `Multi::OnTimeout` called into JavaScript from libuv without a callback scope, so the microtask queue was not drained afterwards. Before Node.js 26.4.0 an unrelated drain in `CheckImmediate` hid this ([nodejs/node#62969](https://github.com/nodejs/node/pull/62969)). Both now open a `Napi::CallbackScope`. As a side effect, `process.nextTick` callbacks and microtasks queued from inside data, header, progress, and other easy callbacks now run once the libuv callback that dispatched them returns, instead of after each individual callback. This matches how Node.js core runs callbacks. ([#455](https://github.com/JCMais/node-libcurl/pull/455), fixes [#454](https://github.com/JCMais/node-libcurl/issues/454)) ### Added diff --git a/src/Multi.cc b/src/Multi.cc index b4027d48..c9e13ee6 100644 --- a/src/Multi.cc +++ b/src/Multi.cc @@ -78,6 +78,10 @@ Multi::Multi(const Napi::CallbackInfo& info) : Napi::ObjectWrap(info), id // We need to keep the reference alive for the duration of the timer. this->Ref(); + // Used by OnSocket / OnTimeout to open a callback scope when entering JS from + // libuv. Created once here rather than per event. + this->asyncContext = std::make_shared(env, "node-libcurl:Multi"); + // Enable notification API if requested and supported if (shouldUseNotificationsApi) { #if NODE_LIBCURL_VER_GE(8, 17, 0) @@ -168,6 +172,9 @@ void Multi::Dispose() { this->mh = nullptr; } + // Must happen while the environment is still valid: napi_async_destroy. + this->asyncContext.reset(); + curl->AdjustHandleMemory(CURL_HANDLE_TYPE_MULTI, -1); } @@ -840,6 +847,22 @@ void Multi::NotifyCallback(CURLM* multi, unsigned int notification, CURL* easy, UV_TIMER_CB(Multi::OnTimeout) { Multi* obj = static_cast(timer->data); + // This runs from libuv, that is, from outside any JS context. Node.js only + // performs a microtask checkpoint when a callback scope is closed, so without + // one the promise CallOnMessageCallback settles below stays queued until + // something else happens to drain the microtask queue - which, for a caller + // awaiting one request at a time, is the next tick of this very timer. + // + // The local copy must outlive callbackScope: close() from inside onMessage + // resets obj->asyncContext while the scope is still open, and since Node.js 25 + // the async resource stack points into the context. + std::shared_ptr asyncContext = obj->asyncContext; + if (!asyncContext) return; + + Napi::Env env = obj->Env(); + Napi::HandleScope handleScope(env); + Napi::CallbackScope callbackScope(env, *asyncContext); + NODE_LIBCURL_DEBUG_LOG(obj, "Multi::OnTimeout", ""); // Check comment on node_libcurl.cc @@ -867,6 +890,15 @@ void Multi::OnSocket(uv_poll_t* handle, int status, int events) { Multi::CurlSocketContext* ctx = static_cast(handle->data); + // See the comment in Multi::OnTimeout - a callback scope is required here for + // the microtask checkpoint to run, and the local copy keeps its context alive. + std::shared_ptr asyncContext = ctx->multi->asyncContext; + if (!asyncContext) return; + + Napi::Env env = ctx->multi->Env(); + Napi::HandleScope handleScope(env); + Napi::CallbackScope callbackScope(env, *asyncContext); + NODE_LIBCURL_DEBUG_LOG(ctx->multi, "Multi::OnSocket", "events: " + std::to_string(events)); // Check comment on node_libcurl.cc diff --git a/src/Multi.h b/src/Multi.h index a8e5250f..ad37b7a1 100644 --- a/src/Multi.h +++ b/src/Multi.h @@ -85,6 +85,12 @@ class Multi : public Napi::ObjectWrap { napi_async_cleanup_hook_handle removeHandle; uint64_t id; + // Both libuv callbacks below (OnSocket / OnTimeout) call into JS from outside + // any JS context, so they need a callback scope. One long-lived async context + // per Multi is enough, and avoids a napi_async_init per socket event. + // Shared so an open scope can keep it alive across close() (see OnTimeout). + std::shared_ptr asyncContext; + std::map socketContextMap; // Notification API support (libcurl >= 8.17.0) diff --git a/test/curl/multi.spec.ts b/test/curl/multi.spec.ts new file mode 100644 index 00000000..115fc4ce --- /dev/null +++ b/test/curl/multi.spec.ts @@ -0,0 +1,67 @@ +/** + * Copyright (c) Jonathan Cardoso Machado. All Rights Reserved. + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + */ +import { executionAsyncResource } from 'async_hooks' +import { describe, beforeAll, afterAll, it, expect } from 'vitest' + +import { createServer } from '../helper/server' +import { Easy, Multi } from '../../lib' +import { withCommonTestOptions } from '../helper/commonOptions' + +let serverInstance: ReturnType + +describe('Multi', () => { + beforeAll(async () => { + serverInstance = createServer() + serverInstance.app.get('/', (_req, res) => { + res.send('Hello World!') + }) + await serverInstance.listen() + }) + + afterAll(async () => { + await serverInstance.close() + serverInstance.app._router.stack.pop() + }) + + describe('close', () => { + // onMessage runs inside the callback scope opened by OnSocket / OnTimeout, + // and since Node.js 25 the async resource stack points into that scope's + // async context, so the context must outlive close(). Reading the stack + // used to return garbage or crash the process. + // + // Pinned to the polling path: with the notifications API, onMessage runs + // inside libcurl's notify callback, where curl_multi_cleanup fails with + // CURLM_RECURSIVE_API_CALL. + it('should keep the async resource valid when called from inside onMessage', async () => { + const resourceAfterClose = await new Promise( + (resolve, reject) => { + const multi = new Multi({ shouldUseNotificationsApi: false }) + const easy = new Easy() + withCommonTestOptions(easy) + easy.setOpt('URL', serverInstance.url) + easy.setOpt('WRITEFUNCTION', (_buf, size, nmemb) => size * nmemb) + + multi.onMessage((error, handle) => { + multi.removeHandle(handle) + handle.close() + multi.close() + + if (error) { + reject(error) + return + } + + resolve(executionAsyncResource()) + }) + multi.addHandle(easy) + }, + ) + + expect(typeof resourceAfterClose).toBe('object') + }) + }) +}) diff --git a/test/curl/serializedRequests.spec.ts b/test/curl/serializedRequests.spec.ts new file mode 100644 index 00000000..d8e8ada8 --- /dev/null +++ b/test/curl/serializedRequests.spec.ts @@ -0,0 +1,97 @@ +/** + * Copyright (c) Jonathan Cardoso Machado. All Rights Reserved. + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + */ +import { describe, beforeAll, afterAll, it, expect } from 'vitest' + +import { createServer } from '../helper/server' +import { Curl, Multi } from '../../lib' +import { withCommonTestOptions } from '../helper/commonOptions' + +let serverInstance: ReturnType + +// Regression guard for requests awaited one at a time. +// +// Multi::OnSocket and Multi::OnTimeout enter JS from a libuv callback. The +// promise `perform()` settles is resolved from there, and Node.js only runs a +// microtask checkpoint when a callback scope is closed. Without one, the +// continuation that emits `end` was not scheduled until the next tick of +// libcurl's multi timer, making every serialized request take ~1s on Node.js 26 +// (Linux). Concurrency hid it, because other transfers kept the loop busy. +describe('Curl', () => { + beforeAll(async () => { + serverInstance = createServer() + serverInstance.app.get('/', (_req, res) => { + res.send('Hello World!') + }) + await serverInstance.listen() + }) + + afterAll(async () => { + await serverInstance.close() + serverInstance.app._router.stack.pop() + }) + + describe('perform', () => { + const performOnce = (multi?: Multi) => + new Promise((resolve, reject) => { + const startedAt = process.hrtime.bigint() + const curl = new Curl() + withCommonTestOptions(curl) + curl.setOpt('URL', serverInstance.url) + + if (multi) { + curl.setMulti(multi) + } + + curl.on('end', () => { + const elapsedMs = Number(process.hrtime.bigint() - startedAt) / 1e6 + curl.close() + resolve(elapsedMs) + }) + curl.on('error', (error) => { + curl.close() + reject(error) + }) + + curl.perform() + }) + + // Against a local server each request is sub-millisecond. The bug pinned + // every one of them at libcurl's multi timer period (~1000ms), so a + // generous threshold still separates the two regimes decisively. + const medianSerializedLatency = async (multi?: Multi) => { + // warm-up: the very first request pays for connection setup and JIT + await performOnce(multi) + + const latencies: number[] = [] + for (let i = 0; i < 10; i += 1) { + latencies.push(await performOnce(multi)) + } + + const sorted = [...latencies].sort((a, b) => a - b) + return sorted[Math.floor(sorted.length / 2)] + } + + it('should emit end without waiting for the multi timer when requests are awaited one at a time', async () => { + expect(await medianSerializedLatency()).toBeLessThan(250) + }) + + // The default Multi drains completions from Multi::NotifyCallback when built + // against libcurl >= 8.17, and straight from OnSocket / OnTimeout otherwise. + // Both are inside the callback scopes this guards, so pin the polling + // fallback explicitly instead of relying on a libcurl < 8.17 build to be the + // only thing exercising it. + it('should emit end without waiting for the multi timer when the notifications API is disabled', async () => { + const multi = new Multi({ shouldUseNotificationsApi: false }) + + try { + expect(await medianSerializedLatency(multi)).toBeLessThan(250) + } finally { + multi.close() + } + }) + }) +})