diff --git a/test/async-hooks/hook-checks.mjs b/test/async-hooks/hook-checks.mjs new file mode 100644 index 00000000000000..abf230630fbe30 --- /dev/null +++ b/test/async-hooks/hook-checks.mjs @@ -0,0 +1,53 @@ +import '../common/index.mjs'; +import assert, { ok, strictEqual } from 'assert'; + +/** + * Checks the expected invocations against the invocations that actually + * occurred. + * + * @name checkInvocations + * @function + * @param {object} activity including timestamps for each life time event, + * i.e. init, before ... + * @param {object} hooks the expected life time event invocations with a count + * indicating how often they should have been invoked, + * i.e. `{ init: 1, before: 2, after: 2 }` + * @param {string} stage the name of the stage in the test at which we are + * checking the invocations + */ +export function checkInvocations(activity, hooks, stage) { + const stageInfo = `Checking invocations at stage "${stage}":\n `; + + ok(activity != null, + `${stageInfo} Trying to check invocation for an activity, ` + + 'but it was empty/undefined.' + ); + + // Check that actual invocations for all hooks match the expected invocations + [ 'init', 'before', 'after', 'destroy', 'promiseResolve' ].forEach(checkHook); + + function checkHook(k) { + const val = hooks[k]; + // Not expected ... all good + if (val == null) return; + + if (val === 0) { + // Didn't expect any invocations, but it was actually invoked + const invocations = activity[k].length; + const msg = `${stageInfo} Called "${k}" ${invocations} time(s), ` + + 'but expected no invocations.'; + assert(activity[k] === null && activity[k] === undefined, msg); + } else { + // Expected some invocations, make sure that it was invoked at all + const msg1 = `${stageInfo} Never called "${k}", ` + + `but expected ${val} invocation(s).`; + assert(activity[k] !== null && activity[k] !== undefined, msg1); + + // Now make sure that the expected count and + // the actual invocation count match + const msg2 = `${stageInfo} Called "${k}" ${activity[k].length} ` + + `time(s), but expected ${val} invocation(s).`; + strictEqual(activity[k].length, val, msg2); + } + } +} diff --git a/test/async-hooks/init-hooks.mjs b/test/async-hooks/init-hooks.mjs new file mode 100644 index 00000000000000..84bfee98a2c5f6 --- /dev/null +++ b/test/async-hooks/init-hooks.mjs @@ -0,0 +1,247 @@ +// Flags: --expose-gc + +import { isMainThread } from '../common/index.mjs'; +import { fail } from 'assert'; +import { createHook } from 'async_hooks'; +import process, { _rawDebug as print } from 'process'; +import { inspect as utilInspect } from 'util'; + +if (typeof globalThis.gc === 'function') { + (function exity(cntr) { + process.once('beforeExit', () => { + globalThis.gc(); + if (cntr < 4) setImmediate(() => exity(cntr + 1)); + }); + })(0); +} + +function noop() {} + +class ActivityCollector { + constructor(start, { + allowNoInit = false, + oninit, + onbefore, + onafter, + ondestroy, + onpromiseResolve, + logid = null, + logtype = null + } = {}) { + this._start = start; + this._allowNoInit = allowNoInit; + this._activities = new Map(); + this._logid = logid; + this._logtype = logtype; + + // Register event handlers if provided + this.oninit = typeof oninit === 'function' ? oninit : noop; + this.onbefore = typeof onbefore === 'function' ? onbefore : noop; + this.onafter = typeof onafter === 'function' ? onafter : noop; + this.ondestroy = typeof ondestroy === 'function' ? ondestroy : noop; + this.onpromiseResolve = typeof onpromiseResolve === 'function' ? + onpromiseResolve : noop; + + // Create the hook with which we'll collect activity data + this._asyncHook = createHook({ + init: this._init.bind(this), + before: this._before.bind(this), + after: this._after.bind(this), + destroy: this._destroy.bind(this), + promiseResolve: this._promiseResolve.bind(this) + }); + } + + enable() { + this._asyncHook.enable(); + } + + disable() { + this._asyncHook.disable(); + } + + sanityCheck(types) { + if (types != null && !Array.isArray(types)) types = [ types ]; + + function activityString(a) { + return utilInspect(a, false, 5, true); + } + + const violations = []; + let tempActivityString; + + function v(msg) { violations.push(msg); } + for (const a of this._activities.values()) { + tempActivityString = activityString(a); + if (types != null && !types.includes(a.type)) continue; + + if (a.init && a.init.length > 1) { + v(`Activity inited twice\n${tempActivityString}` + + '\nExpected "init" to be called at most once'); + } + if (a.destroy && a.destroy.length > 1) { + v(`Activity destroyed twice\n${tempActivityString}` + + '\nExpected "destroy" to be called at most once'); + } + if (a.before && a.after) { + if (a.before.length < a.after.length) { + v('Activity called "after" without calling "before"\n' + + `${tempActivityString}` + + '\nExpected no "after" call without a "before"'); + } + if (a.before.some((x, idx) => x > a.after[idx])) { + v('Activity had an instance where "after" ' + + 'was invoked before "before"\n' + + `${tempActivityString}` + + '\nExpected "after" to be called after "before"'); + } + } + if (a.before && a.destroy) { + if (a.before.some((x, idx) => x > a.destroy[idx])) { + v('Activity had an instance where "destroy" ' + + 'was invoked before "before"\n' + + `${tempActivityString}` + + '\nExpected "destroy" to be called after "before"'); + } + } + if (a.after && a.destroy) { + if (a.after.some((x, idx) => x > a.destroy[idx])) { + v('Activity had an instance where "destroy" ' + + 'was invoked before "after"\n' + + `${tempActivityString}` + + '\nExpected "destroy" to be called after "after"'); + } + } + if (!a.handleIsObject) { + v(`No resource object\n${tempActivityString}` + + '\nExpected "init" to be called with a resource object'); + } + } + if (violations.length) { + console.error(violations.join('\n\n') + '\n'); + fail(`${violations.length} failed sanity checks`); + } + } + + inspect(opts = {}) { + if (typeof opts === 'string') opts = { types: opts }; + const { types = null, depth = 5, stage = null } = opts; + const activities = types == null ? + Array.from(this._activities.values()) : + this.activitiesOfTypes(types); + + if (stage != null) console.log(`\n${stage}`); + console.log(utilInspect(activities, false, depth, true)); + } + + activitiesOfTypes(types) { + if (!Array.isArray(types)) types = [ types ]; + return this.activities.filter((x) => types.includes(x.type)); + } + + get activities() { + return Array.from(this._activities.values()); + } + + _stamp(h, hook) { + if (h == null) return; + if (h[hook] == null) h[hook] = []; + const time = process.hrtime(this._start); + h[hook].push((time[0] * 1e9) + time[1]); + } + + _getActivity(uid, hook) { + const h = this._activities.get(uid); + if (!h) { + // If we allowed handles without init we ignore any further life time + // events this makes sense for a few tests in which we enable some hooks + // later + if (this._allowNoInit) { + const stub = { uid, type: 'Unknown', handleIsObject: true, handle: {} }; + this._activities.set(uid, stub); + return stub; + } else if (!isMainThread) { + // Worker threads start main script execution inside of an AsyncWrap + // callback, so we don't yield errors for these. + return null; + } + const err = new Error(`Found a handle whose ${hook}` + + ' hook was invoked but not its init hook'); + throw err; + } + return h; + } + + _init(uid, type, triggerAsyncId, handle) { + const activity = { + uid, + type, + triggerAsyncId, + // In some cases (e.g. Timeout) the handle is a function, thus the usual + // `typeof handle === 'object' && handle !== null` check can't be used. + handleIsObject: handle instanceof Object, + handle + }; + this._stamp(activity, 'init'); + this._activities.set(uid, activity); + this._maybeLog(uid, type, 'init'); + this.oninit(uid, type, triggerAsyncId, handle); + } + + _before(uid) { + const h = this._getActivity(uid, 'before'); + this._stamp(h, 'before'); + this._maybeLog(uid, h && h.type, 'before'); + this.onbefore(uid); + } + + _after(uid) { + const h = this._getActivity(uid, 'after'); + this._stamp(h, 'after'); + this._maybeLog(uid, h && h.type, 'after'); + this.onafter(uid); + } + + _destroy(uid) { + const h = this._getActivity(uid, 'destroy'); + this._stamp(h, 'destroy'); + this._maybeLog(uid, h && h.type, 'destroy'); + this.ondestroy(uid); + } + + _promiseResolve(uid) { + const h = this._getActivity(uid, 'promiseResolve'); + this._stamp(h, 'promiseResolve'); + this._maybeLog(uid, h && h.type, 'promiseResolve'); + this.onpromiseResolve(uid); + } + + _maybeLog(uid, type, name) { + if (this._logid && + (type == null || this._logtype == null || this._logtype === type)) { + print(`${this._logid}.${name}.uid-${uid}`); + } + } +} + +export default function initHooks({ + oninit, + onbefore, + onafter, + ondestroy, + onpromiseResolve, + allowNoInit, + logid, + logtype +} = {}) { + return new ActivityCollector(process.hrtime(), { + oninit, + onbefore, + onafter, + ondestroy, + onpromiseResolve, + allowNoInit, + logid, + logtype + }); +}; diff --git a/test/async-hooks/test-async-await.mjs b/test/async-hooks/test-async-await.mjs new file mode 100644 index 00000000000000..e549cfb8cb5016 --- /dev/null +++ b/test/async-hooks/test-async-await.mjs @@ -0,0 +1,91 @@ +import { platformTimeout, mustCall } from '../common/index.mjs'; + +// This test ensures async hooks are being properly called +// when using async-await mechanics. This involves: +// 1. Checking that all initialized promises are being resolved +// 2. Checking that for each 'before' corresponding hook 'after' hook is called + +import assert, { strictEqual } from 'assert'; +import process from 'process'; +import initHooks from './init-hooks.mjs'; + +import { promisify } from 'util'; + +const sleep = promisify(setTimeout); +// Either 'inited' or 'resolved' +const promisesInitState = new Map(); +// Either 'before' or 'after' AND asyncId must be present in the other map +const promisesExecutionState = new Map(); + +const hooks = initHooks({ + oninit, + onbefore, + onafter, + ondestroy: null, // Intentionally not tested, since it will be removed soon + onpromiseResolve +}); +hooks.enable(); + +function oninit(asyncId, type) { + if (type === 'PROMISE') { + promisesInitState.set(asyncId, 'inited'); + } +} + +function onbefore(asyncId) { + if (!promisesInitState.has(asyncId)) { + return; + } + promisesExecutionState.set(asyncId, 'before'); +} + +function onafter(asyncId) { + if (!promisesInitState.has(asyncId)) { + return; + } + + strictEqual(promisesExecutionState.get(asyncId), 'before', + 'after hook called for promise without prior call' + + 'to before hook'); + strictEqual(promisesInitState.get(asyncId), 'resolved', + 'after hook called for promise without prior call' + + 'to resolve hook'); + promisesExecutionState.set(asyncId, 'after'); +} + +function onpromiseResolve(asyncId) { + assert(promisesInitState.has(asyncId), + 'resolve hook called for promise without prior call to init hook'); + + promisesInitState.set(asyncId, 'resolved'); +} + +const timeout = platformTimeout(10); + +function checkPromisesInitState() { + for (const initState of promisesInitState.values()) { + // Promise should not be initialized without being resolved. + strictEqual(initState, 'resolved'); + } +} + +function checkPromisesExecutionState() { + for (const executionState of promisesExecutionState.values()) { + // Check for mismatch between before and after hook calls. + strictEqual(executionState, 'after'); + } +} + +process.on('beforeExit', mustCall(() => { + hooks.disable(); + hooks.sanityCheck('PROMISE'); + + checkPromisesInitState(); + checkPromisesExecutionState(); +})); + +async function asyncFunc() { + await sleep(timeout); +} + +asyncFunc(); diff --git a/test/async-hooks/test-async-exec-resource-http-32060.mjs b/test/async-hooks/test-async-exec-resource-http-32060.mjs new file mode 100644 index 00000000000000..ae4559f1c99ccd --- /dev/null +++ b/test/async-hooks/test-async-exec-resource-http-32060.mjs @@ -0,0 +1,32 @@ +import '../common/index.mjs'; +import { strictEqual } from 'assert'; +import { executionAsyncResource, executionAsyncId, createHook } from 'async_hooks'; +import { createServer, get } from 'http'; + +const hooked = {}; +createHook({ + init(asyncId, type, triggerAsyncId, resource) { + hooked[asyncId] = resource; + } +}).enable(); + +const server = createServer((req, res) => { + res.write('hello'); + setTimeout(() => { + res.end(' world!'); + }, 1000); +}); + +server.listen(0, () => { + strictEqual(executionAsyncResource(), hooked[executionAsyncId()]); + get({ port: server.address().port }, (res) => { + strictEqual(executionAsyncResource(), hooked[executionAsyncId()]); + res.on('data', () => { + strictEqual(executionAsyncResource(), hooked[executionAsyncId()]); + }); + res.on('end', () => { + strictEqual(executionAsyncResource(), hooked[executionAsyncId()]); + server.close(); + }); + }); +}); diff --git a/test/async-hooks/test-async-exec-resource-http.mjs b/test/async-hooks/test-async-exec-resource-http.mjs new file mode 100644 index 00000000000000..529f3af0242ec2 --- /dev/null +++ b/test/async-hooks/test-async-exec-resource-http.mjs @@ -0,0 +1,24 @@ +import '../common/index.mjs'; +import { strictEqual } from 'assert'; +import { executionAsyncResource, executionAsyncId, createHook } from 'async_hooks'; +import { createServer, get } from 'http'; + +const hooked = {}; +createHook({ + init(asyncId, type, triggerAsyncId, resource) { + hooked[asyncId] = resource; + } +}).enable(); + +const server = createServer((req, res) => { + res.end('ok'); +}); + +server.listen(0, () => { + strictEqual(executionAsyncResource(), hooked[executionAsyncId()]); + + get({ port: server.address().port }, () => { + strictEqual(executionAsyncResource(), hooked[executionAsyncId()]); + server.close(); + }); +}); diff --git a/test/async-hooks/test-async-exec-resource-match.mjs b/test/async-hooks/test-async-exec-resource-match.mjs new file mode 100644 index 00000000000000..789e4844c82771 --- /dev/null +++ b/test/async-hooks/test-async-exec-resource-match.mjs @@ -0,0 +1,59 @@ +import { mustCallAtLeast, mustCall } from '../common/index.mjs'; +import { ok } from 'assert'; +import { readFile } from 'fs'; +import { createHook, executionAsyncResource, AsyncResource } from 'async_hooks'; +import { fileURLToPath } from 'url'; + +const __filename = fileURLToPath(import.meta.url); + +// Ignore any asyncIds created before our hook is active. +let firstSeenAsyncId = -1; +const idResMap = new Map(); +const numExpectedCalls = 5; + +createHook({ + init: mustCallAtLeast( + (asyncId, type, triggerId, resource) => { + if (firstSeenAsyncId === -1) { + firstSeenAsyncId = asyncId; + } + ok(idResMap.get(asyncId) === undefined); + idResMap.set(asyncId, resource); + }, numExpectedCalls), + before(asyncId) { + if (asyncId >= firstSeenAsyncId) { + beforeHook(asyncId); + } + }, + after(asyncId) { + if (asyncId >= firstSeenAsyncId) { + afterHook(asyncId); + } + } +}).enable(); + +const beforeHook = mustCallAtLeast( + (asyncId) => { + const res = idResMap.get(asyncId); + ok(res !== undefined); + const execRes = executionAsyncResource(); + ok(execRes === res, 'resource mismatch in before'); + }, numExpectedCalls); + +const afterHook = mustCallAtLeast( + (asyncId) => { + const res = idResMap.get(asyncId); + ok(res !== undefined); + const execRes = executionAsyncResource(); + ok(execRes === res, 'resource mismatch in after'); + }, numExpectedCalls); + +const res = new AsyncResource('TheResource'); +const initRes = idResMap.get(res.asyncId()); +ok(initRes === res, 'resource mismatch in init'); +res.runInAsyncScope(mustCall(() => { + const execRes = executionAsyncResource(); + ok(execRes === res, 'resource mismatch in cb'); +})); + +readFile(__filename, mustCall()); diff --git a/test/async-hooks/test-async-local-storage-args.mjs b/test/async-hooks/test-async-local-storage-args.mjs new file mode 100644 index 00000000000000..98a2d0a318ae5b --- /dev/null +++ b/test/async-hooks/test-async-local-storage-args.mjs @@ -0,0 +1,12 @@ +import '../common/index.mjs'; +import { strictEqual } from 'assert'; +import { AsyncLocalStorage } from 'async_hooks'; + +const asyncLocalStorage = new AsyncLocalStorage(); + +asyncLocalStorage.run({}, (runArg) => { + strictEqual(runArg, 'foo'); + asyncLocalStorage.exit((exitArg) => { + strictEqual(exitArg, 'bar'); + }, 'bar'); +}, 'foo'); diff --git a/test/async-hooks/test-async-local-storage-async-await.mjs b/test/async-hooks/test-async-local-storage-async-await.mjs new file mode 100644 index 00000000000000..2ffa06f9fffbd7 --- /dev/null +++ b/test/async-hooks/test-async-local-storage-async-await.mjs @@ -0,0 +1,18 @@ +import '../common/index.mjs'; +import { strictEqual } from 'assert'; +import { AsyncLocalStorage } from 'async_hooks'; + +const asyncLocalStorage = new AsyncLocalStorage(); + +async function test() { + asyncLocalStorage.getStore().set('foo', 'bar'); + await Promise.resolve(); + strictEqual(asyncLocalStorage.getStore().get('foo'), 'bar'); +} + +async function main() { + await asyncLocalStorage.run(new Map(), test); + strictEqual(asyncLocalStorage.getStore(), undefined); +} + +main(); diff --git a/test/async-hooks/test-async-local-storage-async-functions.mjs b/test/async-hooks/test-async-local-storage-async-functions.mjs new file mode 100644 index 00000000000000..f02df9833759dd --- /dev/null +++ b/test/async-hooks/test-async-local-storage-async-functions.mjs @@ -0,0 +1,26 @@ +import '../common/index.mjs'; +import { strictEqual, notStrictEqual } from 'assert'; +import { AsyncLocalStorage } from 'async_hooks'; + +async function foo() {} + +const asyncLocalStorage = new AsyncLocalStorage(); + +async function testOut() { + await foo(); + strictEqual(asyncLocalStorage.getStore(), undefined); +} + +async function testAwait() { + await foo(); + notStrictEqual(asyncLocalStorage.getStore(), undefined); + strictEqual(asyncLocalStorage.getStore().get('key'), 'value'); + await asyncLocalStorage.exit(testOut); +} + +asyncLocalStorage.run(new Map(), () => { + const store = asyncLocalStorage.getStore(); + store.set('key', 'value'); + testAwait(); // should not reject +}); +strictEqual(asyncLocalStorage.getStore(), undefined); diff --git a/test/async-hooks/test-async-local-storage-dgram.mjs b/test/async-hooks/test-async-local-storage-dgram.mjs new file mode 100644 index 00000000000000..7e2c7fcd7f0e50 --- /dev/null +++ b/test/async-hooks/test-async-local-storage-dgram.mjs @@ -0,0 +1,24 @@ +import '../common/index.mjs'; + +// Regression tests for https://github.com/nodejs/node/issues/40693 + +import { deepStrictEqual } from 'assert'; +import { createSocket } from 'dgram'; +import { AsyncLocalStorage } from 'async_hooks'; + +createSocket('udp4') + .on('message', function(msg, rinfo) { this.send(msg, rinfo.port); }) + .on('listening', function() { + const asyncLocalStorage = new AsyncLocalStorage(); + const store = { val: 'abcd' }; + asyncLocalStorage.run(store, () => { + const client = createSocket('udp4'); + client.on('message', (msg, rinfo) => { + deepStrictEqual(asyncLocalStorage.getStore(), store); + client.close(); + this.close(); + }); + client.send('Hello, world!', this.address().port); + }); + }) + .bind(0); diff --git a/test/async-hooks/test-async-local-storage-enable-disable.mjs b/test/async-hooks/test-async-local-storage-enable-disable.mjs new file mode 100644 index 00000000000000..c111f1d317e2fc --- /dev/null +++ b/test/async-hooks/test-async-local-storage-enable-disable.mjs @@ -0,0 +1,32 @@ +import '../common/index.mjs'; +import { strictEqual } from 'assert'; +import process from 'process'; +import { AsyncLocalStorage } from 'async_hooks'; + +const asyncLocalStorage = new AsyncLocalStorage(); + +asyncLocalStorage.run(new Map(), () => { + asyncLocalStorage.getStore().set('foo', 'bar'); + process.nextTick(() => { + strictEqual(asyncLocalStorage.getStore().get('foo'), 'bar'); + process.nextTick(() => { + strictEqual(asyncLocalStorage.getStore(), undefined); + }); + + asyncLocalStorage.disable(); + strictEqual(asyncLocalStorage.getStore(), undefined); + + // Calls to exit() should not mess with enabled status + asyncLocalStorage.exit(() => { + strictEqual(asyncLocalStorage.getStore(), undefined); + }); + strictEqual(asyncLocalStorage.getStore(), undefined); + + process.nextTick(() => { + strictEqual(asyncLocalStorage.getStore(), undefined); + asyncLocalStorage.run(new Map().set('bar', 'foo'), () => { + strictEqual(asyncLocalStorage.getStore().get('bar'), 'foo'); + }); + }); + }); +}); diff --git a/test/async-hooks/test-async-local-storage-enter-with.mjs b/test/async-hooks/test-async-local-storage-enter-with.mjs new file mode 100644 index 00000000000000..cdfd0a752fad6f --- /dev/null +++ b/test/async-hooks/test-async-local-storage-enter-with.mjs @@ -0,0 +1,19 @@ +import '../common/index.mjs'; +import { strictEqual } from 'assert'; +import { AsyncLocalStorage } from 'async_hooks'; + +const asyncLocalStorage = new AsyncLocalStorage(); + +setImmediate(() => { + const store = { foo: 'bar' }; + asyncLocalStorage.enterWith(store); + + strictEqual(asyncLocalStorage.getStore(), store); + setTimeout(() => { + strictEqual(asyncLocalStorage.getStore(), store); + }, 10); +}); + +setTimeout(() => { + strictEqual(asyncLocalStorage.getStore(), undefined); +}, 10); diff --git a/test/async-hooks/test-async-local-storage-errors.mjs b/test/async-hooks/test-async-local-storage-errors.mjs new file mode 100644 index 00000000000000..2953beb69db2c0 --- /dev/null +++ b/test/async-hooks/test-async-local-storage-errors.mjs @@ -0,0 +1,118 @@ +import { mustCall } from '../common/index.mjs'; +import { strictEqual, fail } from 'assert'; +import { AsyncLocalStorage } from 'async_hooks'; +import process from 'process'; +import { compileFunction } from 'vm'; + +// err1 is emitted sync as a control - no events +// err2 is emitted after a timeout - uncaughtExceptionMonitor +// + uncaughtException +// err3 is emitted after some awaits - unhandledRejection +// err4 is emitted during handling err3 - uncaughtExceptionMonitor +// err5 is emitted after err4 from a VM lacking hooks - unhandledRejection +// + uncaughtException + +const asyncLocalStorage = new AsyncLocalStorage(); +const callbackToken = { callbackToken: true }; +const awaitToken = { awaitToken: true }; + +let i = 0; + +// Redefining the uncaughtExceptionHandler is a bit odd, so we just do this +// so we can track total invocations +let underlyingExceptionHandler; +const exceptionHandler = mustCall(function(...args) { + return underlyingExceptionHandler.call(this, ...args); +}, 2); +process.setUncaughtExceptionCaptureCallback(exceptionHandler); + +const exceptionMonitor = mustCall((err, origin) => { + if (err.message === 'err2') { + strictEqual(origin, 'uncaughtException'); + strictEqual(asyncLocalStorage.getStore(), callbackToken); + } else if (err.message === 'err4') { + strictEqual(origin, 'unhandledRejection'); + strictEqual(asyncLocalStorage.getStore(), awaitToken); + } else { + fail('unknown error ' + err); + } +}, 2); +process.on('uncaughtExceptionMonitor', exceptionMonitor); + +function fireErr1() { + underlyingExceptionHandler = mustCall(function(err) { + ++i; + strictEqual(err.message, 'err2'); + strictEqual(asyncLocalStorage.getStore(), callbackToken); + }, 1); + try { + asyncLocalStorage.run(callbackToken, () => { + setTimeout(fireErr2, 0); + throw new Error('err1'); + }); + } catch (e) { + strictEqual(e.message, 'err1'); + strictEqual(asyncLocalStorage.getStore(), undefined); + } +} + +function fireErr2() { + process.nextTick(() => { + strictEqual(i, 1); + fireErr3(); + }); + throw new Error('err2'); +} + +function fireErr3() { + strictEqual(asyncLocalStorage.getStore(), callbackToken); + const rejectionHandler3 = mustCall((err) => { + strictEqual(err.message, 'err3'); + strictEqual(asyncLocalStorage.getStore(), awaitToken); + process.off('unhandledRejection', rejectionHandler3); + + fireErr4(); + }, 1); + process.on('unhandledRejection', rejectionHandler3); + async function awaitTest() { + await null; + throw new Error('err3'); + } + asyncLocalStorage.run(awaitToken, awaitTest); +} + +const uncaughtExceptionHandler4 = mustCall( + function(err) { + strictEqual(err.message, 'err4'); + strictEqual(asyncLocalStorage.getStore(), awaitToken); + fireErr5(); + }, 1); +function fireErr4() { + strictEqual(asyncLocalStorage.getStore(), awaitToken); + underlyingExceptionHandler = uncaughtExceptionHandler4; + // re-entrant check + Promise.reject(new Error('err4')); +} + +function fireErr5() { + strictEqual(asyncLocalStorage.getStore(), awaitToken); + underlyingExceptionHandler = () => {}; + const rejectionHandler5 = mustCall((err) => { + strictEqual(err.message, 'err5'); + strictEqual(asyncLocalStorage.getStore(), awaitToken); + process.off('unhandledRejection', rejectionHandler5); + }, 1); + process.on('unhandledRejection', rejectionHandler5); + const makeOrphan = compileFunction(`(${String(() => { + async function main() { + await null; + Promise.resolve().then(() => { + throw new Error('err5'); + }); + } + main(); + })})()`); + makeOrphan(); +} + +fireErr1(); diff --git a/test/async-hooks/test-async-local-storage-gcable.mjs b/test/async-hooks/test-async-local-storage-gcable.mjs new file mode 100644 index 00000000000000..3e209311653c3d --- /dev/null +++ b/test/async-hooks/test-async-local-storage-gcable.mjs @@ -0,0 +1,19 @@ +// Flags: --expose_gc + +// This test ensures that AsyncLocalStorage gets gced once it was disabled +// and no strong references remain in userland. + +import { mustCall } from '../common/index.mjs'; +import { AsyncLocalStorage } from 'async_hooks'; +import onGC from '../common/ongc.js'; + +let asyncLocalStorage = new AsyncLocalStorage(); + +asyncLocalStorage.run({}, () => { + asyncLocalStorage.disable(); + + onGC(asyncLocalStorage, { ongc: mustCall() }); +}); + +asyncLocalStorage = null; +globalThis.gc(); diff --git a/test/async-hooks/test-async-local-storage-http-agent.mjs b/test/async-hooks/test-async-local-storage-http-agent.mjs new file mode 100644 index 00000000000000..3b20ffe69c1695 --- /dev/null +++ b/test/async-hooks/test-async-local-storage-http-agent.mjs @@ -0,0 +1,34 @@ +import { mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import { AsyncLocalStorage } from 'async_hooks'; +import { Agent, createServer, get } from 'http'; + +const asyncLocalStorage = new AsyncLocalStorage(); + +const agent = new Agent({ + maxSockets: 1 +}); + +const N = 3; +let responses = 0; + +const server = createServer(mustCall((req, res) => { + res.end('ok'); +}, N)); + +server.listen(0, mustCall(() => { + const port = server.address().port; + + for (let i = 0; i < N; i++) { + asyncLocalStorage.run(i, () => { + get({ agent, port }, mustCall((res) => { + strictEqual(asyncLocalStorage.getStore(), i); + if (++responses === N) { + server.close(); + agent.destroy(); + } + res.resume(); + })); + }); + } +})); diff --git a/test/async-hooks/test-async-local-storage-http.mjs b/test/async-hooks/test-async-local-storage-http.mjs new file mode 100644 index 00000000000000..022499dc3aa10e --- /dev/null +++ b/test/async-hooks/test-async-local-storage-http.mjs @@ -0,0 +1,20 @@ +import '../common/index.mjs'; +import { strictEqual } from 'assert'; +import { AsyncLocalStorage } from 'async_hooks'; +import { createServer, get } from 'http'; + +const asyncLocalStorage = new AsyncLocalStorage(); +const server = createServer((req, res) => { + res.end('ok'); +}); + +server.listen(0, () => { + asyncLocalStorage.run(new Map(), () => { + const store = asyncLocalStorage.getStore(); + store.set('hello', 'world'); + get({ host: 'localhost', port: server.address().port }, () => { + strictEqual(asyncLocalStorage.getStore().get('hello'), 'world'); + server.close(); + }); + }); +}); diff --git a/test/async-hooks/test-async-local-storage-misc-stores.mjs b/test/async-hooks/test-async-local-storage-misc-stores.mjs new file mode 100644 index 00000000000000..f120a318d6db63 --- /dev/null +++ b/test/async-hooks/test-async-local-storage-misc-stores.mjs @@ -0,0 +1,14 @@ +import '../common/index.mjs'; +import { strictEqual } from 'assert'; +import { AsyncLocalStorage } from 'async_hooks'; + +const asyncLocalStorage = new AsyncLocalStorage(); + +asyncLocalStorage.run('hello node', () => { + strictEqual(asyncLocalStorage.getStore(), 'hello node'); +}); + +const runStore = { hello: 'node' }; +asyncLocalStorage.run(runStore, () => { + strictEqual(asyncLocalStorage.getStore(), runStore); +}); diff --git a/test/async-hooks/test-async-local-storage-nested.mjs b/test/async-hooks/test-async-local-storage-nested.mjs new file mode 100644 index 00000000000000..afea7f70585d5c --- /dev/null +++ b/test/async-hooks/test-async-local-storage-nested.mjs @@ -0,0 +1,24 @@ +import '../common/index.mjs'; +import { strictEqual } from 'assert'; +import { AsyncLocalStorage } from 'async_hooks'; + +const asyncLocalStorage = new AsyncLocalStorage(); +const outer = {}; +const inner = {}; + +function testInner() { + strictEqual(asyncLocalStorage.getStore(), outer); + + asyncLocalStorage.run(inner, () => { + strictEqual(asyncLocalStorage.getStore(), inner); + }); + strictEqual(asyncLocalStorage.getStore(), outer); + + asyncLocalStorage.exit(() => { + strictEqual(asyncLocalStorage.getStore(), undefined); + }); + strictEqual(asyncLocalStorage.getStore(), outer); +} + +asyncLocalStorage.run(outer, testInner); +strictEqual(asyncLocalStorage.getStore(), undefined); diff --git a/test/async-hooks/test-async-local-storage-no-mix-contexts.mjs b/test/async-hooks/test-async-local-storage-no-mix-contexts.mjs new file mode 100644 index 00000000000000..633a2f3f7b2449 --- /dev/null +++ b/test/async-hooks/test-async-local-storage-no-mix-contexts.mjs @@ -0,0 +1,37 @@ +import '../common/index.mjs'; +import { strictEqual } from 'assert'; +import { AsyncLocalStorage } from 'async_hooks'; + +const asyncLocalStorage = new AsyncLocalStorage(); +const asyncLocalStorage2 = new AsyncLocalStorage(); + +setTimeout(() => { + asyncLocalStorage.run(new Map(), () => { + asyncLocalStorage2.run(new Map(), () => { + const store = asyncLocalStorage.getStore(); + const store2 = asyncLocalStorage2.getStore(); + store.set('hello', 'world'); + store2.set('hello', 'foo'); + setTimeout(() => { + strictEqual(asyncLocalStorage.getStore().get('hello'), 'world'); + strictEqual(asyncLocalStorage2.getStore().get('hello'), 'foo'); + asyncLocalStorage.exit(() => { + strictEqual(asyncLocalStorage.getStore(), undefined); + strictEqual(asyncLocalStorage2.getStore().get('hello'), 'foo'); + }); + strictEqual(asyncLocalStorage.getStore().get('hello'), 'world'); + strictEqual(asyncLocalStorage2.getStore().get('hello'), 'foo'); + }, 200); + }); + }); +}, 100); + +setTimeout(() => { + asyncLocalStorage.run(new Map(), () => { + const store = asyncLocalStorage.getStore(); + store.set('hello', 'earth'); + setTimeout(() => { + strictEqual(asyncLocalStorage.getStore().get('hello'), 'earth'); + }, 100); + }); +}, 100); diff --git a/test/async-hooks/test-async-local-storage-promises.mjs b/test/async-hooks/test-async-local-storage-promises.mjs new file mode 100644 index 00000000000000..3afb30c43e28e9 --- /dev/null +++ b/test/async-hooks/test-async-local-storage-promises.mjs @@ -0,0 +1,27 @@ +import '../common/index.mjs'; +import { strictEqual } from 'assert'; +import { AsyncLocalStorage } from 'async_hooks'; + +async function main() { + const asyncLocalStorage = new AsyncLocalStorage(); + const err = new Error(); + const next = () => Promise.resolve() + .then(() => { + strictEqual(asyncLocalStorage.getStore().get('a'), 1); + throw err; + }); + await new Promise((resolve, reject) => { + asyncLocalStorage.run(new Map(), () => { + const store = asyncLocalStorage.getStore(); + store.set('a', 1); + next().then(resolve, reject); + }); + }) + .catch((e) => { + strictEqual(asyncLocalStorage.getStore(), undefined); + strictEqual(e, err); + }); + strictEqual(asyncLocalStorage.getStore(), undefined); +} + +main(); diff --git a/test/async-hooks/test-async-local-storage-socket.mjs b/test/async-hooks/test-async-local-storage-socket.mjs new file mode 100644 index 00000000000000..922c8db5c0fea2 --- /dev/null +++ b/test/async-hooks/test-async-local-storage-socket.mjs @@ -0,0 +1,24 @@ +import '../common/index.mjs'; + +// Regression tests for https://github.com/nodejs/node/issues/40693 + +import { deepStrictEqual } from 'assert'; +import { createServer, connect } from 'net'; +import { AsyncLocalStorage } from 'async_hooks'; + +createServer((socket) => { + socket.write('Hello, world!'); + socket.pipe(socket); + }) + .listen(0, function() { + const asyncLocalStorage = new AsyncLocalStorage(); + const store = { val: 'abcd' }; + asyncLocalStorage.run(store, () => { + const client = connect({ port: this.address().port }); + client.on('data', () => { + deepStrictEqual(asyncLocalStorage.getStore(), store); + client.end(); + this.close(); + }); + }); + }); diff --git a/test/async-hooks/test-async-local-storage-thenable.mjs b/test/async-hooks/test-async-local-storage-thenable.mjs new file mode 100644 index 00000000000000..53884da985b73d --- /dev/null +++ b/test/async-hooks/test-async-local-storage-thenable.mjs @@ -0,0 +1,51 @@ +import { mustCall } from '../common/index.mjs'; + +import { strictEqual } from 'assert'; +import { AsyncLocalStorage } from 'async_hooks'; + +// This test verifies that async local storage works with thenables + +const store = new AsyncLocalStorage(); +const data = Symbol('verifier'); + +const then = mustCall((cb) => { + strictEqual(store.getStore(), data); + setImmediate(cb); +}, 4); + +function thenable() { + return { + then + }; +} + +// Await a thenable +store.run(data, async () => { + strictEqual(store.getStore(), data); + await thenable(); + strictEqual(store.getStore(), data); +}); + +// Returning a thenable in an async function +store.run(data, async () => { + try { + strictEqual(store.getStore(), data); + return thenable(); + } finally { + strictEqual(store.getStore(), data); + } +}); + +// Resolving a thenable +store.run(data, () => { + strictEqual(store.getStore(), data); + Promise.resolve(thenable()); + strictEqual(store.getStore(), data); +}); + +// Returning a thenable in a then handler +store.run(data, () => { + strictEqual(store.getStore(), data); + Promise.resolve().then(() => thenable()); + strictEqual(store.getStore(), data); +}); diff --git a/test/async-hooks/test-async-local-storage-tlssocket.mjs b/test/async-hooks/test-async-local-storage-tlssocket.mjs new file mode 100644 index 00000000000000..7664c86570a392 --- /dev/null +++ b/test/async-hooks/test-async-local-storage-tlssocket.mjs @@ -0,0 +1,33 @@ +import { hasCrypto, skip } from '../common/index.mjs'; +if (!hasCrypto) + skip('missing crypto'); + +// Regression tests for https://github.com/nodejs/node/issues/40693 + +import { deepStrictEqual } from 'assert'; +import { readKey } from '../common/fixtures.mjs'; +import { createServer, connect } from 'tls'; +import { AsyncLocalStorage } from 'async_hooks'; + +const options = { + cert: readKey('rsa_cert.crt'), + key: readKey('rsa_private.pem'), + rejectUnauthorized: false +}; + +createServer(options, (socket) => { + socket.write('Hello, world!'); + socket.pipe(socket); + }) + .listen(0, function() { + const asyncLocalStorage = new AsyncLocalStorage(); + const store = { val: 'abcd' }; + asyncLocalStorage.run(store, () => { + const client = connect({ port: this.address().port, ...options }); + client.on('data', () => { + deepStrictEqual(asyncLocalStorage.getStore(), store); + client.end(); + this.close(); + }); + }); + }); diff --git a/test/async-hooks/test-async-wrap-providers.mjs b/test/async-hooks/test-async-wrap-providers.mjs new file mode 100644 index 00000000000000..bbaa5048d685a9 --- /dev/null +++ b/test/async-hooks/test-async-wrap-providers.mjs @@ -0,0 +1,19 @@ +// Flags: --expose-internals + +import { expectsError } from '../common/index.mjs'; +import internalTestBinding from 'internal/test/binding'; +import { ok, deepStrictEqual, throws } from 'assert'; +import { asyncWrapProviders } from 'async_hooks'; + +const { internalBinding } = internalTestBinding; +const providers = internalBinding('async_wrap').Providers; + +ok(typeof asyncWrapProviders === 'object'); +deepStrictEqual(asyncWrapProviders, { __proto__: null, ...providers }); + +const providerKeys = Object.keys(asyncWrapProviders); +throws(() => { + asyncWrapProviders[providerKeys[0]] = 'another value'; +}, expectsError({ + name: 'TypeError', +}), 'should not allow modify asyncWrap providers'); diff --git a/test/async-hooks/test-callback-error.mjs b/test/async-hooks/test-callback-error.mjs new file mode 100644 index 00000000000000..a94e7f5523fab0 --- /dev/null +++ b/test/async-hooks/test-callback-error.mjs @@ -0,0 +1,92 @@ +import { mustCall, isWindows } from '../common/index.mjs'; +import { ok, ifError, strictEqual } from 'assert'; +import { spawnSync } from 'child_process'; +import { argv, execPath, exit } from 'process'; +import { AsyncResource } from 'async_hooks'; +import initHooks from './init-hooks.mjs'; +import { fileURLToPath } from 'url'; + +const __filename = fileURLToPath(import.meta.url); + +const arg = argv[2]; +switch (arg) { + case 'test_init_callback': + initHooks({ + oninit: mustCall(() => { throw new Error(arg); }) + }).enable(); + new AsyncResource(`${arg}_type`); + exit(); + + case 'test_callback': { + initHooks({ + onbefore: mustCall(() => { throw new Error(arg); }) + }).enable(); + const resource = new AsyncResource(`${arg}_type`); + resource.runInAsyncScope(() => {}); + exit(); + } + + case 'test_callback_abort': + initHooks({ + oninit: mustCall(() => { throw new Error(arg); }) + }).enable(); + new AsyncResource(`${arg}_type`); + exit(); +} + +// This part should run only for the primary test +ok(!arg); +{ + // console.log should stay until this test's flakiness is solved + console.log('start case 1'); + console.time('end case 1'); + const child = spawnSync(execPath, [__filename, 'test_init_callback']); + ifError(child.error); + const test_init_first_line = child.stderr.toString().split(/[\r\n]+/g)[0]; + strictEqual(test_init_first_line, 'Error: test_init_callback'); + strictEqual(child.status, 1); + console.timeEnd('end case 1'); +} + +{ + console.log('start case 2'); + console.time('end case 2'); + const child = spawnSync(execPath, [__filename, 'test_callback']); + ifError(child.error); + const test_callback_first_line = child.stderr.toString().split(/[\r\n]+/g)[0]; + strictEqual(test_callback_first_line, 'Error: test_callback'); + strictEqual(child.status, 1); + console.timeEnd('end case 2'); +} + +{ + console.log('start case 3'); + console.time('end case 3'); + let program = execPath; + let args = [ + '--abort-on-uncaught-exception', __filename, 'test_callback_abort' ]; + const options = { encoding: 'utf8' }; + if (!isWindows) { + program = `ulimit -c 0 && exec ${program} ${args.join(' ')}`; + args = []; + options.shell = true; + } + const child = spawnSync(program, args, options); + if (isWindows) { + strictEqual(child.status, 134); + strictEqual(child.signal, null); + } else { + strictEqual(child.status, null); + // Most posix systems will show 'SIGABRT', but alpine34 does not + if (child.signal !== 'SIGABRT') { + console.log(`primary received signal ${child.signal}\nchild's stderr:`); + console.log(child.stderr); + exit(1); + } + strictEqual(child.signal, 'SIGABRT'); + } + strictEqual(child.stdout, ''); + const firstLineStderr = child.stderr.split(/[\r\n]+/g)[0].trim(); + strictEqual(firstLineStderr, 'Error: test_callback_abort'); + console.timeEnd('end case 3'); +} diff --git a/test/async-hooks/test-crypto-pbkdf2.mjs b/test/async-hooks/test-crypto-pbkdf2.mjs new file mode 100644 index 00000000000000..1dd07c79d8b533 --- /dev/null +++ b/test/async-hooks/test-crypto-pbkdf2.mjs @@ -0,0 +1,42 @@ +import { hasCrypto, skip, isMainThread, mustCall } from '../common/index.mjs'; +if (!hasCrypto) + skip('missing crypto'); +if (!isMainThread) + skip('Worker bootstrapping works differently -> different async IDs'); + +import { strictEqual } from 'assert'; +import tick from '../common/tick.js'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; +import { pbkdf2 } from 'crypto'; +import process from 'process'; + + +const hooks = initHooks(); + +hooks.enable(); + +pbkdf2('password', 'salt', 1, 20, 'sha256', mustCall(onpbkdf2)); + +function onpbkdf2() { + const as = hooks.activitiesOfTypes('PBKDF2REQUEST'); + const a = as[0]; + checkInvocations(a, { init: 1, before: 1 }, 'while in onpbkdf2 callback'); + tick(2); +} + +process.on('exit', onexit); +function onexit() { + hooks.disable(); + hooks.sanityCheck('PBKDF2REQUEST'); + + const as = hooks.activitiesOfTypes('PBKDF2REQUEST'); + strictEqual(as.length, 1); + + const a = as[0]; + strictEqual(a.type, 'PBKDF2REQUEST'); + strictEqual(typeof a.uid, 'number'); + strictEqual(a.triggerAsyncId, 1); + checkInvocations(a, { init: 1, before: 1, after: 1, destroy: 1 }, + 'when process exits'); +} diff --git a/test/async-hooks/test-crypto-randomBytes.mjs b/test/async-hooks/test-crypto-randomBytes.mjs new file mode 100644 index 00000000000000..97d08fcf8a1549 --- /dev/null +++ b/test/async-hooks/test-crypto-randomBytes.mjs @@ -0,0 +1,43 @@ +import { hasCrypto, skip, isMainThread, mustCall } from '../common/index.mjs'; +if (!hasCrypto) + skip('missing crypto'); +if (!isMainThread) + skip('Worker bootstrapping works differently -> different async IDs'); + +import { strictEqual } from 'assert'; +import tick from '../common/tick.js'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; +import { randomBytes } from 'crypto'; +import process from 'process'; + + +const hooks = initHooks(); + +hooks.enable(); +randomBytes(1, mustCall(onrandomBytes)); + +function onrandomBytes() { + const as = hooks.activitiesOfTypes('RANDOMBYTESREQUEST'); + const a = as[0]; + checkInvocations(a, { init: 1, before: 1 }, + 'while in onrandomBytes callback'); + tick(2); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('RANDOMBYTESREQUEST'); + + const as = hooks.activitiesOfTypes('RANDOMBYTESREQUEST'); + strictEqual(as.length, 1); + + const a = as[0]; + strictEqual(a.type, 'RANDOMBYTESREQUEST'); + strictEqual(typeof a.uid, 'number'); + strictEqual(a.triggerAsyncId, 1); + checkInvocations(a, { init: 1, before: 1, after: 1, destroy: 1 }, + 'when process exits'); +} diff --git a/test/async-hooks/test-destroy-not-blocked.mjs b/test/async-hooks/test-destroy-not-blocked.mjs new file mode 100644 index 00000000000000..a85305cc1f79b4 --- /dev/null +++ b/test/async-hooks/test-destroy-not-blocked.mjs @@ -0,0 +1,97 @@ +// Flags: --expose_gc + +import { mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import tick from '../common/tick.js'; + +import { createHook, AsyncResource } from 'async_hooks'; +import process from 'process'; + +// Test priority of destroy hook relative to nextTick,... and +// verify a microtask is scheduled in case a lot items are queued + +const resType = 'MyResource'; +let activeId = -1; +createHook({ + init(id, type) { + if (type === resType) { + strictEqual(activeId, -1); + activeId = id; + } + }, + destroy(id) { + if (activeId === id) { + activeId = -1; + } + } +}).enable(); + +function testNextTick() { + strictEqual(activeId, -1); + const res = new AsyncResource(resType); + strictEqual(activeId, res.asyncId()); + res.emitDestroy(); + // nextTick has higher prio than emit destroy + process.nextTick(mustCall(() => + strictEqual(activeId, res.asyncId())) + ); +} + +function testQueueMicrotask() { + strictEqual(activeId, -1); + const res = new AsyncResource(resType); + strictEqual(activeId, res.asyncId()); + res.emitDestroy(); + // queueMicrotask has higher prio than emit destroy + queueMicrotask(mustCall(() => + strictEqual(activeId, res.asyncId())) + ); +} + +function testImmediate() { + strictEqual(activeId, -1); + const res = new AsyncResource(resType); + strictEqual(activeId, res.asyncId()); + res.emitDestroy(); + setImmediate(mustCall(() => + strictEqual(activeId, -1)) + ); +} + +function testPromise() { + strictEqual(activeId, -1); + const res = new AsyncResource(resType); + strictEqual(activeId, res.asyncId()); + res.emitDestroy(); + // Promise has higher prio than emit destroy + Promise.resolve().then(mustCall(() => + strictEqual(activeId, res.asyncId())) + ); +} + +async function testAwait() { + strictEqual(activeId, -1); + const res = new AsyncResource(resType); + strictEqual(activeId, res.asyncId()); + res.emitDestroy(); + + for (let i = 0; i < 5000; i++) { + await Promise.resolve(); + } + globalThis.gc(); + await Promise.resolve(); + // Limit to trigger a microtask not yet reached + strictEqual(activeId, res.asyncId()); + for (let i = 0; i < 5000; i++) { + await Promise.resolve(); + } + globalThis.gc(); + await Promise.resolve(); + strictEqual(activeId, -1); +} + +testNextTick(); +tick(2, testQueueMicrotask); +tick(4, testImmediate); +tick(6, testPromise); +tick(8, () => testAwait().then(mustCall())); diff --git a/test/async-hooks/test-disable-in-init.mjs b/test/async-hooks/test-disable-in-init.mjs new file mode 100644 index 00000000000000..cc410d8383ec08 --- /dev/null +++ b/test/async-hooks/test-disable-in-init.mjs @@ -0,0 +1,24 @@ +import { mustCall } from '../common/index.mjs'; +import { createHook } from 'async_hooks'; +import { access } from 'fs'; +import { fileURLToPath } from 'url'; + +const __filename = fileURLToPath(import.meta.url); + +let nestedCall = false; + +createHook({ + init: mustCall(() => { + nestedHook.disable(); + if (!nestedCall) { + nestedCall = true; + access(__filename, mustCall()); + } + }, 2) +}).enable(); + +const nestedHook = createHook({ + init: mustCall(2) +}).enable(); + +access(__filename, mustCall()); diff --git a/test/async-hooks/test-embedder.api.async-resource-no-type.mjs b/test/async-hooks/test-embedder.api.async-resource-no-type.mjs new file mode 100644 index 00000000000000..b69e68b54a6b65 --- /dev/null +++ b/test/async-hooks/test-embedder.api.async-resource-no-type.mjs @@ -0,0 +1,32 @@ +import { mustCall } from '../common/index.mjs'; +import { throws, strictEqual } from 'assert'; +import { AsyncResource, executionAsyncId } from 'async_hooks'; +import { spawn } from 'child_process'; +import { argv, execPath } from 'process'; + +import initHooks from './init-hooks.mjs'; + +if (argv[2] === 'child') { + initHooks().enable(); + + class Foo extends AsyncResource { + constructor(type) { + super(type, executionAsyncId()); + } + } + + [null, undefined, 1, Date, {}, []].forEach((i) => { + throws(() => new Foo(i), { + code: 'ERR_INVALID_ARG_TYPE', + name: 'TypeError' + }); + }); + +} else { + const args = argv.slice(1).concat('child'); + spawn(execPath, args) + .on('close', mustCall((code) => { + // No error because the type was defaulted + strictEqual(code, 0); + })); +} diff --git a/test/async-hooks/test-embedder.api.async-resource.mjs b/test/async-hooks/test-embedder.api.async-resource.mjs new file mode 100644 index 00000000000000..bf0d73fbb1f255 --- /dev/null +++ b/test/async-hooks/test-embedder.api.async-resource.mjs @@ -0,0 +1,100 @@ +import { mustCall } from '../common/index.mjs'; +import { throws, strictEqual, notStrictEqual } from 'assert'; +import tick from '../common/tick.js'; +import { AsyncResource, executionAsyncId } from 'async_hooks'; + +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; + +const hooks = initHooks(); +hooks.enable(); + +throws( + () => new AsyncResource(), { + code: 'ERR_INVALID_ARG_TYPE', + name: 'TypeError', + }); +throws(() => { + new AsyncResource('invalid_trigger_id', { triggerAsyncId: null }); +}, { + code: 'ERR_INVALID_ASYNC_ID', + name: 'RangeError', +}); + +strictEqual( + new AsyncResource('default_trigger_id').triggerAsyncId(), + executionAsyncId() +); + +// Create first custom event 'alcazares' with triggerAsyncId derived +// from async_hooks executionAsyncId +const alcaTriggerId = executionAsyncId(); +const alcaEvent = new AsyncResource('alcazares', alcaTriggerId); +const alcazaresActivities = hooks.activitiesOfTypes([ 'alcazares' ]); + +// Alcazares event was constructed and thus only has an `init` call +strictEqual(alcazaresActivities.length, 1); +const alcazares = alcazaresActivities[0]; +strictEqual(alcazares.type, 'alcazares'); +strictEqual(typeof alcazares.uid, 'number'); +strictEqual(alcazares.triggerAsyncId, alcaTriggerId); +checkInvocations(alcazares, { init: 1 }, 'alcazares constructed'); + +strictEqual(typeof alcaEvent.asyncId(), 'number'); +notStrictEqual(alcaEvent.asyncId(), alcaTriggerId); +strictEqual(alcaEvent.triggerAsyncId(), alcaTriggerId); + +alcaEvent.runInAsyncScope(() => { + checkInvocations(alcazares, { init: 1, before: 1 }, + 'alcazares emitted before'); +}); +checkInvocations(alcazares, { init: 1, before: 1, after: 1 }, + 'alcazares emitted after'); +alcaEvent.runInAsyncScope(() => { + checkInvocations(alcazares, { init: 1, before: 2, after: 1 }, + 'alcazares emitted before again'); +}); +checkInvocations(alcazares, { init: 1, before: 2, after: 2 }, + 'alcazares emitted after again'); +alcaEvent.emitDestroy(); +tick(1, mustCall(tick1)); + +function tick1() { + checkInvocations(alcazares, { init: 1, before: 2, after: 2, destroy: 1 }, + 'alcazares emitted destroy'); + + // The below shows that we can pass any number as a trigger id + const pobTriggerId = 111; + const pobEvent = new AsyncResource('poblado', pobTriggerId); + const pobladoActivities = hooks.activitiesOfTypes([ 'poblado' ]); + const poblado = pobladoActivities[0]; + strictEqual(poblado.type, 'poblado'); + strictEqual(typeof poblado.uid, 'number'); + strictEqual(poblado.triggerAsyncId, pobTriggerId); + checkInvocations(poblado, { init: 1 }, 'poblado constructed'); + pobEvent.runInAsyncScope(() => { + checkInvocations(poblado, { init: 1, before: 1 }, + 'poblado emitted before'); + }); + + checkInvocations(poblado, { init: 1, before: 1, after: 1 }, + 'poblado emitted after'); + + // After we disable the hooks we shouldn't receive any events anymore + hooks.disable(); + alcaEvent.emitDestroy(); + tick(1, mustCall(tick2)); + + function tick2() { + checkInvocations( + alcazares, { init: 1, before: 2, after: 2, destroy: 1 }, + 'alcazares emitted destroy a second time after hooks disabled'); + pobEvent.emitDestroy(); + tick(1, mustCall(tick3)); + } + + function tick3() { + checkInvocations(poblado, { init: 1, before: 1, after: 1 }, + 'poblado emitted destroy after hooks disabled'); + } +} diff --git a/test/async-hooks/test-embedder.api.async-resource.runInAsyncScope.mjs b/test/async-hooks/test-embedder.api.async-resource.runInAsyncScope.mjs new file mode 100644 index 00000000000000..028a5b3448cfd3 --- /dev/null +++ b/test/async-hooks/test-embedder.api.async-resource.runInAsyncScope.mjs @@ -0,0 +1,10 @@ +import '../common/index.mjs'; +import { strictEqual } from 'assert'; +import { AsyncResource } from 'async_hooks'; + +// Ensure that asyncResource.makeCallback returns the callback return value. +const a = new AsyncResource('foobar'); +const ret = a.runInAsyncScope(() => { + return 1729; +}); +strictEqual(ret, 1729); diff --git a/test/async-hooks/test-emit-after-on-destroyed.mjs b/test/async-hooks/test-emit-after-on-destroyed.mjs new file mode 100644 index 00000000000000..921ff98258e58c --- /dev/null +++ b/test/async-hooks/test-emit-after-on-destroyed.mjs @@ -0,0 +1,65 @@ +// Flags: --expose-internals + +import { mustCall } from '../common/index.mjs'; +import { strictEqual, match } from 'assert'; +import internalAsyncHooks from 'internal/async_hooks'; +import { spawn } from 'child_process'; +import { argv, execPath } from 'process'; + +const corruptedMsg = /async hook stack has become corrupted/; +const heartbeatMsg = /heartbeat: still alive/; + +const { + newAsyncId, getDefaultTriggerAsyncId, + emitInit, emitBefore, emitAfter, emitDestroy +} = internalAsyncHooks; + +import initHooks from './init-hooks.mjs'; + +if (argv[2] === 'child') { + const hooks = initHooks(); + hooks.enable(); + + // Once 'destroy' has been emitted, we can no longer emit 'after' + + // Emitting 'before', 'after' and then 'destroy' + { + const asyncId = newAsyncId(); + const triggerId = getDefaultTriggerAsyncId(); + emitInit(asyncId, 'event1', triggerId, {}); + emitBefore(asyncId, triggerId); + emitAfter(asyncId); + emitDestroy(asyncId); + } + + // Emitting 'after' after 'destroy' + { + const asyncId = newAsyncId(); + const triggerId = getDefaultTriggerAsyncId(); + emitInit(asyncId, 'event2', triggerId, {}); + emitDestroy(asyncId); + + console.log('heartbeat: still alive'); + emitAfter(asyncId); + } +} else { + const args = ['--expose-internals'] + .concat(argv.slice(1)) + .concat('child'); + let errData = Buffer.from(''); + let outData = Buffer.from(''); + + const child = spawn(execPath, args); + child.stderr.on('data', (d) => { errData = Buffer.concat([ errData, d ]); }); + child.stdout.on('data', (d) => { outData = Buffer.concat([ outData, d ]); }); + + child.on('close', mustCall((code) => { + strictEqual(code, 1); + match(outData.toString(), heartbeatMsg, + 'did not crash until we reached offending line of code ' + + `(found ${outData})`); + match(errData.toString(), corruptedMsg, + 'printed error contains corrupted message ' + + `(found ${errData})`); + })); +} diff --git a/test/async-hooks/test-emit-before-after.mjs b/test/async-hooks/test-emit-before-after.mjs new file mode 100644 index 00000000000000..ae6521c359a26d --- /dev/null +++ b/test/async-hooks/test-emit-before-after.mjs @@ -0,0 +1,38 @@ +// Flags: --expose-internals + +import { mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import internalAsyncHooks from 'internal/async_hooks'; +import initHooks from './init-hooks.mjs'; + +const { newAsyncId, emitBefore, emitAfter, emitInit } = internalAsyncHooks; +const expectedId = newAsyncId(); +const expectedTriggerId = newAsyncId(); +const expectedType = 'test_emit_before_after_type'; + +// Verify that if there is no registered hook, then nothing will happen. +emitBefore(expectedId, expectedTriggerId); +emitAfter(expectedId); + +const chkBefore = mustCall((id) => strictEqual(id, expectedId)); +const chkAfter = mustCall((id) => strictEqual(id, expectedId)); + +const checkOnce = (fn) => { + let called = false; + return (...args) => { + if (called) return; + + called = true; + fn(...args); + }; +}; + +initHooks({ + onbefore: checkOnce(chkBefore), + onafter: checkOnce(chkAfter), + allowNoInit: true +}).enable(); + +emitInit(expectedId, expectedType, expectedTriggerId); +emitBefore(expectedId, expectedTriggerId); +emitAfter(expectedId); diff --git a/test/async-hooks/test-emit-before-on-destroyed.mjs b/test/async-hooks/test-emit-before-on-destroyed.mjs new file mode 100644 index 00000000000000..0a03e4038d6bf2 --- /dev/null +++ b/test/async-hooks/test-emit-before-on-destroyed.mjs @@ -0,0 +1,64 @@ +// Flags: --expose-internals +import { mustCall } from '../common/index.mjs'; +import { strictEqual, match } from 'assert'; +import internalAsyncHooks from 'internal/async_hooks'; +import { spawn } from 'child_process'; +import { argv, execPath } from 'process'; + +const corruptedMsg = /async hook stack has become corrupted/; +const heartbeatMsg = /heartbeat: still alive/; + +const { + newAsyncId, getDefaultTriggerAsyncId, + emitInit, emitBefore, emitAfter, emitDestroy +} = internalAsyncHooks; + +import initHooks from './init-hooks.mjs'; + +if (argv[2] === 'child') { + const hooks = initHooks(); + hooks.enable(); + + // Once 'destroy' has been emitted, we can no longer emit 'before' + + // Emitting 'before', 'after' and then 'destroy' + { + const asyncId = newAsyncId(); + const triggerId = getDefaultTriggerAsyncId(); + emitInit(asyncId, 'event1', triggerId, {}); + emitBefore(asyncId, triggerId); + emitAfter(asyncId); + emitDestroy(asyncId); + } + + // Emitting 'before' after 'destroy' + { + const asyncId = newAsyncId(); + const triggerId = getDefaultTriggerAsyncId(); + emitInit(asyncId, 'event2', triggerId, {}); + emitDestroy(asyncId); + + console.log('heartbeat: still alive'); + emitBefore(asyncId, triggerId); + } +} else { + const args = ['--expose-internals'] + .concat(argv.slice(1)) + .concat('child'); + let errData = Buffer.from(''); + let outData = Buffer.from(''); + + const child = spawn(execPath, args); + child.stderr.on('data', (d) => { errData = Buffer.concat([ errData, d ]); }); + child.stdout.on('data', (d) => { outData = Buffer.concat([ outData, d ]); }); + + child.on('close', mustCall((code) => { + strictEqual(code, 1); + match(outData.toString(), heartbeatMsg, + 'did not crash until we reached offending line of code ' + + `(found ${outData})`); + match(errData.toString(), corruptedMsg, + 'printed error contains corrupted message ' + + `(found ${errData})`); + })); +} diff --git a/test/async-hooks/test-emit-init.mjs b/test/async-hooks/test-emit-init.mjs new file mode 100644 index 00000000000000..c1b9870e587b6c --- /dev/null +++ b/test/async-hooks/test-emit-init.mjs @@ -0,0 +1,39 @@ +// Flags: --expose-internals + +import { mustCall } from '../common/index.mjs'; +import { strictEqual, notStrictEqual } from 'assert'; +import internalAsyncHooks from 'internal/async_hooks'; +import initHooks from './init-hooks.mjs'; + +const { newAsyncId, emitInit } = internalAsyncHooks; +const expectedId = newAsyncId(); +const expectedTriggerId = newAsyncId(); +const expectedType = 'test_emit_init_type'; +const expectedResource = { key: 'test_emit_init_resource' }; + +const hooks1 = initHooks({ + oninit: mustCall((id, type, triggerAsyncId, resource) => { + strictEqual(id, expectedId); + strictEqual(type, expectedType); + strictEqual(triggerAsyncId, expectedTriggerId); + strictEqual(resource.key, expectedResource.key); + }) +}); + +hooks1.enable(); + +emitInit(expectedId, expectedType, expectedTriggerId, + expectedResource); + +hooks1.disable(); + +initHooks({ + oninit: mustCall((id, type, triggerAsyncId, resource) => { + strictEqual(id, expectedId); + strictEqual(type, expectedType); + notStrictEqual(triggerAsyncId, expectedTriggerId); + strictEqual(resource.key, expectedResource.key); + }) +}).enable(); + +emitInit(expectedId, expectedType, null, expectedResource); diff --git a/test/async-hooks/test-enable-disable.mjs b/test/async-hooks/test-enable-disable.mjs new file mode 100644 index 00000000000000..de865be4cd1f52 --- /dev/null +++ b/test/async-hooks/test-enable-disable.mjs @@ -0,0 +1,266 @@ +// Test Steps Explained +// ==================== +// +// Initializing hooks: +// +// We initialize 3 hooks. For hook2 and hook3 we register a callback for the +// "before" and in case of hook3 also for the "after" invocations. +// +// Enabling hooks initially: +// +// We only enable hook1 and hook3 initially. +// +// Enabling hook2: +// +// When hook3's "before" invocation occurs we enable hook2. Since this +// happens right before calling `onfirstImmediate` hook2 will miss all hook +// invocations until then, including the "init" and "before" of the first +// Immediate. +// However afterwards it collects all invocations that follow on the first +// Immediate as well as all invocations on the second Immediate. +// +// This shows that a hook can enable another hook inside a life time event +// callback. +// +// +// Disabling hook1 +// +// Since we registered the "before" callback for hook2 it will execute it +// right before `onsecondImmediate` is called. +// At that point we disable hook1 which is why it will miss all invocations +// afterwards and thus won't include the second "after" as well as the +// "destroy" invocations +// +// This shows that a hook can disable another hook inside a life time event +// callback. +// +// Disabling hook3 +// +// When the second "after" invocation occurs (after onsecondImmediate), hook3 +// disables itself. +// As a result it will not receive the "destroy" invocation. +// +// This shows that a hook can disable itself inside a life time event callback. +// +// Sample Test Log +// =============== +// +// - setting up first Immediate +// hook1.init.uid-5 +// hook3.init.uid-5 +// - finished setting first Immediate +// +// hook1.before.uid-5 +// hook3.before.uid-5 +// - enabled hook2 +// - entering onfirstImmediate +// +// - setting up second Immediate +// hook1.init.uid-6 +// hook3.init.uid-6 +// hook2.init.uid-6 +// - finished setting second Immediate +// +// - exiting onfirstImmediate +// hook1.after.uid-5 +// hook3.after.uid-5 +// hook2.after.uid-5 +// hook1.destroy.uid-5 +// hook3.destroy.uid-5 +// hook2.destroy.uid-5 +// hook1.before.uid-6 +// hook3.before.uid-6 +// hook2.before.uid-6 +// - disabled hook1 +// - entering onsecondImmediate +// - exiting onsecondImmediate +// hook3.after.uid-6 +// - disabled hook3 +// hook2.after.uid-6 +// hook2.destroy.uid-6 + + +import { isMainThread, skip, mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import process from 'process'; +import tick from '../common/tick.js'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; + +if (!isMainThread) + skip('Worker bootstrapping works differently -> different timing'); + +// Include "Unknown"s because hook2 will not be able to identify +// the type of the first Immediate since it will miss its `init` invocation. +const types = [ 'Immediate', 'Unknown' ]; + +// +// Initializing hooks +// +const hook1 = initHooks(); +const hook2 = initHooks({ onbefore: onhook2Before, allowNoInit: true }); +const hook3 = initHooks({ onbefore: onhook3Before, onafter: onhook3After }); + +// +// Enabling hook1 and hook3 only, hook2 is still disabled +// +hook1.enable(); +// Verify that the hook is enabled even if .enable() is called twice. +hook1.enable(); +hook3.enable(); + +// +// Enabling hook2 +// +let enabledHook2 = false; +function onhook3Before() { + if (enabledHook2) return; + hook2.enable(); + enabledHook2 = true; +} + +// +// Disabling hook1 +// +let disabledHook3 = false; +function onhook2Before() { + if (disabledHook3) return; + hook1.disable(); + // Verify that the hook is disabled even if .disable() is called twice. + hook1.disable(); + disabledHook3 = true; +} + +// +// Disabling hook3 during the second "after" invocations it sees +// +let count = 2; +function onhook3After() { + if (!--count) { + hook3.disable(); + } +} + +setImmediate(mustCall(onfirstImmediate)); + +// +// onfirstImmediate is called after all "init" and "before" callbacks of the +// active hooks were invoked +// +function onfirstImmediate() { + const as1 = hook1.activitiesOfTypes(types); + const as2 = hook2.activitiesOfTypes(types); + const as3 = hook3.activitiesOfTypes(types); + strictEqual(as1.length, 1); + // hook2 was not enabled yet .. it is enabled after hook3's "before" completed + strictEqual(as2.length, 0); + strictEqual(as3.length, 1); + + // Check that hook1 and hook3 captured the same Immediate and that it is valid + const firstImmediate = as1[0]; + strictEqual(as3[0].uid, as1[0].uid); + strictEqual(firstImmediate.type, 'Immediate'); + strictEqual(typeof firstImmediate.uid, 'number'); + strictEqual(typeof firstImmediate.triggerAsyncId, 'number'); + checkInvocations(as1[0], { init: 1, before: 1 }, + 'hook1[0]: on first immediate'); + checkInvocations(as3[0], { init: 1, before: 1 }, + 'hook3[0]: on first immediate'); + + // Setup the second Immediate, note that now hook2 is enabled and thus + // will capture all lifetime events of this Immediate + setImmediate(mustCall(onsecondImmediate)); +} + +// +// Once we exit onfirstImmediate the "after" callbacks of the active hooks are +// invoked +// + +let hook1First, hook2First, hook3First; +let hook1Second, hook2Second, hook3Second; + +// +// onsecondImmediate is called after all "before" callbacks of the active hooks +// are invoked again +// +function onsecondImmediate() { + const as1 = hook1.activitiesOfTypes(types); + const as2 = hook2.activitiesOfTypes(types); + const as3 = hook3.activitiesOfTypes(types); + strictEqual(as1.length, 2); + strictEqual(as2.length, 2); + strictEqual(as3.length, 2); + + // Assign the info collected by each hook for each immediate for easier + // reference. + // hook2 saw the "init" of the second immediate before the + // "after" of the first which is why they are ordered the opposite way + hook1First = as1[0]; + hook1Second = as1[1]; + hook2First = as2[1]; + hook2Second = as2[0]; + hook3First = as3[0]; + hook3Second = as3[1]; + + // Check that all hooks captured the same Immediate and that it is valid + const secondImmediate = hook1Second; + strictEqual(hook2Second.uid, hook3Second.uid); + strictEqual(hook1Second.uid, hook3Second.uid); + strictEqual(secondImmediate.type, 'Immediate'); + strictEqual(typeof secondImmediate.uid, 'number'); + strictEqual(typeof secondImmediate.triggerAsyncId, 'number'); + + checkInvocations(hook1First, { init: 1, before: 1, after: 1, destroy: 1 }, + 'hook1First: on second immediate'); + checkInvocations(hook1Second, { init: 1, before: 1 }, + 'hook1Second: on second immediate'); + // hook2 missed the "init" and "before" since it was enabled after they + // occurred + checkInvocations(hook2First, { after: 1, destroy: 1 }, + 'hook2First: on second immediate'); + checkInvocations(hook2Second, { init: 1, before: 1 }, + 'hook2Second: on second immediate'); + checkInvocations(hook3First, { init: 1, before: 1, after: 1, destroy: 1 }, + 'hook3First: on second immediate'); + checkInvocations(hook3Second, { init: 1, before: 1 }, + 'hook3Second: on second immediate'); + tick(1); +} + +// +// Once we exit onsecondImmediate the "after" callbacks of the active hooks are +// invoked again. +// During this second "after" invocation hook3 disables itself +// (see onhook3After). +// + +process.on('exit', onexit); + +function onexit() { + hook1.disable(); + hook2.disable(); + hook3.disable(); + hook1.sanityCheck(); + hook2.sanityCheck(); + hook3.sanityCheck(); + + checkInvocations(hook1First, { init: 1, before: 1, after: 1, destroy: 1 }, + 'hook1First: when process exits'); + // hook1 was disabled during hook2's "before" of the second immediate + // and thus did not see "after" and "destroy" + checkInvocations(hook1Second, { init: 1, before: 1 }, + 'hook1Second: when process exits'); + // hook2 missed the "init" and "before" since it was enabled after they + // occurred + checkInvocations(hook2First, { after: 1, destroy: 1 }, + 'hook2First: when process exits'); + checkInvocations(hook2Second, { init: 1, before: 1, after: 1, destroy: 1 }, + 'hook2Second: when process exits'); + checkInvocations(hook3First, { init: 1, before: 1, after: 1, destroy: 1 }, + 'hook3First: when process exits'); + // We don't see a "destroy" invocation here since hook3 disabled itself + // during its "after" invocation + checkInvocations(hook3Second, { init: 1, before: 1, after: 1 }, + 'hook3Second: when process exits'); +} diff --git a/test/async-hooks/test-enable-in-init.mjs b/test/async-hooks/test-enable-in-init.mjs new file mode 100644 index 00000000000000..bbbac907b44fb2 --- /dev/null +++ b/test/async-hooks/test-enable-in-init.mjs @@ -0,0 +1,23 @@ +import { mustNotCall, mustCall } from '../common/index.mjs'; +import { createHook } from 'async_hooks'; +import { access } from 'fs'; +import { fileURLToPath } from 'url'; + +const __filename = fileURLToPath(import.meta.url); + +const nestedHook = createHook({ + init: mustNotCall() +}); +let nestedCall = false; + +createHook({ + init: mustCall(() => { + nestedHook.enable(); + if (!nestedCall) { + nestedCall = true; + access(__filename, mustCall()); + } + }, 2) +}).enable(); + +access(__filename, mustCall()); diff --git a/test/async-hooks/test-filehandle-no-reuse.mjs b/test/async-hooks/test-filehandle-no-reuse.mjs new file mode 100644 index 00000000000000..c4102b97609c03 --- /dev/null +++ b/test/async-hooks/test-filehandle-no-reuse.mjs @@ -0,0 +1,64 @@ +import { hasCrypto, skip, mustCall } from '../common/index.mjs'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; +import { path } from '../common/fixtures.mjs'; +if (!hasCrypto) + skip('missing crypto'); +import { constants, createServer, connect } from 'http2'; +import { ok } from 'assert'; +import { openSync, closeSync } from 'fs'; +import process from 'process'; + +// Checks that the async resource is not reused by FileHandle. +// Test is based on parallel\test-http2-respond-file-fd.js. + +const hooks = initHooks(); +hooks.enable(); + +const { + HTTP2_HEADER_CONTENT_TYPE +} = constants; + +// Use large fixture to get several file operations. +const fname = path('person-large.jpg'); +const fd = openSync(fname, 'r'); + +const server = createServer(); +server.on('stream', (stream) => { + stream.respondWithFD(fd, { + [HTTP2_HEADER_CONTENT_TYPE]: 'text/plain' + }); +}); +server.on('close', mustCall(() => closeSync(fd))); +server.listen(0, () => { + const client = connect(`http://localhost:${server.address().port}`); + const req = client.request(); + + req.on('response', mustCall()); + req.on('data', () => {}); + req.on('end', mustCall(() => { + client.close(); + server.close(); + })); + req.end(); +}); + +process.on('exit', onExit); + +function onExit() { + hooks.disable(); + hooks.sanityCheck(); + const activities = hooks.activities; + + // Verify both invocations + const fsReqs = activities.filter((x) => x.type === 'FSREQCALLBACK'); + ok(fsReqs.length >= 2); + + checkInvocations(fsReqs[0], { init: 1, destroy: 1 }, 'when process exits'); + checkInvocations(fsReqs[1], { init: 1, destroy: 1 }, 'when process exits'); + + // Verify reuse handle has been wrapped + ok(fsReqs[0].handle !== fsReqs[1].handle, 'Resource reused'); + ok(fsReqs[0].handle === fsReqs[1].handle.handle, + 'Resource not wrapped correctly'); +} diff --git a/test/async-hooks/test-fseventwrap.mjs b/test/async-hooks/test-fseventwrap.mjs new file mode 100644 index 00000000000000..76321ed01adafa --- /dev/null +++ b/test/async-hooks/test-fseventwrap.mjs @@ -0,0 +1,42 @@ +import { isMainThread, skip, isIBMi } from '../common/index.mjs'; + +import { strictEqual } from 'assert'; +import initHooks from './init-hooks.mjs'; +import tick from '../common/tick.js'; +import { checkInvocations } from './hook-checks.mjs'; +import { watch } from 'fs'; +import process from 'process'; +import { fileURLToPath } from 'url'; + +const __filename = fileURLToPath(import.meta.url); + +if (!isMainThread) + skip('Worker bootstrapping works differently -> different async IDs'); + +if (isIBMi) + skip('IBMi does not support fs.watch()'); + +const hooks = initHooks(); + +hooks.enable(); +const watcher = watch(__filename, onwatcherChanged); +function onwatcherChanged() { } + +watcher.close(); +tick(2); + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('FSEVENTWRAP'); + + const as = hooks.activitiesOfTypes('FSEVENTWRAP'); + strictEqual(as.length, 1); + + const a = as[0]; + strictEqual(a.type, 'FSEVENTWRAP'); + strictEqual(typeof a.uid, 'number'); + strictEqual(a.triggerAsyncId, 1); + checkInvocations(a, { init: 1, destroy: 1 }, 'when process exits'); +} diff --git a/test/async-hooks/test-fsreqcallback-access.mjs b/test/async-hooks/test-fsreqcallback-access.mjs new file mode 100644 index 00000000000000..4981b2749cab54 --- /dev/null +++ b/test/async-hooks/test-fsreqcallback-access.mjs @@ -0,0 +1,39 @@ +import { mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import tick from '../common/tick.js'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; +import { access } from 'fs'; +import process from 'process'; +import { fileURLToPath } from 'url'; + +const __filename = fileURLToPath(import.meta.url); + +const hooks = initHooks(); + +hooks.enable(); +access(__filename, mustCall(onaccess)); + +function onaccess() { + const as = hooks.activitiesOfTypes('FSREQCALLBACK'); + const a = as[0]; + checkInvocations(a, { init: 1, before: 1 }, + 'while in onaccess callback'); + tick(2); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('FSREQCALLBACK'); + + const as = hooks.activitiesOfTypes('FSREQCALLBACK'); + strictEqual(as.length, 1); + + const a = as[0]; + strictEqual(a.type, 'FSREQCALLBACK'); + strictEqual(typeof a.uid, 'number'); + checkInvocations(a, { init: 1, before: 1, after: 1, destroy: 1 }, + 'when process exits'); +} diff --git a/test/async-hooks/test-fsreqcallback-readFile.mjs b/test/async-hooks/test-fsreqcallback-readFile.mjs new file mode 100644 index 00000000000000..f28c3e9aefac67 --- /dev/null +++ b/test/async-hooks/test-fsreqcallback-readFile.mjs @@ -0,0 +1,53 @@ +import { isMainThread, skip, mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import tick from '../common/tick.js'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; +import { readFile } from 'fs'; +import process from 'process'; +import { fileURLToPath } from 'url'; + +const __filename = fileURLToPath(import.meta.url); + +if (!isMainThread) + skip('Worker bootstrapping works differently -> different async IDs'); + +const hooks = initHooks(); + +hooks.enable(); +readFile(__filename, mustCall(onread)); + +function onread() { + const as = hooks.activitiesOfTypes('FSREQCALLBACK'); + let lastParent = 1; + for (let i = 0; i < as.length; i++) { + const a = as[i]; + strictEqual(a.type, 'FSREQCALLBACK'); + strictEqual(typeof a.uid, 'number'); + strictEqual(a.triggerAsyncId, lastParent); + lastParent = a.uid; + } + checkInvocations(as[0], { init: 1, before: 1, after: 1, destroy: 1 }, + 'reqwrap[0]: while in onread callback'); + checkInvocations(as[1], { init: 1, before: 1, after: 1, destroy: 1 }, + 'reqwrap[1]: while in onread callback'); + checkInvocations(as[2], { init: 1, before: 1, after: 1, destroy: 1 }, + 'reqwrap[2]: while in onread callback'); + + // This callback is called from within the last fs req callback therefore + // the last req is still going and after/destroy haven't been called yet + checkInvocations(as[3], { init: 1, before: 1 }, + 'reqwrap[3]: while in onread callback'); + tick(2); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('FSREQCALLBACK'); + const as = hooks.activitiesOfTypes('FSREQCALLBACK'); + const a = as.pop(); + checkInvocations(a, { init: 1, before: 1, after: 1, destroy: 1 }, + 'when process exits'); +} diff --git a/test/async-hooks/test-getaddrinforeqwrap.mjs b/test/async-hooks/test-getaddrinforeqwrap.mjs new file mode 100644 index 00000000000000..6cc5f72792db55 --- /dev/null +++ b/test/async-hooks/test-getaddrinforeqwrap.mjs @@ -0,0 +1,41 @@ +import { isMainThread, skip, mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import tick from '../common/tick.js'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; +import { lookup } from 'dns'; +import process from 'process'; + +if (!isMainThread) + skip('Worker bootstrapping works differently -> different async IDs'); + +const hooks = initHooks(); + +hooks.enable(); +lookup('www.google.com', 4, mustCall(onlookup)); +function onlookup() { + // We don't care about the error here in order to allow + // tests to run offline (lookup will fail in that case and the err be set); + + const as = hooks.activitiesOfTypes('GETADDRINFOREQWRAP'); + strictEqual(as.length, 1); + + const a = as[0]; + strictEqual(a.type, 'GETADDRINFOREQWRAP'); + strictEqual(typeof a.uid, 'number'); + strictEqual(a.triggerAsyncId, 1); + checkInvocations(a, { init: 1, before: 1 }, 'while in onlookup callback'); + tick(2); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('GETADDRINFOREQWRAP'); + + const as = hooks.activitiesOfTypes('GETADDRINFOREQWRAP'); + const a = as[0]; + checkInvocations(a, { init: 1, before: 1, after: 1, destroy: 1 }, + 'when process exits'); +} diff --git a/test/async-hooks/test-getnameinforeqwrap.mjs b/test/async-hooks/test-getnameinforeqwrap.mjs new file mode 100644 index 00000000000000..8b2f76cc71f4dd --- /dev/null +++ b/test/async-hooks/test-getnameinforeqwrap.mjs @@ -0,0 +1,42 @@ +import { isMainThread, skip, mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import tick from '../common/tick.js'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; +import { lookupService } from 'dns'; +import process from 'process'; + +if (!isMainThread) + skip('Worker bootstrapping works differently -> different async IDs'); + +const hooks = initHooks(); + +hooks.enable(); +lookupService('127.0.0.1', 80, mustCall(onlookupService)); +function onlookupService() { + // We don't care about the error here in order to allow + // tests to run offline (lookup will fail in that case and the err be set) + + const as = hooks.activitiesOfTypes('GETNAMEINFOREQWRAP'); + strictEqual(as.length, 1); + + const a = as[0]; + strictEqual(a.type, 'GETNAMEINFOREQWRAP'); + strictEqual(typeof a.uid, 'number'); + strictEqual(a.triggerAsyncId, 1); + checkInvocations(a, { init: 1, before: 1 }, + 'while in onlookupService callback'); + tick(2); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('GETNAMEINFOREQWRAP'); + + const as = hooks.activitiesOfTypes('GETNAMEINFOREQWRAP'); + const a = as[0]; + checkInvocations(a, { init: 1, before: 1, after: 1, destroy: 1 }, + 'when process exits'); +} diff --git a/test/async-hooks/test-graph.fsreq-readFile.mjs b/test/async-hooks/test-graph.fsreq-readFile.mjs new file mode 100644 index 00000000000000..2ece67a02451d2 --- /dev/null +++ b/test/async-hooks/test-graph.fsreq-readFile.mjs @@ -0,0 +1,28 @@ +import { mustCall } from '../common/index.mjs'; +import initHooks from './init-hooks.mjs'; +import verifyGraph from './verify-graph.mjs'; +import { readFile } from 'fs'; +import process from 'process'; +import { fileURLToPath } from 'url'; + +const __filename = fileURLToPath(import.meta.url); + +const hooks = initHooks(); + +hooks.enable(); +readFile(__filename, mustCall(onread)); + +function onread() {} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + verifyGraph( + hooks, + [ { type: 'FSREQCALLBACK', id: 'fsreq:1', triggerAsyncId: null }, + { type: 'FSREQCALLBACK', id: 'fsreq:2', triggerAsyncId: 'fsreq:1' }, + { type: 'FSREQCALLBACK', id: 'fsreq:3', triggerAsyncId: 'fsreq:2' }, + { type: 'FSREQCALLBACK', id: 'fsreq:4', triggerAsyncId: 'fsreq:3' } ] + ); +} diff --git a/test/async-hooks/test-graph.http.mjs b/test/async-hooks/test-graph.http.mjs new file mode 100644 index 00000000000000..05fdd94110e45a --- /dev/null +++ b/test/async-hooks/test-graph.http.mjs @@ -0,0 +1,52 @@ +import { hasIPv6, skip, mustCall } from '../common/index.mjs'; +if (!hasIPv6) + skip('IPv6 support required'); + +import initHooks from './init-hooks.mjs'; +import verifyGraph from './verify-graph.mjs'; +import { createServer, get } from 'http'; +import process from 'process'; + +const hooks = initHooks(); +hooks.enable(); + +const server = createServer(mustCall((req, res) => { + res.writeHead(200, { 'Connection': 'close' }); + res.end(); + server.close(mustCall()); +})); +server.listen(0, mustCall(() => { + get({ + host: '::1', + family: 6, + port: server.address().port + }, mustCall()); +})); + +process.on('exit', () => { + hooks.disable(); + + verifyGraph( + hooks, + [ { type: 'TCPSERVERWRAP', + id: 'tcpserver:1', + triggerAsyncId: null }, + { type: 'TCPWRAP', id: 'tcp:1', triggerAsyncId: 'tcpserver:1' }, + { type: 'TCPCONNECTWRAP', + id: 'tcpconnect:1', + triggerAsyncId: 'tcp:1' }, + { type: 'HTTPCLIENTREQUEST', + id: 'httpclientrequest:1', + triggerAsyncId: 'tcpserver:1' }, + { type: 'TCPWRAP', id: 'tcp:2', triggerAsyncId: 'tcpserver:1' }, + { type: 'HTTPINCOMINGMESSAGE', + id: 'httpincomingmessage:1', + triggerAsyncId: 'tcp:2' }, + { type: 'Timeout', + id: 'timeout:1', + triggerAsyncId: null }, + { type: 'SHUTDOWNWRAP', + id: 'shutdown:1', + triggerAsyncId: 'tcp:2' } ] + ); +}); diff --git a/test/async-hooks/test-graph.intervals.mjs b/test/async-hooks/test-graph.intervals.mjs new file mode 100644 index 00000000000000..5f3dbb937b7329 --- /dev/null +++ b/test/async-hooks/test-graph.intervals.mjs @@ -0,0 +1,35 @@ +import { mustCall } from '../common/index.mjs'; +import process from 'process'; +import initHooks from './init-hooks.mjs'; +import verifyGraph from './verify-graph.mjs'; + +const TIMEOUT = 1; + +const hooks = initHooks(); +hooks.enable(); + +let count = 0; +const iv1 = setInterval(mustCall(onfirstInterval, 3), TIMEOUT); +let iv2; + +function onfirstInterval() { + if (++count === 3) { + clearInterval(iv1); + iv2 = setInterval(mustCall(onsecondInterval, 1), TIMEOUT + 1); + } +} + +function onsecondInterval() { + clearInterval(iv2); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + verifyGraph( + hooks, + [ { type: 'Timeout', id: 'timeout:1', triggerAsyncId: null }, + { type: 'Timeout', id: 'timeout:2', triggerAsyncId: 'timeout:1' }] + ); +} diff --git a/test/async-hooks/test-graph.pipe.mjs b/test/async-hooks/test-graph.pipe.mjs new file mode 100644 index 00000000000000..31f847076b3d2d --- /dev/null +++ b/test/async-hooks/test-graph.pipe.mjs @@ -0,0 +1,31 @@ +import { mustCall } from '../common/index.mjs'; +import initHooks from './init-hooks.mjs'; +import verifyGraph from './verify-graph.mjs'; +import { spawn } from 'child_process'; +import process from 'process'; + +const hooks = initHooks(); + +hooks.enable(); +const sleep = spawn('sleep', [ '0.1' ]); + +sleep + .on('exit', mustCall(onsleepExit)) + .on('close', mustCall(onsleepClose)); + +function onsleepExit() {} + +function onsleepClose() {} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + verifyGraph( + hooks, + [ { type: 'PROCESSWRAP', id: 'process:1', triggerAsyncId: null }, + { type: 'PIPEWRAP', id: 'pipe:1', triggerAsyncId: null }, + { type: 'PIPEWRAP', id: 'pipe:2', triggerAsyncId: null }, + { type: 'PIPEWRAP', id: 'pipe:3', triggerAsyncId: null } ] + ); +} diff --git a/test/async-hooks/test-graph.pipeconnect.mjs b/test/async-hooks/test-graph.pipeconnect.mjs new file mode 100644 index 00000000000000..9f20d4de682d2d --- /dev/null +++ b/test/async-hooks/test-graph.pipeconnect.mjs @@ -0,0 +1,38 @@ +import { PIPE, mustCall } from '../common/index.mjs'; +import process from 'process'; +import initHooks from './init-hooks.mjs'; +import verifyGraph from './verify-graph.mjs'; + +import { createServer, connect } from 'net'; + +import { refresh } from '../common/tmpdir.js'; +refresh(); + +const hooks = initHooks(); +hooks.enable(); + +const server = createServer((c) => { + c.end(); + server.close(); +}).listen(PIPE, mustCall(onlisten)); + +function onlisten() { + connect(PIPE, mustCall(onconnect)); +} + +function onconnect() {} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + verifyGraph( + hooks, + [ { type: 'PIPESERVERWRAP', id: 'pipeserver:1', triggerAsyncId: null }, + { type: 'PIPEWRAP', id: 'pipe:1', triggerAsyncId: 'pipeserver:1' }, + { type: 'PIPECONNECTWRAP', id: 'pipeconnect:1', + triggerAsyncId: 'pipe:1' }, + { type: 'PIPEWRAP', id: 'pipe:2', triggerAsyncId: 'pipeserver:1' }, + { type: 'SHUTDOWNWRAP', id: 'shutdown:1', triggerAsyncId: 'pipe:2' } ] + ); +} diff --git a/test/async-hooks/test-graph.shutdown.mjs b/test/async-hooks/test-graph.shutdown.mjs new file mode 100644 index 00000000000000..33cdcf6fc5d9a1 --- /dev/null +++ b/test/async-hooks/test-graph.shutdown.mjs @@ -0,0 +1,45 @@ +import { hasIPv6, skip, mustCall } from '../common/index.mjs'; +import process from 'process'; + +if (!hasIPv6) + skip('IPv6 support required'); + +import initHooks from './init-hooks.mjs'; +import verifyGraph from './verify-graph.mjs'; +import { createServer, connect } from 'net'; + +const hooks = initHooks(); +hooks.enable(); + +const server = createServer(onconnection) + .on('listening', mustCall(onlistening)); +server.listen(); +function onlistening() { + connect(server.address().port, mustCall(onconnected)); +} + +function onconnection(c) { + c.end(); + this.close(onserverClosed); +} + +function onconnected() {} + +function onserverClosed() {} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + verifyGraph( + hooks, + [ { type: 'TCPSERVERWRAP', id: 'tcpserver:1', triggerAsyncId: null }, + { type: 'TCPWRAP', id: 'tcp:1', triggerAsyncId: 'tcpserver:1' }, + { type: 'GETADDRINFOREQWRAP', + id: 'getaddrinforeq:1', triggerAsyncId: 'tcp:1' }, + { type: 'TCPCONNECTWRAP', + id: 'tcpconnect:1', triggerAsyncId: 'tcp:1' }, + { type: 'TCPWRAP', id: 'tcp:2', triggerAsyncId: 'tcpserver:1' }, + { type: 'SHUTDOWNWRAP', id: 'shutdown:1', triggerAsyncId: 'tcp:2' } ] + ); +} diff --git a/test/async-hooks/test-graph.signal.mjs b/test/async-hooks/test-graph.signal.mjs new file mode 100644 index 00000000000000..9e9ff366596bd0 --- /dev/null +++ b/test/async-hooks/test-graph.signal.mjs @@ -0,0 +1,65 @@ +import { isWindows, skip, isMainThread, mustCall } from '../common/index.mjs'; +if (isWindows) + skip('no signals on Windows'); +if (!isMainThread) + skip('No signal handling available in Workers'); + +import initHooks from './init-hooks.mjs'; +import verifyGraph from './verify-graph.mjs'; +import { exec } from 'child_process'; +import process from 'process'; + +const hooks = initHooks(); + +hooks.enable(); +const interval = setInterval(() => {}, 9999); // Keep event loop open +process.on('SIGUSR2', mustCall(onsigusr2, 2)); + +let count = 0; +exec(`kill -USR2 ${process.pid}`); + +function onsigusr2() { + count++; + + if (count === 1) { + // Trigger same signal handler again + exec(`kill -USR2 ${process.pid}`); + } else { + // Install another signal handler + process.removeAllListeners('SIGUSR2'); + process.on('SIGUSR2', mustCall(onsigusr2Again)); + + exec(`kill -USR2 ${process.pid}`); + } +} + +function onsigusr2Again() { + clearInterval(interval); // Let the event loop close +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + verifyGraph( + hooks, + [ { type: 'SIGNALWRAP', id: 'signal:1', triggerAsyncId: null }, + { type: 'PROCESSWRAP', id: 'process:1', triggerAsyncId: null }, + { type: 'PIPEWRAP', id: 'pipe:1', triggerAsyncId: null }, + { type: 'PIPEWRAP', id: 'pipe:2', triggerAsyncId: null }, + { type: 'PIPEWRAP', id: 'pipe:3', triggerAsyncId: null }, + { type: 'PROCESSWRAP', id: 'process:2', triggerAsyncId: 'signal:1' }, + { type: 'PIPEWRAP', id: 'pipe:4', triggerAsyncId: 'signal:1' }, + { type: 'PIPEWRAP', id: 'pipe:5', triggerAsyncId: 'signal:1' }, + { type: 'PIPEWRAP', id: 'pipe:6', triggerAsyncId: 'signal:1' }, + { type: 'SIGNALWRAP', id: 'signal:2', + // TEST_THREAD_ID is set by tools/test.py. Adjust test results depending + // on whether the test was invoked via test.py or from the shell + // directly. + triggerAsyncId: process.env.TEST_THREAD_ID ? 'signal:1' : 'pipe:2' }, + { type: 'PROCESSWRAP', id: 'process:3', triggerAsyncId: 'signal:1' }, + { type: 'PIPEWRAP', id: 'pipe:7', triggerAsyncId: 'signal:1' }, + { type: 'PIPEWRAP', id: 'pipe:8', triggerAsyncId: 'signal:1' }, + { type: 'PIPEWRAP', id: 'pipe:9', triggerAsyncId: 'signal:1' } ] + ); +} diff --git a/test/async-hooks/test-graph.statwatcher.mjs b/test/async-hooks/test-graph.statwatcher.mjs new file mode 100644 index 00000000000000..cb95e01ef90de8 --- /dev/null +++ b/test/async-hooks/test-graph.statwatcher.mjs @@ -0,0 +1,38 @@ +import '../common/index.mjs'; +import initHooks from './init-hooks.mjs'; +import verifyGraph from './verify-graph.mjs'; +import { watchFile, unwatchFile } from 'fs'; +import { createRequire } from 'module'; +import process from 'process'; +import { fileURLToPath } from 'url'; + +const require = createRequire(import.meta.url); +const commonPath = require.resolve('../common/index.js'); +const __filename = fileURLToPath(import.meta.url); + +const hooks = initHooks(); +hooks.enable(); + +function onchange() { } +// Install first file watcher +watchFile(__filename, onchange); + +// Install second file watcher +watchFile(commonPath, onchange); + +// Remove first file watcher +unwatchFile(__filename); + +// Remove second file watcher +unwatchFile(commonPath); + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + verifyGraph( + hooks, + [ { type: 'STATWATCHER', id: 'statwatcher:1', triggerAsyncId: null }, + { type: 'STATWATCHER', id: 'statwatcher:2', triggerAsyncId: null } ] + ); +} diff --git a/test/async-hooks/test-graph.tcp.mjs b/test/async-hooks/test-graph.tcp.mjs new file mode 100644 index 00000000000000..364b6a5e879d52 --- /dev/null +++ b/test/async-hooks/test-graph.tcp.mjs @@ -0,0 +1,46 @@ +import { hasIPv6, skip, mustCall } from '../common/index.mjs'; +if (!hasIPv6) + skip('IPv6 support required'); + +import initHooks from './init-hooks.mjs'; +import verifyGraph from './verify-graph.mjs'; +import { createServer, connect } from 'net'; +import process from 'process'; + +const hooks = initHooks(); +hooks.enable(); + +const server = createServer(mustCall(onconnection)) + .on('listening', mustCall(onlistening)); + +server.listen(0); + +connect({ port: server.address().port, host: '::1' }, + mustCall(onconnected)); + +function onlistening() {} + +function onconnected() {} + +function onconnection(c) { + c.end(); + this.close(mustCall(onserverClosed)); +} + +function onserverClosed() {} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + + verifyGraph( + hooks, + [ { type: 'TCPSERVERWRAP', id: 'tcpserver:1', triggerAsyncId: null }, + { type: 'TCPWRAP', id: 'tcp:1', triggerAsyncId: null }, + { type: 'TCPCONNECTWRAP', + id: 'tcpconnect:1', triggerAsyncId: 'tcp:1' }, + { type: 'TCPWRAP', id: 'tcp:2', triggerAsyncId: 'tcpserver:1' }, + { type: 'SHUTDOWNWRAP', id: 'shutdown:1', triggerAsyncId: 'tcp:2' } ] + ); +} diff --git a/test/async-hooks/test-graph.timeouts.mjs b/test/async-hooks/test-graph.timeouts.mjs new file mode 100644 index 00000000000000..483fb12eab7ba2 --- /dev/null +++ b/test/async-hooks/test-graph.timeouts.mjs @@ -0,0 +1,31 @@ +import { mustCall } from '../common/index.mjs'; +import process from 'process'; +import initHooks from './init-hooks.mjs'; +import verifyGraph from './verify-graph.mjs'; +const TIMEOUT = 1; + +const hooks = initHooks(); +hooks.enable(); + +setTimeout(mustCall(ontimeout), TIMEOUT); +function ontimeout() { + setTimeout(onsecondTimeout, TIMEOUT + 1); +} + +function onsecondTimeout() { + setTimeout(onthirdTimeout, TIMEOUT + 2); +} + +function onthirdTimeout() {} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + verifyGraph( + hooks, + [ { type: 'Timeout', id: 'timeout:1', triggerAsyncId: null }, + { type: 'Timeout', id: 'timeout:2', triggerAsyncId: 'timeout:1' }, + { type: 'Timeout', id: 'timeout:3', triggerAsyncId: 'timeout:2' }] + ); +} diff --git a/test/async-hooks/test-graph.tls-write-12.mjs b/test/async-hooks/test-graph.tls-write-12.mjs new file mode 100644 index 00000000000000..2d04244200a57f --- /dev/null +++ b/test/async-hooks/test-graph.tls-write-12.mjs @@ -0,0 +1,9 @@ +import { hasCrypto, skip } from '../common/index.mjs'; +if (!hasCrypto) + skip('missing crypto'); + +import { DEFAULT_MAX_VERSION } from 'tls'; + +DEFAULT_MAX_VERSION = 'TLSv1.2'; + +await import('./test-graph.tls-write.mjs'); diff --git a/test/async-hooks/test-graph.tls-write.mjs b/test/async-hooks/test-graph.tls-write.mjs new file mode 100644 index 00000000000000..780566c9ce0d01 --- /dev/null +++ b/test/async-hooks/test-graph.tls-write.mjs @@ -0,0 +1,68 @@ +import { hasCrypto, skip, hasIPv6, mustCall } from '../common/index.mjs'; +if (!hasCrypto) + skip('missing crypto'); + +if (!hasIPv6) + skip('IPv6 support required'); + +import initHooks from './init-hooks.mjs'; +import verifyGraph from './verify-graph.mjs'; +import { createServer, connect } from 'tls'; +import { readKey } from '../common/fixtures.mjs'; +import process from 'process'; + +const hooks = initHooks(); +hooks.enable(); + +// +// Creating server and listening on port +// +const server = createServer({ + cert: readKey('rsa_cert.crt'), + key: readKey('rsa_private.pem') + }) + .on('listening', mustCall(onlistening)) + .on('secureConnection', mustCall(onsecureConnection)) + .listen(0); + +function onlistening() { + // + // Creating client and connecting it to server + // + connect(server.address().port, { rejectUnauthorized: false }) + .on('secureConnect', mustCall(onsecureConnect)); +} + +function onsecureConnection() {} + +function onsecureConnect() { + // end() client socket, which causes slightly different hook events than + // destroy(), but with TLS1.3 destroy() rips the connection down before the + // server completes the handshake. + this.end(); + + // Closing server + server.close(mustCall(onserverClosed)); +} + +function onserverClosed() {} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + + verifyGraph( + hooks, + [ { type: 'TCPSERVERWRAP', id: 'tcpserver:1', triggerAsyncId: null }, + { type: 'TCPWRAP', id: 'tcp:1', triggerAsyncId: 'tcpserver:1' }, + { type: 'TLSWRAP', id: 'tls:1', triggerAsyncId: 'tcpserver:1' }, + { type: 'GETADDRINFOREQWRAP', + id: 'getaddrinforeq:1', triggerAsyncId: 'tls:1' }, + { type: 'TCPCONNECTWRAP', + id: 'tcpconnect:1', triggerAsyncId: 'tcp:1' }, + { type: 'TCPWRAP', id: 'tcp:2', triggerAsyncId: 'tcpserver:1' }, + { type: 'TLSWRAP', id: 'tls:2', triggerAsyncId: 'tcpserver:1' }, + ] + ); +} diff --git a/test/async-hooks/test-http-agent-handle-reuse-parallel.mjs b/test/async-hooks/test-http-agent-handle-reuse-parallel.mjs new file mode 100644 index 00000000000000..1aafd52bf690f0 --- /dev/null +++ b/test/async-hooks/test-http-agent-handle-reuse-parallel.mjs @@ -0,0 +1,95 @@ +// Flags: --expose-internals +import { mustCallAtLeast, mustCall } from '../common/index.mjs'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; +import { ok, strictEqual } from 'assert'; +import internalAsyncHooks from 'internal/async_hooks'; +import process from 'process'; + +import { Agent, createServer, request } from 'http'; + +const { async_id_symbol } = internalAsyncHooks.symbols; + +// Checks that the async resource used in init in case of a reused handle +// is not reused. Test is based on parallel\test-async-hooks-http-agent.js. + +const hooks = initHooks(); +hooks.enable(); + +const reqAsyncIds = []; +let socket; +let responses = 0; + +// Make sure a single socket is transparently reused for 2 requests. +const agent = new Agent({ + keepAlive: true, + keepAliveMsecs: Infinity, + maxSockets: 1 +}); + +const verifyRequest = (idx) => (res) => { + reqAsyncIds[idx] = res.socket[async_id_symbol]; + ok(reqAsyncIds[idx] > 0, `${reqAsyncIds[idx]} > 0`); + if (socket) { + // Check that both requests share their socket. + strictEqual(res.socket, socket); + } else { + socket = res.socket; + } + + res.on('data', mustCallAtLeast(() => {})); + res.on('end', mustCall(() => { + if (++responses === 2) { + // Clean up to let the event loop stop. + server.close(); + agent.destroy(); + } + })); +}; + +const server = createServer(mustCall((req, res) => { + req.once('data', mustCallAtLeast(() => { + res.writeHead(200, { 'Content-Type': 'text/plain' }); + res.write('foo'); + })); + req.on('end', mustCall(() => { + res.end('bar'); + })); +}, 2)).listen(0, mustCall(() => { + const port = server.address().port; + const payload = 'hello world'; + + // First request. + const r1 = request({ + agent, port, method: 'POST' + }, mustCall(verifyRequest(0))); + r1.end(payload); + + // Second request. Sent in parallel with the first one. + const r2 = request({ + agent, port, method: 'POST' + }, mustCall(verifyRequest(1))); + r2.end(payload); +})); + + +process.on('exit', onExit); + +function onExit() { + hooks.disable(); + hooks.sanityCheck(); + const activities = hooks.activities; + + // Verify both invocations + const first = activities.filter((x) => x.uid === reqAsyncIds[0])[0]; + checkInvocations(first, { init: 1, destroy: 1 }, 'when process exits'); + + const second = activities.filter((x) => x.uid === reqAsyncIds[1])[0]; + checkInvocations(second, { init: 1, destroy: 1 }, 'when process exits'); + + // Verify reuse handle has been wrapped + strictEqual(first.type, second.type); + ok(first.handle !== second.handle, 'Resource reused'); + ok(first.handle === second.handle.handle, + 'Resource not wrapped correctly'); +} diff --git a/test/async-hooks/test-http-agent-handle-reuse-serial.mjs b/test/async-hooks/test-http-agent-handle-reuse-serial.mjs new file mode 100644 index 00000000000000..508e1110b39d02 --- /dev/null +++ b/test/async-hooks/test-http-agent-handle-reuse-serial.mjs @@ -0,0 +1,113 @@ +// Flags: --expose-internals +import { mustCall, mustCallAtLeast } from '../common/index.mjs'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; +import { ok, strictEqual } from 'assert'; +import internalAsyncHooks from 'internal/async_hooks'; +import process from 'process'; + +import { Agent, createServer, request } from 'http'; + +const { async_id_symbol } = internalAsyncHooks.symbols; + +// Checks that the async resource used in init in case of a reused handle +// is not reused. Test is based on parallel\test-async-hooks-http-agent.js. + +const hooks = initHooks(); +hooks.enable(); + +let asyncIdAtFirstReq; +let asyncIdAtSecondReq; + +// Make sure a single socket is transparently reused for 2 requests. +const agent = new Agent({ + keepAlive: true, + keepAliveMsecs: Infinity, + maxSockets: 1 +}); + +const server = createServer(mustCall((req, res) => { + req.once('data', mustCallAtLeast(() => { + res.writeHead(200, { 'Content-Type': 'text/plain' }); + res.write('foo'); + })); + req.on('end', mustCall(() => { + res.end('bar'); + })); +}, 2)).listen(0, mustCall(() => { + const port = server.address().port; + const payload = 'hello world'; + + // First request. This is useless except for adding a socket to the + // agent’s pool for reuse. + const r1 = request({ + agent, port, method: 'POST' + }, mustCall((res) => { + // Remember which socket we used. + const socket = res.socket; + asyncIdAtFirstReq = socket[async_id_symbol]; + ok(asyncIdAtFirstReq > 0, `${asyncIdAtFirstReq} > 0`); + // Check that request and response share their socket. + strictEqual(r1.socket, socket); + + res.on('data', mustCallAtLeast(() => {})); + res.on('end', mustCall(() => { + // setImmediate() to give the agent time to register the freed socket. + setImmediate(mustCall(() => { + // The socket is free for reuse now. + strictEqual(socket[async_id_symbol], -1); + + // Second request. To re-create the exact conditions from the + // referenced issue, we use a POST request without chunked encoding + // (hence the Content-Length header) and call .end() after the + // response header has already been received. + const r2 = request({ + agent, port, method: 'POST', headers: { + 'Content-Length': payload.length + } + }, mustCall((res) => { + asyncIdAtSecondReq = res.socket[async_id_symbol]; + ok(asyncIdAtSecondReq > 0, `${asyncIdAtSecondReq} > 0`); + strictEqual(r2.socket, socket); + + // Empty payload, to hit the “right” code path. + r2.end(''); + + res.on('data', mustCallAtLeast(() => {})); + res.on('end', mustCall(() => { + // Clean up to let the event loop stop. + server.close(); + agent.destroy(); + })); + })); + + // Schedule a payload to be written immediately, but do not end the + // request just yet. + r2.write(payload); + })); + })); + })); + r1.end(payload); +})); + + +process.on('exit', onExit); + +function onExit() { + hooks.disable(); + hooks.sanityCheck(); + const activities = hooks.activities; + + // Verify both invocations + const first = activities.filter((x) => x.uid === asyncIdAtFirstReq)[0]; + checkInvocations(first, { init: 1, destroy: 1 }, 'when process exits'); + + const second = activities.filter((x) => x.uid === asyncIdAtSecondReq)[0]; + checkInvocations(second, { init: 1, destroy: 1 }, 'when process exits'); + + // Verify reuse handle has been wrapped + strictEqual(first.type, second.type); + ok(first.handle !== second.handle, 'Resource reused'); + ok(first.handle === second.handle.handle, + 'Resource not wrapped correctly'); +} diff --git a/test/async-hooks/test-httpparser-reuse.mjs b/test/async-hooks/test-httpparser-reuse.mjs new file mode 100644 index 00000000000000..56d0b7e728786a --- /dev/null +++ b/test/async-hooks/test-httpparser-reuse.mjs @@ -0,0 +1,73 @@ +import { mustCall } from '../common/index.mjs'; +import { strictEqual, ok } from 'assert'; +import { createHook } from 'async_hooks'; +import { createServer, get } from 'http'; + +// Verify that resource emitted for an HTTPParser is not reused. +// Verify that correct create/destroy events are emitted. + +const reused = Symbol('reused'); + +const reusedParser = []; +const incomingMessageParser = []; +const clientRequestParser = []; +const dupDestroys = []; +const destroyed = []; + +createHook({ + init(asyncId, type, triggerAsyncId, resource) { + switch (type) { + case 'HTTPINCOMINGMESSAGE': + incomingMessageParser.push(asyncId); + break; + case 'HTTPCLIENTREQUEST': + clientRequestParser.push(asyncId); + break; + } + + if (resource[reused]) { + reusedParser.push( + `resource reused: ${asyncId}, ${triggerAsyncId}, ${type}` + ); + } + resource[reused] = true; + }, + destroy(asyncId) { + if (destroyed.includes(asyncId)) { + dupDestroys.push(asyncId); + } else { + destroyed.push(asyncId); + } + } +}).enable(); + +const server = createServer((req, res) => { + res.end(); +}); + +server.listen(0, mustCall(() => { + const PORT = server.address().port; + const url = `http://127.0.0.1:${PORT}`; + get(url, mustCall(() => { + server.close(mustCall(() => { + server.listen(PORT, mustCall(() => { + get(url, mustCall(() => { + server.close(mustCall(() => { + setTimeout(mustCall(verify), 200); + })); + })); + })); + })); + })); +})); + +function verify() { + strictEqual(reusedParser.length, 0); + + strictEqual(incomingMessageParser.length, 2); + strictEqual(clientRequestParser.length, 2); + + strictEqual(dupDestroys.length, 0); + incomingMessageParser.forEach((id) => ok(destroyed.includes(id))); + clientRequestParser.forEach((id) => ok(destroyed.includes(id))); +} diff --git a/test/async-hooks/test-httpparser.request.mjs b/test/async-hooks/test-httpparser.request.mjs new file mode 100644 index 00000000000000..d483b1aff93ab6 --- /dev/null +++ b/test/async-hooks/test-httpparser.request.mjs @@ -0,0 +1,52 @@ +import { mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import process from 'process'; +import tick from '../common/tick.js'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; + +const hooks = initHooks(); +hooks.enable(); + +import { HTTPParser } from '_http_common'; + +const REQUEST = HTTPParser.REQUEST; + +const kOnHeadersComplete = HTTPParser.kOnHeadersComplete | 0; + +const request = Buffer.from( + 'GET /hello HTTP/1.1\r\n\r\n' +); + +const parser = new HTTPParser(); +parser.initialize(REQUEST, {}); +const as = hooks.activitiesOfTypes('HTTPINCOMINGMESSAGE'); +const httpparser = as[0]; + +strictEqual(as.length, 1); +strictEqual(typeof httpparser.uid, 'number'); +strictEqual(typeof httpparser.triggerAsyncId, 'number'); +checkInvocations(httpparser, { init: 1 }, 'when created new Httphttpparser'); + +parser[kOnHeadersComplete] = mustCall(onheadersComplete); +parser.execute(request, 0, request.length); + +function onheadersComplete() { + checkInvocations(httpparser, { init: 1, before: 1 }, + 'when onheadersComplete called'); + tick(1, mustCall(tick1)); +} + +function tick1() { + parser.close(); + tick(1); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('HTTPINCOMINGMESSAGE'); + checkInvocations(httpparser, { init: 1, before: 1, after: 1, destroy: 1 }, + 'when process exits'); +} diff --git a/test/async-hooks/test-httpparser.response.mjs b/test/async-hooks/test-httpparser.response.mjs new file mode 100644 index 00000000000000..29754523be9524 --- /dev/null +++ b/test/async-hooks/test-httpparser.response.mjs @@ -0,0 +1,63 @@ +import { mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import process from 'process'; +import tick from '../common/tick.js'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; + +const hooks = initHooks(); + +hooks.enable(); + +import { HTTPParser } from '_http_common'; + +const RESPONSE = HTTPParser.RESPONSE; +const kOnHeadersComplete = HTTPParser.kOnHeadersComplete | 0; +const kOnBody = HTTPParser.kOnBody | 0; + +const request = Buffer.from( + 'HTTP/1.1 200 OK\r\n' + + 'Content-Type: text/plain\r\n' + + 'Content-Length: 4\r\n' + + '\r\n' + + 'pong' +); + +const parser = new HTTPParser(); +parser.initialize(RESPONSE, {}); +const as = hooks.activitiesOfTypes('HTTPCLIENTREQUEST'); +const httpparser = as[0]; + +strictEqual(as.length, 1); +strictEqual(typeof httpparser.uid, 'number'); +strictEqual(typeof httpparser.triggerAsyncId, 'number'); +checkInvocations(httpparser, { init: 1 }, 'when created new Httphttpparser'); + +parser[kOnHeadersComplete] = mustCall(onheadersComplete); +parser[kOnBody] = mustCall(onbody); +parser.execute(request, 0, request.length); + +function onheadersComplete() { + checkInvocations(httpparser, { init: 1, before: 1 }, + 'when onheadersComplete called'); +} + +function onbody() { + checkInvocations(httpparser, { init: 1, before: 2, after: 1 }, + 'when onbody called'); + tick(1, mustCall(tick1)); +} + +function tick1() { + parser.close(); + tick(1); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('HTTPCLIENTREQUEST'); + checkInvocations(httpparser, { init: 1, before: 2, after: 2, destroy: 1 }, + 'when process exits'); +} diff --git a/test/async-hooks/test-immediate.mjs b/test/async-hooks/test-immediate.mjs new file mode 100644 index 00000000000000..df84007478601e --- /dev/null +++ b/test/async-hooks/test-immediate.mjs @@ -0,0 +1,62 @@ +import { mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import process from 'process'; +import tick from '../common/tick.js'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; + +const hooks = initHooks(); +hooks.enable(); + +// Install first immediate +setImmediate(mustCall(onimmediate)); + +const as = hooks.activitiesOfTypes('Immediate'); +strictEqual(as.length, 1); +const imd1 = as[0]; +strictEqual(imd1.type, 'Immediate'); +strictEqual(typeof imd1.uid, 'number'); +strictEqual(typeof imd1.triggerAsyncId, 'number'); +checkInvocations(imd1, { init: 1 }, + 'imd1: when first set immediate installed'); + +let imd2; + +function onimmediate() { + let as = hooks.activitiesOfTypes('Immediate'); + strictEqual(as.length, 1); + checkInvocations(imd1, { init: 1, before: 1 }, + 'imd1: when first set immediate triggered'); + + // Install second immediate + setImmediate(mustCall(onimmediateTwo)); + as = hooks.activitiesOfTypes('Immediate'); + strictEqual(as.length, 2); + imd2 = as[1]; + strictEqual(imd2.type, 'Immediate'); + strictEqual(typeof imd2.uid, 'number'); + strictEqual(typeof imd2.triggerAsyncId, 'number'); + checkInvocations(imd1, { init: 1, before: 1 }, + 'imd1: when second set immediate installed'); + checkInvocations(imd2, { init: 1 }, + 'imd2: when second set immediate installed'); +} + +function onimmediateTwo() { + checkInvocations(imd1, { init: 1, before: 1, after: 1, destroy: 1 }, + 'imd1: when second set immediate triggered'); + checkInvocations(imd2, { init: 1, before: 1 }, + 'imd2: when second set immediate triggered'); + tick(1); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('Immediate'); + checkInvocations(imd1, { init: 1, before: 1, after: 1, destroy: 1 }, + 'imd1: when process exits'); + checkInvocations(imd2, { init: 1, before: 1, after: 1, destroy: 1 }, + 'imd2: when process exits'); +} diff --git a/test/async-hooks/test-improper-order.mjs b/test/async-hooks/test-improper-order.mjs new file mode 100644 index 00000000000000..f8116db1898575 --- /dev/null +++ b/test/async-hooks/test-improper-order.mjs @@ -0,0 +1,63 @@ +// Flags: --expose-internals +import { mustCall } from '../common/index.mjs'; +import { strictEqual, match } from 'assert'; +import internal_async_hooks from 'internal/async_hooks'; +import { spawn } from 'child_process'; +import { argv, execPath } from 'process'; + +const corruptedMsg = /async hook stack has become corrupted/; +const heartbeatMsg = /heartbeat: still alive/; + +const { + newAsyncId, getDefaultTriggerAsyncId, + emitInit, emitBefore, emitAfter +} = internal_async_hooks; + +import initHooks from './init-hooks.mjs'; + +if (argv[2] === 'child') { + const hooks = initHooks(); + hooks.enable(); + + // Async hooks enforce proper order of 'before' and 'after' invocations + + // Proper ordering + { + const asyncId = newAsyncId(); + const triggerId = getDefaultTriggerAsyncId(); + emitInit(asyncId, 'event1', triggerId, {}); + emitBefore(asyncId, triggerId); + emitAfter(asyncId); + } + + // Improper ordering + // Emitting 'after' without 'before' which is illegal + { + const asyncId = newAsyncId(); + const triggerId = getDefaultTriggerAsyncId(); + emitInit(asyncId, 'event2', triggerId, {}); + + console.log('heartbeat: still alive'); + emitAfter(asyncId); + } +} else { + const args = ['--expose-internals'] + .concat(argv.slice(1)) + .concat('child'); + let errData = Buffer.from(''); + let outData = Buffer.from(''); + + const child = spawn(execPath, args); + child.stderr.on('data', (d) => { errData = Buffer.concat([ errData, d ]); }); + child.stdout.on('data', (d) => { outData = Buffer.concat([ outData, d ]); }); + + child.on('close', mustCall((code) => { + strictEqual(code, 1); + match(outData.toString(), heartbeatMsg, + 'did not crash until we reached offending line of code ' + + `(found ${outData})`); + match(errData.toString(), corruptedMsg, + 'printed error contains corrupted message ' + + `(found ${errData})`); + })); +} diff --git a/test/async-hooks/test-improper-unwind.mjs b/test/async-hooks/test-improper-unwind.mjs new file mode 100644 index 00000000000000..a19944c6939ec4 --- /dev/null +++ b/test/async-hooks/test-improper-unwind.mjs @@ -0,0 +1,67 @@ +// Flags: --expose-internals +import { mustCall } from '../common/index.mjs'; +import { strictEqual, match } from 'assert'; +import internal_async_hooks from 'internal/async_hooks'; +import { spawn } from 'child_process'; +import { argv, execPath } from 'process'; + +const corruptedMsg = /async hook stack has become corrupted/; +const heartbeatMsg = /heartbeat: still alive/; + +const { + newAsyncId, getDefaultTriggerAsyncId, + emitInit, emitBefore, emitAfter +} = internal_async_hooks; + +import initHooks from './init-hooks.mjs'; + +if (argv[2] === 'child') { + const hooks = initHooks(); + hooks.enable(); + + // In both the below two cases 'before' of event2 is nested inside 'before' + // of event1. + // Therefore the 'after' of event2 needs to occur before the + // 'after' of event 1. + // The first test of the two below follows that rule, + // the second one doesn't. + + const eventOneId = newAsyncId(); + const eventTwoId = newAsyncId(); + const triggerId = getDefaultTriggerAsyncId(); + emitInit(eventOneId, 'event1', triggerId, {}); + emitInit(eventTwoId, 'event2', triggerId, {}); + + // Proper unwind + emitBefore(eventOneId, triggerId); + emitBefore(eventTwoId, triggerId); + emitAfter(eventTwoId); + emitAfter(eventOneId); + + // Improper unwind + emitBefore(eventOneId, triggerId); + emitBefore(eventTwoId, triggerId); + + console.log('heartbeat: still alive'); + emitAfter(eventOneId); +} else { + const args = ['--expose-internals'] + .concat(argv.slice(1)) + .concat('child'); + let errData = Buffer.from(''); + let outData = Buffer.from(''); + + const child = spawn(execPath, args); + child.stderr.on('data', (d) => { errData = Buffer.concat([ errData, d ]); }); + child.stdout.on('data', (d) => { outData = Buffer.concat([ outData, d ]); }); + + child.on('close', mustCall((code) => { + strictEqual(code, 1); + match(outData.toString(), heartbeatMsg, + 'did not crash until we reached offending line of code ' + + `(found ${outData})`); + match(errData.toString(), corruptedMsg, + 'printed error contains corrupted message ' + + `(found ${errData})`); + })); +} diff --git a/test/async-hooks/test-late-hook-enable.mjs b/test/async-hooks/test-late-hook-enable.mjs new file mode 100644 index 00000000000000..b956275e73a8a5 --- /dev/null +++ b/test/async-hooks/test-late-hook-enable.mjs @@ -0,0 +1,51 @@ +import { mustNotCall, mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import { createHook } from 'async_hooks'; +import process from 'process'; + +// Checks that enabling async hooks in a callback actually +// triggers after & destroy as expected. + +const fnsToTest = [setTimeout, (cb) => { + setImmediate(() => { + cb(); + + // We need to keep the event loop open for this to actually work + // since destroy hooks are triggered in unrefed Immediates + setImmediate(() => { + hook.disable(); + }); + }); +}, (cb) => { + setImmediate(() => { + process.nextTick(() => { + cb(); + + // We need to keep the event loop open for this to actually work + // since destroy hooks are triggered in unrefed Immediates + setImmediate(() => { + hook.disable(); + strictEqual(fnsToTest.length, 0); + }); + }); + }); +}]; + +const hook = createHook({ + before: mustNotCall(), + after: mustCall(() => {}, 3), + destroy: mustCall(() => { + hook.disable(); + nextTest(); + }, 3) +}); + +nextTest(); + +function nextTest() { + if (fnsToTest.length > 0) { + fnsToTest.shift()(mustCall(() => { + hook.enable(); + })); + } +} diff --git a/test/async-hooks/test-net-get-connections.mjs b/test/async-hooks/test-net-get-connections.mjs new file mode 100644 index 00000000000000..4b736b44ebc271 --- /dev/null +++ b/test/async-hooks/test-net-get-connections.mjs @@ -0,0 +1,9 @@ +import { mustCall } from '../common/index.mjs'; +import { createServer } from 'net'; +const server = createServer(); + +// This test was based on an error raised by Haraka. +// It caused server.getConnections to raise an exception. +// Ref: https://github.com/haraka/Haraka/pull/1951 + +server.getConnections(mustCall()); diff --git a/test/async-hooks/test-nexttick-default-trigger.mjs b/test/async-hooks/test-nexttick-default-trigger.mjs new file mode 100644 index 00000000000000..c453824e4f513f --- /dev/null +++ b/test/async-hooks/test-nexttick-default-trigger.mjs @@ -0,0 +1,28 @@ +import { mustCall } from '../common/index.mjs'; +import process from 'process'; + +// This tests ensures that the triggerId of the nextTick function sets the +// triggerAsyncId correctly. + +import { strictEqual } from 'assert'; +import { executionAsyncId, triggerAsyncId } from 'async_hooks'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; + +const hooks = initHooks(); +hooks.enable(); + +const rootAsyncId = executionAsyncId(); + +process.nextTick(mustCall(() => { + strictEqual(triggerAsyncId(), rootAsyncId); +})); + +process.on('exit', () => { + hooks.sanityCheck(); + + const as = hooks.activitiesOfTypes('TickObject'); + checkInvocations(as[0], { + init: 1, before: 1, after: 1, destroy: 1 + }, 'when process exits'); +}); diff --git a/test/async-hooks/test-no-assert-when-disabled.mjs b/test/async-hooks/test-no-assert-when-disabled.mjs new file mode 100644 index 00000000000000..3c91837c9f39f2 --- /dev/null +++ b/test/async-hooks/test-no-assert-when-disabled.mjs @@ -0,0 +1,14 @@ +// Flags: --no-force-async-hooks-checks --expose-internals +import { isMainThread, skip } from '../common/index.mjs'; + +if (!isMainThread) + skip('Workers don\'t inherit per-env state like the check flag'); + +import internalAsyncHooks from 'internal/async_hooks'; +const { emitInit, emitBefore, emitAfter, emitDestroy } = internalAsyncHooks; + +// Negative asyncIds and invalid type name +emitInit(-1, null, -1, {}); +emitBefore(-1, -1); +emitAfter(-1); +emitDestroy(-1); diff --git a/test/async-hooks/test-pipeconnectwrap.mjs b/test/async-hooks/test-pipeconnectwrap.mjs new file mode 100644 index 00000000000000..36a4a746277eb5 --- /dev/null +++ b/test/async-hooks/test-pipeconnectwrap.mjs @@ -0,0 +1,94 @@ +import { mustCall, PIPE } from '../common/index.mjs'; +import { strictEqual, ok } from 'assert'; +import tick from '../common/tick.js'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; +import { refresh } from '../common/tmpdir.js'; +import { createServer, connect } from 'net'; +import process from 'process'; + +refresh(); + +const hooks = initHooks(); +hooks.enable(); +let pipe1, pipe2; +let pipeserver; +let pipeconnect; + +const server = createServer(mustCall((c) => { + c.end(); + server.close(); + process.nextTick(maybeOnconnect.bind(null, 'server')); +})).listen(PIPE, mustCall(onlisten)); + +function onlisten() { + const pipeservers = hooks.activitiesOfTypes('PIPESERVERWRAP'); + let pipeconnects = hooks.activitiesOfTypes('PIPECONNECTWRAP'); + strictEqual(pipeservers.length, 1); + strictEqual(pipeconnects.length, 0); + + connect(PIPE, + mustCall(maybeOnconnect.bind(null, 'client'))); + + const pipes = hooks.activitiesOfTypes('PIPEWRAP'); + pipeconnects = hooks.activitiesOfTypes('PIPECONNECTWRAP'); + strictEqual(pipes.length, 1); + strictEqual(pipeconnects.length, 1); + + pipeserver = pipeservers[0]; + pipe1 = pipes[0]; + pipeconnect = pipeconnects[0]; + + strictEqual(pipeserver.type, 'PIPESERVERWRAP'); + strictEqual(pipe1.type, 'PIPEWRAP'); + strictEqual(pipeconnect.type, 'PIPECONNECTWRAP'); + for (const a of [ pipeserver, pipe1, pipeconnect ]) { + strictEqual(typeof a.uid, 'number'); + strictEqual(typeof a.triggerAsyncId, 'number'); + checkInvocations(a, { init: 1 }, 'after net.connect'); + } +} + +const awaitOnconnectCalls = new Set(['server', 'client']); +function maybeOnconnect(source) { + // Both server and client must call onconnect. On most OS's waiting for + // the client is sufficient, but on CentOS 5 the sever needs to respond too. + ok(awaitOnconnectCalls.size > 0); + awaitOnconnectCalls.delete(source); + if (awaitOnconnectCalls.size > 0) return; + + const pipes = hooks.activitiesOfTypes('PIPEWRAP'); + const pipeconnects = hooks.activitiesOfTypes('PIPECONNECTWRAP'); + + strictEqual(pipes.length, 2); + strictEqual(pipeconnects.length, 1); + pipe2 = pipes[1]; + strictEqual(typeof pipe2.uid, 'number'); + strictEqual(typeof pipe2.triggerAsyncId, 'number'); + + checkInvocations(pipeserver, { init: 1, before: 1, after: 1 }, + 'pipeserver, client connected'); + checkInvocations(pipe1, { init: 1 }, 'pipe1, client connected'); + checkInvocations(pipeconnect, { init: 1, before: 1 }, + 'pipeconnect, client connected'); + checkInvocations(pipe2, { init: 1 }, 'pipe2, client connected'); + tick(5); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('PIPEWRAP'); + hooks.sanityCheck('PIPESERVERWRAP'); + hooks.sanityCheck('PIPECONNECTWRAP'); + // TODO(thlorenz) why have some of those 'before' and 'after' called twice + checkInvocations(pipeserver, { init: 1, before: 1, after: 1, destroy: 1 }, + 'pipeserver, process exiting'); + checkInvocations(pipe1, { init: 1, before: 2, after: 2, destroy: 1 }, + 'pipe1, process exiting'); + checkInvocations(pipeconnect, { init: 1, before: 1, after: 1, destroy: 1 }, + 'pipeconnect, process exiting'); + checkInvocations(pipe2, { init: 1, before: 2, after: 2, destroy: 1 }, + 'pipe2, process exiting'); +} diff --git a/test/async-hooks/test-pipewrap.mjs b/test/async-hooks/test-pipewrap.mjs new file mode 100644 index 00000000000000..21b85325619b7c --- /dev/null +++ b/test/async-hooks/test-pipewrap.mjs @@ -0,0 +1,91 @@ +// NOTE: this also covers process wrap as one is created along with the pipes +// when we launch the sleep process + +// Flags: --expose-gc + +import { isMainThread, skip, mustCall } from '../common/index.mjs'; +import { strictEqual, ok } from 'assert'; +import tick from '../common/tick.js'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; +import { spawn } from 'child_process'; +import process from 'process'; + +if (!isMainThread) + skip('Worker bootstrapping works differently -> different async IDs'); + +const hooks = initHooks(); + +hooks.enable(); +const nodeVersionSpawn = spawn(process.execPath, [ '--version' ]); + +nodeVersionSpawn + .on('exit', mustCall(onsleepExit)) + .on('close', mustCall(onsleepClose)); + +// A process wrap and 3 pipe wraps for std{in,out,err} are initialized +// synchronously +const processes = hooks.activitiesOfTypes('PROCESSWRAP'); +const pipes = hooks.activitiesOfTypes('PIPEWRAP'); +strictEqual(processes.length, 1); +strictEqual(pipes.length, 3); + +const processwrap = processes[0]; +const pipe1 = pipes[0]; +const pipe2 = pipes[1]; +const pipe3 = pipes[2]; + +strictEqual(processwrap.type, 'PROCESSWRAP'); +strictEqual(processwrap.triggerAsyncId, 1); +checkInvocations(processwrap, { init: 1 }, + 'processwrap when sleep.spawn was called'); + +[ pipe1, pipe2, pipe3 ].forEach((x) => { + strictEqual(x.type, 'PIPEWRAP'); + strictEqual(x.triggerAsyncId, 1); + checkInvocations(x, { init: 1 }, 'pipe wrap when sleep.spawn was called'); +}); + +function onsleepExit() { + checkInvocations(processwrap, { init: 1, before: 1 }, + 'processwrap while in onsleepExit callback'); +} + +function onsleepClose() { + tick(1, () => + checkInvocations( + processwrap, + { init: 1, before: 1, after: 1 }, + 'processwrap while in onsleepClose callback') + ); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('PROCESSWRAP'); + hooks.sanityCheck('PIPEWRAP'); + + checkInvocations( + processwrap, + { init: 1, before: 1, after: 1 }, + 'processwrap while in onsleepClose callback'); + + [ pipe1, pipe2, pipe3 ].forEach((x) => { + strictEqual(x.type, 'PIPEWRAP'); + strictEqual(x.triggerAsyncId, 1); + }); + + const ioEvents = Math.min(pipe2.before.length, pipe2.after.length); + // 2 events without any IO and at least one more for the node version data. + // Usually it is just one event, but it can be more. + ok(ioEvents >= 3, `at least 3 stdout io events, got ${ioEvents}`); + + checkInvocations(pipe1, { init: 1, before: 1, after: 1 }, + 'pipe wrap when sleep.spawn was called'); + checkInvocations(pipe2, { init: 1, before: ioEvents, after: ioEvents }, + 'pipe wrap when sleep.spawn was called'); + checkInvocations(pipe3, { init: 1, before: 2, after: 2 }, + 'pipe wrap when sleep.spawn was called'); +} diff --git a/test/async-hooks/test-promise.chain-promise-before-init-hooks.mjs b/test/async-hooks/test-promise.chain-promise-before-init-hooks.mjs new file mode 100644 index 00000000000000..7c8790cdd21ad4 --- /dev/null +++ b/test/async-hooks/test-promise.chain-promise-before-init-hooks.mjs @@ -0,0 +1,40 @@ +import { isMainThread, skip, mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import process from 'process'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; + +if (!isMainThread) + skip('Worker bootstrapping works differently -> different async IDs'); + +const p = new Promise(mustCall(function executor(resolve) { + resolve(5); +})); + +p.then(function afterResolution(val) { + strictEqual(val, 5); + return val; +}); + +// Init hooks after chained promise is created +const hooks = initHooks(); +hooks._allowNoInit = true; +hooks.enable(); + + +process.on('exit', function onexit() { + hooks.disable(); + hooks.sanityCheck('PROMISE'); + + // Because the init event was never emitted the hooks listener doesn't + // know what the type was. Thus check for Unknown rather than PROMISE. + const as = hooks.activitiesOfTypes('PROMISE'); + const unknown = hooks.activitiesOfTypes('Unknown'); + strictEqual(as.length, 0); + strictEqual(unknown.length, 1); + + const a0 = unknown[0]; + strictEqual(a0.type, 'Unknown'); + strictEqual(typeof a0.uid, 'number'); + checkInvocations(a0, { before: 1, after: 1 }, 'when process exits'); +}); diff --git a/test/async-hooks/test-promise.mjs b/test/async-hooks/test-promise.mjs new file mode 100644 index 00000000000000..22b0722742a1a2 --- /dev/null +++ b/test/async-hooks/test-promise.mjs @@ -0,0 +1,53 @@ +import { isMainThread, skip, mustCall } from '../common/index.mjs'; + +import { strictEqual } from 'assert'; +import process from 'process'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; + +if (!isMainThread) + skip('Worker bootstrapping works differently -> different async IDs'); + +const hooks = initHooks(); + +hooks.enable(); + +const p = new Promise(mustCall(executor)); +p.then(function afterResolution(val) { + strictEqual(val, 5); + const as = hooks.activitiesOfTypes('PROMISE'); + strictEqual(as.length, 2); + checkInvocations(as[0], { init: 1 }, 'after resolution parent promise'); + checkInvocations(as[1], { init: 1, before: 1 }, + 'after resolution child promise'); +}); + +function executor(resolve) { + const as = hooks.activitiesOfTypes('PROMISE'); + strictEqual(as.length, 1); + const a = as[0]; + checkInvocations(a, { init: 1 }, 'while in promise executor'); + resolve(5); +} + +process.on('exit', onexit); +function onexit() { + hooks.disable(); + hooks.sanityCheck('PROMISE'); + + const as = hooks.activitiesOfTypes('PROMISE'); + strictEqual(as.length, 2); + + const a0 = as[0]; + strictEqual(a0.type, 'PROMISE'); + strictEqual(typeof a0.uid, 'number'); + strictEqual(a0.triggerAsyncId, 1); + checkInvocations(a0, { init: 1 }, 'when process exits'); + + const a1 = as[1]; + strictEqual(a1.type, 'PROMISE'); + strictEqual(typeof a1.uid, 'number'); + strictEqual(a1.triggerAsyncId, a0.uid); + // We expect a destroy hook as well but we cannot guarantee predictable gc. + checkInvocations(a1, { init: 1, before: 1, after: 1 }, 'when process exits'); +} diff --git a/test/async-hooks/test-promise.promise-before-init-hooks.mjs b/test/async-hooks/test-promise.promise-before-init-hooks.mjs new file mode 100644 index 00000000000000..70565c1e828c87 --- /dev/null +++ b/test/async-hooks/test-promise.promise-before-init-hooks.mjs @@ -0,0 +1,41 @@ +import { mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import process from 'process'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; + +const p = new Promise(mustCall(function executor(resolve) { + resolve(5); +})); + +// Init hooks after promise was created +const hooks = initHooks({ allowNoInit: true }); +hooks.enable(); + +p.then(function afterResolution(val) { + strictEqual(val, 5); + const as = hooks.activitiesOfTypes('PROMISE'); + strictEqual(as.length, 1); + checkInvocations(as[0], { init: 1, before: 1 }, + 'after resolution child promise'); + return val; +}); + +process.on('exit', function onexit() { + hooks.disable(); + hooks.sanityCheck('PROMISE'); + + const as = hooks.activitiesOfTypes('PROMISE'); + strictEqual(as.length, 1); + + const a0 = as[0]; + strictEqual(a0.type, 'PROMISE'); + strictEqual(typeof a0.uid, 'number'); + // We can't get the asyncId from the parent dynamically, since init was + // never called. However, it is known that the parent promise was created + // immediately before the child promise, thus there should only be one + // difference in id. + strictEqual(a0.triggerAsyncId, a0.uid - 1); + // We expect a destroy hook as well but we cannot guarantee predictable gc. + checkInvocations(a0, { init: 1, before: 1, after: 1 }, 'when process exits'); +}); diff --git a/test/async-hooks/test-querywrap.mjs b/test/async-hooks/test-querywrap.mjs new file mode 100644 index 00000000000000..1d7ce314a97fcc --- /dev/null +++ b/test/async-hooks/test-querywrap.mjs @@ -0,0 +1,40 @@ +// Flags: --expose-gc + +import { mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import tick from '../common/tick.js'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; +import { resolve } from 'dns'; +import process from 'process'; + +const hooks = initHooks(); + +hooks.enable(); +// Uses cares for queryA which in turn uses QUERYWRAP +resolve('localhost', mustCall(onresolved)); + +function onresolved() { + const as = hooks.activitiesOfTypes('QUERYWRAP'); + const a = as[0]; + strictEqual(as.length, 1); + checkInvocations(a, { init: 1, before: 1 }, 'while in onresolved callback'); + tick(1E4); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('QUERYWRAP'); + + const as = hooks.activitiesOfTypes('QUERYWRAP'); + strictEqual(as.length, 1); + const a = as[0]; + + strictEqual(a.type, 'QUERYWRAP'); + strictEqual(typeof a.uid, 'number'); + strictEqual(typeof a.triggerAsyncId, 'number'); + checkInvocations(a, { init: 1, before: 1, after: 1, destroy: 1 }, + 'when process exits'); +} diff --git a/test/async-hooks/test-queue-microtask.mjs b/test/async-hooks/test-queue-microtask.mjs new file mode 100644 index 00000000000000..54d7560360b621 --- /dev/null +++ b/test/async-hooks/test-queue-microtask.mjs @@ -0,0 +1,25 @@ +import { mustCall } from '../common/index.mjs'; + +import { strictEqual } from 'assert'; +import { executionAsyncId, triggerAsyncId } from 'async_hooks'; +import process from 'process'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; + +const hooks = initHooks(); +hooks.enable(); + +const rootAsyncId = executionAsyncId(); + +queueMicrotask(mustCall(() => { + strictEqual(triggerAsyncId(), rootAsyncId); +})); + +process.on('exit', () => { + hooks.sanityCheck(); + + const as = hooks.activitiesOfTypes('Microtask'); + checkInvocations(as[0], { + init: 1, before: 1, after: 1, destroy: 1 + }, 'when process exits'); +}); diff --git a/test/async-hooks/test-shutdownwrap.mjs b/test/async-hooks/test-shutdownwrap.mjs new file mode 100644 index 00000000000000..da8d91d65fb5b8 --- /dev/null +++ b/test/async-hooks/test-shutdownwrap.mjs @@ -0,0 +1,61 @@ +import { mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import process from 'process'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; + +import { createServer, connect } from 'net'; + +const hooks = initHooks(); +hooks.enable(); + +const server = createServer(onconnection) + .on('listening', mustCall(onlistening)); +server.listen(); +function onlistening() { + connect(server.address().port, mustCall(onconnected)); +} + +// It is non-deterministic in which order onconnection and onconnected fire. +// Therefore we track here if we ended the connection already or not. +let endedConnection = false; +function onconnection(c) { + strictEqual(hooks.activitiesOfTypes('SHUTDOWNWRAP').length, 0); + c.end(); + process.nextTick(() => { + endedConnection = true; + const as = hooks.activitiesOfTypes('SHUTDOWNWRAP'); + strictEqual(as.length, 1); + checkInvocations(as[0], { init: 1 }, 'after ending client connection'); + this.close(onserverClosed); + }); +} + +function onconnected() { + if (endedConnection) { + strictEqual(hooks.activitiesOfTypes('SHUTDOWNWRAP').length, 1); + + } else { + strictEqual(hooks.activitiesOfTypes('SHUTDOWNWRAP').length, 0); + } +} + +function onserverClosed() { + const as = hooks.activitiesOfTypes('SHUTDOWNWRAP'); + checkInvocations(as[0], { init: 1, before: 1, after: 1, destroy: 1 }, + 'when server closed'); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('SHUTDOWNWRAP'); + const as = hooks.activitiesOfTypes('SHUTDOWNWRAP'); + const a = as[0]; + strictEqual(a.type, 'SHUTDOWNWRAP'); + strictEqual(typeof a.uid, 'number'); + strictEqual(typeof a.triggerAsyncId, 'number'); + checkInvocations(as[0], { init: 1, before: 1, after: 1, destroy: 1 }, + 'when process exits'); +} diff --git a/test/async-hooks/test-signalwrap.mjs b/test/async-hooks/test-signalwrap.mjs new file mode 100644 index 00000000000000..d96a3114b6ddd2 --- /dev/null +++ b/test/async-hooks/test-signalwrap.mjs @@ -0,0 +1,104 @@ +import { isWindows, skip, isMainThread, mustCall } from '../common/index.mjs'; + +if (isWindows) + skip('no signals in Windows'); +if (!isMainThread) + skip('No signal handling available in Workers'); + +import { strictEqual } from 'assert'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; +import { exec } from 'child_process'; +import process from 'process'; + +const hooks = initHooks(); + +hooks.enable(); + +// Keep the event loop open so process doesn't exit before receiving signals. +const interval = setInterval(() => {}, 9999); + +process.on('SIGUSR2', mustCall(onsigusr2, 2)); + +const as = hooks.activitiesOfTypes('SIGNALWRAP'); +strictEqual(as.length, 1); +const signal1 = as[0]; +strictEqual(signal1.type, 'SIGNALWRAP'); +strictEqual(typeof signal1.uid, 'number'); +strictEqual(typeof signal1.triggerAsyncId, 'number'); +checkInvocations(signal1, { init: 1 }, 'when SIGUSR2 handler is set up'); + +let count = 0; +exec(`kill -USR2 ${process.pid}`); + +let signal2; + +function onsigusr2() { + count++; + + if (count === 1) { + // first invocation + checkInvocations( + signal1, { init: 1, before: 1 }, + ' signal1: when first SIGUSR2 handler is called for the first time'); + + // Trigger same signal handler again + exec(`kill -USR2 ${process.pid}`); + } else { + // second invocation + checkInvocations( + signal1, { init: 1, before: 2, after: 1 }, + 'signal1: when first SIGUSR2 handler is called for the second time'); + + // Install another signal handler + process.removeAllListeners('SIGUSR2'); + process.on('SIGUSR2', mustCall(onsigusr2Again)); + + const as = hooks.activitiesOfTypes('SIGNALWRAP'); + // The isTTY checks are needed to allow test to work whether run with + // test.py or directly with the node executable. The third signal event + // listener is the SIGWINCH handler that node installs when it thinks + // process.stdout is a tty. + const expectedLen = 2 + (!!process.stdout.isTTY || !!process.stderr.isTTY); + strictEqual(as.length, expectedLen); + signal2 = as[expectedLen - 1]; // Last item in the array. + strictEqual(signal2.type, 'SIGNALWRAP'); + strictEqual(typeof signal2.uid, 'number'); + strictEqual(typeof signal2.triggerAsyncId, 'number'); + + checkInvocations( + signal1, { init: 1, before: 2, after: 1 }, + 'signal1: when second SIGUSR2 handler is set up'); + checkInvocations( + signal2, { init: 1 }, + 'signal2: when second SIGUSR2 handler is setup'); + + exec(`kill -USR2 ${process.pid}`); + } +} + +function onsigusr2Again() { + clearInterval(interval); + setImmediate(() => { + checkInvocations( + signal1, { init: 1, before: 2, after: 2, destroy: 1 }, + 'signal1: when second SIGUSR2 handler is called'); + checkInvocations( + signal2, { init: 1, before: 1 }, + 'signal2: when second SIGUSR2 handler is called'); + }); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('SIGNALWRAP'); + checkInvocations( + signal1, { init: 1, before: 2, after: 2, destroy: 1 }, + 'signal1: when second SIGUSR2 process exits'); + // Second signal not destroyed yet since its event listener is still active + checkInvocations( + signal2, { init: 1, before: 1, after: 1 }, + 'signal2: when second SIGUSR2 process exits'); +} diff --git a/test/async-hooks/test-statwatcher.mjs b/test/async-hooks/test-statwatcher.mjs new file mode 100644 index 00000000000000..5dcd16a9780797 --- /dev/null +++ b/test/async-hooks/test-statwatcher.mjs @@ -0,0 +1,105 @@ +import { isMainThread, skip, platformTimeout, mustCallAtLeast } from '../common/index.mjs'; +import { refresh, path as _path } from '../common/tmpdir.js'; +import { strictEqual } from 'assert'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; +import { watchFile, writeFileSync, unwatchFile } from 'fs'; +import { join } from 'path'; +import process from 'process'; + +if (!isMainThread) + skip('Worker bootstrapping works differently -> different async IDs'); + +refresh(); + +const file1 = join(_path, 'file1'); +const file2 = join(_path, 'file2'); + +const onchangex = (x) => (curr, prev) => { + console.log(`Watcher: ${x}`); + console.log('current stat data:', curr); + console.log('previous stat data:', prev); +}; + +const checkWatcherStart = (name, watcher) => { + strictEqual(watcher.type, 'STATWATCHER'); + strictEqual(typeof watcher.uid, 'number'); + strictEqual(watcher.triggerAsyncId, 1); + checkInvocations(watcher, { init: 1 }, + `${name}: when started to watch file`); +}; + +const hooks = initHooks(); +hooks.enable(); + +// Install first file watcher. +const w1 = watchFile(file1, { interval: 10 }, onchangex('w1')); +let as = hooks.activitiesOfTypes('STATWATCHER'); +strictEqual(as.length, 1); +// Count all change events to account for all of them in checkInvocations. +let w1HookCount = 0; +w1.on('change', () => w1HookCount++); + +const statwatcher1 = as[0]; +checkWatcherStart('watcher1', statwatcher1); + +// Install second file watcher +const w2 = watchFile(file2, { interval: 10 }, onchangex('w2')); +as = hooks.activitiesOfTypes('STATWATCHER'); +strictEqual(as.length, 2); +// Count all change events to account for all of them in checkInvocations. +let w2HookCount = 0; +w2.on('change', () => w2HookCount++); + +const statwatcher2 = as[1]; +checkInvocations(statwatcher1, { init: 1 }, + 'watcher1: when started to watch second file'); +checkWatcherStart('watcher2', statwatcher2); + +setTimeout(() => writeFileSync(file1, 'foo++'), + platformTimeout(100)); +w1.on('change', mustCallAtLeast((curr, prev) => { + console.log('w1 change to', curr, 'from', prev); + // Wait until we get the write above. + if (prev.size !== 0 || curr.size !== 5) + return; + + setImmediate(() => { + checkInvocations(statwatcher1, + { init: 1, before: w1HookCount, after: w1HookCount }, + 'watcher1: when unwatched first file'); + checkInvocations(statwatcher2, { init: 1 }, + 'watcher2: when unwatched first file'); + + setTimeout(() => writeFileSync(file2, 'bar++'), + platformTimeout(100)); + w2.on('change', mustCallAtLeast((curr, prev) => { + console.log('w2 change to', curr, 'from', prev); + // Wait until we get the write above. + if (prev.size !== 0 || curr.size !== 5) + return; + + setImmediate(() => { + checkInvocations(statwatcher1, + { init: 1, before: w1HookCount, after: w1HookCount }, + 'watcher1: when unwatched second file'); + checkInvocations(statwatcher2, + { init: 1, before: w2HookCount, after: w2HookCount }, + 'watcher2: when unwatched second file'); + unwatchFile(file1); + unwatchFile(file2); + }); + })); + }); +})); + +process.once('exit', () => { + hooks.disable(); + hooks.sanityCheck('STATWATCHER'); + checkInvocations(statwatcher1, + { init: 1, before: w1HookCount, after: w1HookCount }, + 'watcher1: when process exits'); + checkInvocations(statwatcher2, + { init: 1, before: w2HookCount, after: w2HookCount }, + 'watcher2: when process exits'); +}); diff --git a/test/async-hooks/test-tcpwrap.mjs b/test/async-hooks/test-tcpwrap.mjs new file mode 100644 index 00000000000000..a0db0dbd8820fd --- /dev/null +++ b/test/async-hooks/test-tcpwrap.mjs @@ -0,0 +1,163 @@ +// Covers TCPWRAP and related TCPCONNECTWRAP +import { hasIPv6, skip, mustCall } from '../common/index.mjs'; +if (!hasIPv6) + skip('IPv6 support required'); + +import { strictEqual } from 'assert'; +import process from 'process'; +import tick from '../common/tick.js'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; +import { createServer, connect } from 'net'; + +let tcp1, tcp2; +let tcpserver; +let tcpconnect; + +const hooks = initHooks(); +hooks.enable(); + +const server = createServer(mustCall(onconnection)) + .on('listening', mustCall(onlistening)); + +// Calling server.listen creates a TCPWRAP synchronously +{ + server.listen(0); + const tcpsservers = hooks.activitiesOfTypes('TCPSERVERWRAP'); + const tcpconnects = hooks.activitiesOfTypes('TCPCONNECTWRAP'); + strictEqual(tcpsservers.length, 1); + strictEqual(tcpconnects.length, 0); + tcpserver = tcpsservers[0]; + strictEqual(tcpserver.type, 'TCPSERVERWRAP'); + strictEqual(typeof tcpserver.uid, 'number'); + strictEqual(typeof tcpserver.triggerAsyncId, 'number'); + checkInvocations(tcpserver, { init: 1 }, 'when calling server.listen'); +} + +// Calling net.connect creates another TCPWRAP synchronously +{ + connect( + { port: server.address().port, host: '::1' }, + mustCall(onconnected)); + const tcps = hooks.activitiesOfTypes('TCPWRAP'); + strictEqual(tcps.length, 1); + process.nextTick(() => { + const tcpconnects = hooks.activitiesOfTypes('TCPCONNECTWRAP'); + strictEqual(tcpconnects.length, 1); + }); + + tcp1 = tcps[0]; + strictEqual(tcps.length, 1); + strictEqual(tcp1.type, 'TCPWRAP'); + strictEqual(typeof tcp1.uid, 'number'); + strictEqual(typeof tcp1.triggerAsyncId, 'number'); + + checkInvocations(tcpserver, { init: 1 }, + 'tcpserver when client is connecting'); + checkInvocations(tcp1, { init: 1 }, 'tcp1 when client is connecting'); +} + +function onlistening() { + strictEqual(hooks.activitiesOfTypes('TCPWRAP').length, 1); +} + +// Depending on timing we see client: onconnected or server: onconnection first +// Therefore we can't depend on any ordering, but when we see a connection for +// the first time we assign the tcpconnectwrap. +function ontcpConnection(serverConnection) { + if (tcpconnect != null) { + // When client receives connection first ('onconnected') and the server + // second then we see an 'after' here, otherwise not + const expected = serverConnection ? + { init: 1, before: 1, after: 1 } : + { init: 1, before: 1 }; + checkInvocations( + tcpconnect, expected, + 'tcpconnect: when both client and server received connection'); + return; + } + + // Only focusing on TCPCONNECTWRAP here + const tcpconnects = hooks.activitiesOfTypes('TCPCONNECTWRAP'); + strictEqual(tcpconnects.length, 1); + tcpconnect = tcpconnects[0]; + strictEqual(tcpconnect.type, 'TCPCONNECTWRAP'); + strictEqual(typeof tcpconnect.uid, 'number'); + strictEqual(typeof tcpconnect.triggerAsyncId, 'number'); + // When client receives connection first ('onconnected'), we 'before' has + // been invoked at this point already, otherwise it only was 'init'ed + const expected = serverConnection ? { init: 1 } : { init: 1, before: 1 }; + checkInvocations(tcpconnect, expected, + 'tcpconnect: when tcp connection is established'); +} + +let serverConnected = false; +function onconnected() { + ontcpConnection(false); + // In the case that the client connects before the server TCPWRAP 'before' + // and 'after' weren't invoked yet. Also @see ontcpConnection. + const expected = serverConnected ? + { init: 1, before: 1, after: 1 } : + { init: 1 }; + checkInvocations(tcpserver, expected, 'tcpserver when client connects'); + checkInvocations(tcp1, { init: 1 }, 'tcp1 when client connects'); +} + +function onconnection(c) { + serverConnected = true; + ontcpConnection(true); + + const tcps = hooks.activitiesOfTypes([ 'TCPWRAP' ]); + const tcpconnects = hooks.activitiesOfTypes('TCPCONNECTWRAP'); + strictEqual(tcps.length, 2); + strictEqual(tcpconnects.length, 1); + tcp2 = tcps[1]; + strictEqual(tcp2.type, 'TCPWRAP'); + strictEqual(typeof tcp2.uid, 'number'); + strictEqual(typeof tcp2.triggerAsyncId, 'number'); + + checkInvocations(tcpserver, { init: 1, before: 1 }, + 'tcpserver when server receives connection'); + checkInvocations(tcp1, { init: 1 }, 'tcp1 when server receives connection'); + checkInvocations(tcp2, { init: 1 }, 'tcp2 when server receives connection'); + + c.end(); + this.close(mustCall(onserverClosed)); +} + +function onserverClosed() { + checkInvocations(tcpserver, { init: 1, before: 1, after: 1, destroy: 1 }, + 'tcpserver when server is closed'); + setImmediate(() => { + checkInvocations(tcp1, { init: 1, before: 2, after: 2, destroy: 1 }, + 'tcp1 after server is closed'); + }); + checkInvocations(tcp2, { init: 1, before: 1, after: 1 }, + 'tcp2 synchronously when server is closed'); + + tick(2, () => { + checkInvocations(tcp2, { init: 1, before: 2, after: 2, destroy: 1 }, + 'tcp2 when server is closed'); + checkInvocations(tcpconnect, { init: 1, before: 1, after: 1, destroy: 1 }, + 'tcpconnect when server is closed'); + }); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck([ 'TCPWRAP', 'TCPSERVERWRAP', 'TCPCONNECTWRAP' ]); + + checkInvocations(tcpserver, { init: 1, before: 1, after: 1, destroy: 1 }, + 'tcpserver when process exits'); + checkInvocations( + tcp1, { init: 1, before: 2, after: 2, destroy: 1 }, + 'tcp1 when process exits'); + checkInvocations( + tcp2, { init: 1, before: 2, after: 2, destroy: 1 }, + 'tcp2 when process exits'); + checkInvocations( + tcpconnect, { init: 1, before: 1, after: 1, destroy: 1 }, + 'tcpconnect when process exits'); +} diff --git a/test/async-hooks/test-timers.setInterval.mjs b/test/async-hooks/test-timers.setInterval.mjs new file mode 100644 index 00000000000000..eedd0444309a50 --- /dev/null +++ b/test/async-hooks/test-timers.setInterval.mjs @@ -0,0 +1,46 @@ +import { platformTimeout, mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import process from 'process'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; + +const TIMEOUT = platformTimeout(100); + +const hooks = initHooks(); +hooks.enable(); + +const interval = setInterval(mustCall(ontimeout, 2), TIMEOUT); +const as = hooks.activitiesOfTypes('Timeout'); +strictEqual(as.length, 1); +const t1 = as[0]; +strictEqual(t1.type, 'Timeout'); +strictEqual(typeof t1.uid, 'number'); +strictEqual(typeof t1.triggerAsyncId, 'number'); +checkInvocations(t1, { init: 1 }, 't1: when timer installed'); + +let iter = 0; +function ontimeout() { + if (iter === 0) { + checkInvocations(t1, { init: 1, before: 1 }, 't1: when first timer fired'); + } else { + checkInvocations(t1, { init: 1, before: 2, after: 1 }, + 't1: when first interval fired again'); + clearInterval(interval); + return; + } + + iter++; + throw new Error('setInterval Error'); +} + +process.once('uncaughtException', mustCall((err) => { + strictEqual(err.message, 'setInterval Error'); +})); + +process.on('exit', () => { + hooks.disable(); + hooks.sanityCheck('Timeout'); + + checkInvocations(t1, { init: 1, before: 2, after: 2, destroy: 1 }, + 't1: when process exits'); +}); diff --git a/test/async-hooks/test-timers.setTimeout.mjs b/test/async-hooks/test-timers.setTimeout.mjs new file mode 100644 index 00000000000000..fd8d24072b22f3 --- /dev/null +++ b/test/async-hooks/test-timers.setTimeout.mjs @@ -0,0 +1,61 @@ +import { platformTimeout, mustCall, mustNotCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import process from 'process'; +import tick from '../common/tick.js'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; + +const TIMEOUT = platformTimeout(100); + +const hooks = initHooks(); +hooks.enable(); + +// Install first timeout +setTimeout(mustCall(ontimeout), TIMEOUT); +const as = hooks.activitiesOfTypes('Timeout'); +strictEqual(as.length, 1); +const t1 = as[0]; +strictEqual(t1.type, 'Timeout'); +strictEqual(typeof t1.uid, 'number'); +strictEqual(typeof t1.triggerAsyncId, 'number'); +checkInvocations(t1, { init: 1 }, 't1: when first timer installed'); + +let timer; +let t2; +function ontimeout() { + checkInvocations(t1, { init: 1, before: 1 }, 't1: when first timer fired'); + + setTimeout(onSecondTimeout, TIMEOUT).unref(); + const as = hooks.activitiesOfTypes('Timeout'); + t2 = as[1]; + strictEqual(as.length, 2); + checkInvocations(t1, { init: 1, before: 1 }, + 't1: when second timer installed'); + checkInvocations(t2, { init: 1 }, + 't2: when second timer installed'); + + timer = setTimeout(mustNotCall(), 2 ** 31 - 1); +} + +function onSecondTimeout() { + const as = hooks.activitiesOfTypes('Timeout'); + strictEqual(as.length, 3); + checkInvocations(t1, { init: 1, before: 1, after: 1 }, + 't1: when second timer fired'); + checkInvocations(t2, { init: 1, before: 1 }, + 't2: when second timer fired'); + clearTimeout(timer); + tick(2); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('Timeout'); + + checkInvocations(t1, { init: 1, before: 1, after: 1, destroy: 1 }, + 't1: when process exits'); + checkInvocations(t2, { init: 1, before: 1, after: 1, destroy: 1 }, + 't2: when process exits'); +} diff --git a/test/async-hooks/test-tlswrap.mjs b/test/async-hooks/test-tlswrap.mjs new file mode 100644 index 00000000000000..45198f9a1cce49 --- /dev/null +++ b/test/async-hooks/test-tlswrap.mjs @@ -0,0 +1,136 @@ +import { hasCrypto, skip, mustCall } from '../common/index.mjs'; +if (!hasCrypto) + skip('missing crypto'); + +import { strictEqual } from 'assert'; +import process from 'process'; +import { readKey } from '../common/fixtures.mjs'; +import { DEFAULT_MAX_VERSION, createServer, connect } from 'tls'; + +import tick from '../common/tick.js'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; + +const hooks = initHooks(); +hooks.enable(); + +// TODO(@sam-github) assumes server handshake completes before client, true for +// 1.2, not for 1.3. Might need a rewrite for TLS1.3. +DEFAULT_MAX_VERSION = 'TLSv1.2'; + +// +// Creating server and listening on port +// +const server = createServer({ + cert: readKey('rsa_cert.crt'), + key: readKey('rsa_private.pem') + }) + .on('listening', mustCall(onlistening)) + .on('secureConnection', mustCall(onsecureConnection)) + .listen(0); + +let svr, client; +function onlistening() { + // + // Creating client and connecting it to server + // + connect(server.address().port, { rejectUnauthorized: false }) + .on('secureConnect', mustCall(onsecureConnect)); + + const as = hooks.activitiesOfTypes('TLSWRAP'); + strictEqual(as.length, 1); + svr = as[0]; + + strictEqual(svr.type, 'TLSWRAP'); + strictEqual(typeof svr.uid, 'number'); + strictEqual(typeof svr.triggerAsyncId, 'number'); + checkInvocations(svr, { init: 1 }, 'server: when client connecting'); +} + +function onsecureConnection() { + // + // Server received client connection + // + const as = hooks.activitiesOfTypes('TLSWRAP'); + strictEqual(as.length, 2); + // TODO(@sam-github) This happens after onsecureConnect, with TLS1.3. + client = as[1]; + strictEqual(client.type, 'TLSWRAP'); + strictEqual(typeof client.uid, 'number'); + strictEqual(typeof client.triggerAsyncId, 'number'); + + // TODO(thlorenz) which callback did the server wrap execute that already + // finished as well? + checkInvocations(svr, { init: 1, before: 1, after: 1 }, + 'server: when server has secure connection'); + + checkInvocations(client, { init: 1, before: 2, after: 1 }, + 'client: when server has secure connection'); +} + +function onsecureConnect() { + // + // Client connected to server + // + checkInvocations(svr, { init: 1, before: 2, after: 1 }, + 'server: when client connected'); + checkInvocations(client, { init: 1, before: 2, after: 2 }, + 'client: when client connected'); + + // + // Destroying client socket + // + this.destroy(); // This destroys client before server handshakes, with TLS1.3 + checkInvocations(svr, { init: 1, before: 2, after: 1 }, + 'server: when destroying client'); + checkInvocations(client, { init: 1, before: 2, after: 2 }, + 'client: when destroying client'); + + tick(5, tick1); + function tick1() { + checkInvocations(svr, { init: 1, before: 2, after: 2 }, + 'server: when client destroyed'); + // TODO: why is client not destroyed here even after 5 ticks? + // or could it be that it isn't actually destroyed until + // the server is closed? + if (client.before.length < 3) { + tick(5, tick1); + return; + } + checkInvocations(client, { init: 1, before: 3, after: 3 }, + 'client: when client destroyed'); + // + // Closing server + // + server.close(mustCall(onserverClosed)); + // No changes to invocations until server actually closed below + checkInvocations(svr, { init: 1, before: 2, after: 2 }, + 'server: when closing server'); + checkInvocations(client, { init: 1, before: 3, after: 3 }, + 'client: when closing server'); + } +} + +function onserverClosed() { + // + // Server closed + // + tick(1E4, mustCall(() => { + checkInvocations(svr, { init: 1, before: 2, after: 2 }, + 'server: when server closed'); + checkInvocations(client, { init: 1, before: 3, after: 3 }, + 'client: when server closed'); + })); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('TLSWRAP'); + + checkInvocations(svr, { init: 1, before: 2, after: 2 }, + 'server: when process exits'); + checkInvocations(client, { init: 1, before: 3, after: 3 }, + 'client: when process exits'); +} diff --git a/test/async-hooks/test-ttywrap.readstream.mjs b/test/async-hooks/test-ttywrap.readstream.mjs new file mode 100644 index 00000000000000..2adca34b380c7e --- /dev/null +++ b/test/async-hooks/test-ttywrap.readstream.mjs @@ -0,0 +1,48 @@ +import { skip, mustCall } from '../common/index.mjs'; +import { strictEqual, fail } from 'assert'; +import { exit, stdin } from 'process'; + +// General hook test setup +import tick from '../common/tick.js'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; + +const hooks = initHooks(); +hooks.enable(); + +if (!stdin.isTTY) { + skip('no valid readable TTY available'); + exit(); +} + +// test specific setup +const checkInitOpts = { init: 1 }; +const checkEndedOpts = { init: 1, before: 1, after: 1, destroy: 1 }; + +// test code +// +// listen to stdin except on Windows +const activities = hooks.activitiesOfTypes('TTYWRAP'); +strictEqual(activities.length, 1); + +const tty = activities[0]; +strictEqual(tty.type, 'TTYWRAP'); +strictEqual(typeof tty.uid, 'number'); +strictEqual(typeof tty.triggerAsyncId, 'number'); +checkInvocations(tty, checkInitOpts, 'when tty created'); + +const delayedOnCloseHandler = mustCall(() => { + checkInvocations(tty, checkEndedOpts, 'when tty ended'); +}); +stdin.on('error', (err) => fail(err)); +stdin.on('close', mustCall(() => + tick(2, delayedOnCloseHandler) +)); +stdin.destroy(); +checkInvocations(tty, checkInitOpts, 'when tty.end() was invoked'); + +process.on('exit', () => { + hooks.disable(); + hooks.sanityCheck('TTYWRAP'); + checkInvocations(tty, checkEndedOpts, 'when process exits'); +}); diff --git a/test/async-hooks/test-udpsendwrap.mjs b/test/async-hooks/test-udpsendwrap.mjs new file mode 100644 index 00000000000000..3e0d773fb73113 --- /dev/null +++ b/test/async-hooks/test-udpsendwrap.mjs @@ -0,0 +1,54 @@ +// Flags: --test-udp-no-try-send +import { mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import process from 'process'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; +import { createSocket } from 'dgram'; + +const hooks = initHooks(); + +hooks.enable(); +let send; + +const sock = createSocket('udp4') + .on('listening', mustCall(onlistening)) + .bind(); + +function onlistening() { + sock.send( + Buffer.alloc(2), 0, 2, sock.address().port, + undefined, mustCall(onsent)); + + // Init not called synchronously because dns lookup always wraps + // callback in a next tick even if no lookup is needed + // TODO (trevnorris) submit patch to fix creation of tick objects and instead + // create the send wrap synchronously. + strictEqual(hooks.activitiesOfTypes('UDPSENDWRAP').length, 0); +} + +function onsent() { + const as = hooks.activitiesOfTypes('UDPSENDWRAP'); + send = as[0]; + + strictEqual(as.length, 1); + strictEqual(send.type, 'UDPSENDWRAP'); + strictEqual(typeof send.uid, 'number'); + strictEqual(typeof send.triggerAsyncId, 'number'); + checkInvocations(send, { init: 1, before: 1 }, 'when message sent'); + + sock.close(mustCall(onsockClosed)); +} + +function onsockClosed() { + checkInvocations(send, { init: 1, before: 1, after: 1 }, 'when sock closed'); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('UDPSENDWRAP'); + checkInvocations(send, { init: 1, before: 1, after: 1, destroy: 1 }, + 'when process exits'); +} diff --git a/test/async-hooks/test-udpwrap.mjs b/test/async-hooks/test-udpwrap.mjs new file mode 100644 index 00000000000000..cc76947c374b02 --- /dev/null +++ b/test/async-hooks/test-udpwrap.mjs @@ -0,0 +1,36 @@ +import { mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import process from 'process'; +import tick from '../common/tick.js'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; +import { createSocket } from 'dgram'; + +const hooks = initHooks(); + +hooks.enable(); +const sock = createSocket('udp4'); + +const as = hooks.activitiesOfTypes('UDPWRAP'); +const udpwrap = as[0]; +strictEqual(as.length, 1); +strictEqual(udpwrap.type, 'UDPWRAP'); +strictEqual(typeof udpwrap.uid, 'number'); +strictEqual(typeof udpwrap.triggerAsyncId, 'number'); +checkInvocations(udpwrap, { init: 1 }, 'after dgram.createSocket call'); + +sock.close(mustCall(onsockClosed)); + +function onsockClosed() { + checkInvocations(udpwrap, { init: 1 }, 'when socket is closed'); + tick(2); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('UDPWRAP'); + checkInvocations(udpwrap, { init: 1, destroy: 1 }, + 'when process exits'); +} diff --git a/test/async-hooks/test-unhandled-exception-valid-ids.mjs b/test/async-hooks/test-unhandled-exception-valid-ids.mjs new file mode 100644 index 00000000000000..795a1873d47f79 --- /dev/null +++ b/test/async-hooks/test-unhandled-exception-valid-ids.mjs @@ -0,0 +1,16 @@ +import { mustCall } from '../common/index.mjs'; +import process from 'process'; +import initHooks from './init-hooks.mjs'; + +const hooks = initHooks(); +hooks.enable(); + +setImmediate(() => { + throw new Error(); +}); + +setTimeout(() => { + throw new Error(); +}, 1); + +process.on('uncaughtException', mustCall(2)); diff --git a/test/async-hooks/test-unhandled-rejection-context.mjs b/test/async-hooks/test-unhandled-rejection-context.mjs new file mode 100644 index 00000000000000..07f59a8cffad59 --- /dev/null +++ b/test/async-hooks/test-unhandled-rejection-context.mjs @@ -0,0 +1,26 @@ +import { isMainThread, skip, mustCall } from '../common/index.mjs'; + +import { strictEqual } from 'assert'; +import process from 'process'; +import initHooks from './init-hooks.mjs'; +import { executionAsyncId } from 'async_hooks'; + +if (!isMainThread) + skip('Worker bootstrapping works differently -> different async IDs'); + +const promiseAsyncIds = []; +const hooks = initHooks({ + oninit(asyncId, type) { + if (type === 'PROMISE') { + promiseAsyncIds.push(asyncId); + } + } +}); + +hooks.enable(); +Promise.reject(); + +process.on('unhandledRejection', mustCall(() => { + strictEqual(promiseAsyncIds.length, 1); + strictEqual(executionAsyncId(), promiseAsyncIds[0]); +})); diff --git a/test/async-hooks/test-writewrap.mjs b/test/async-hooks/test-writewrap.mjs new file mode 100644 index 00000000000000..509c2a4a4892cd --- /dev/null +++ b/test/async-hooks/test-writewrap.mjs @@ -0,0 +1,111 @@ +import { mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import process from 'process'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; +import { createServer, connect } from 'net'; + +const hooks = initHooks(); +hooks.enable(); + +// +// Creating server and listening on port +// +const server = createServer() + .on('listening', mustCall(onlistening)) + .on('connection', mustCall(onconnection)) + .listen(0); + +strictEqual(hooks.activitiesOfTypes('WRITEWRAP').length, 0); + +function onlistening() { + strictEqual(hooks.activitiesOfTypes('WRITEWRAP').length, 0); + // + // Creating client and connecting it to server + // + connect(server.address().port) + .on('connect', mustCall(onconnect)); + + strictEqual(hooks.activitiesOfTypes('WRITEWRAP').length, 0); +} + +function checkDestroyedWriteWraps(n, stage) { + const as = hooks.activitiesOfTypes('WRITEWRAP'); + strictEqual(as.length, n, + `${as.length} out of ${n} WRITEWRAPs when ${stage}`); + + function checkValidWriteWrap(w) { + strictEqual(w.type, 'WRITEWRAP'); + strictEqual(typeof w.uid, 'number'); + strictEqual(typeof w.triggerAsyncId, 'number'); + + checkInvocations(w, { init: 1 }, `when ${stage}`); + } + as.forEach(checkValidWriteWrap); +} + +function onconnection(conn) { + conn.write('hi'); // Let the client know we're ready. + conn.resume(); + // + // Server received client connection + // + checkDestroyedWriteWraps(0, 'server got connection'); +} + +function onconnect() { + // + // Client connected to server + // + checkDestroyedWriteWraps(0, 'client connected'); + + this.once('data', mustCall(ondata)); +} + +function ondata() { + // + // Writing data to client socket + // + const write = () => { + let writeFinished = false; + this.write('f'.repeat(1280000), () => { + writeFinished = true; + }); + process.nextTick(() => { + if (writeFinished) { + // Synchronous finish, write more data immediately. + writeFinished = false; + write(); + } else { + // Asynchronous write; this is what we are here for. + onafterwrite(this); + } + }); + }; + write(); +} + +function onafterwrite(self) { + checkDestroyedWriteWraps(1, 'client destroyed'); + self.end(); + + checkDestroyedWriteWraps(1, 'client destroyed'); + + // + // Closing server + // + server.close(mustCall(onserverClosed)); + checkDestroyedWriteWraps(1, 'server closing'); +} + +function onserverClosed() { + checkDestroyedWriteWraps(1, 'server closed'); +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('WRITEWRAP'); + checkDestroyedWriteWraps(1, 'process exits'); +} diff --git a/test/async-hooks/test-zlib.zlib-binding.deflate.mjs b/test/async-hooks/test-zlib.zlib-binding.deflate.mjs new file mode 100644 index 00000000000000..99b10b478e443b --- /dev/null +++ b/test/async-hooks/test-zlib.zlib-binding.deflate.mjs @@ -0,0 +1,76 @@ +// Flags: --expose-internals +import { mustCall } from '../common/index.mjs'; +import { strictEqual } from 'assert'; +import process from 'process'; +import initHooks from './init-hooks.mjs'; +import { checkInvocations } from './hook-checks.mjs'; + +const hooks = initHooks(); + +hooks.enable(); + +import internalTestBinding from 'internal/test/binding'; +const { internalBinding } = internalTestBinding; +const { Zlib } = internalBinding('zlib'); +import { constants } from 'zlib'; + +const handle = new Zlib(constants.DEFLATE); + +const as = hooks.activitiesOfTypes('ZLIB'); +strictEqual(as.length, 1); +const hdl = as[0]; +strictEqual(hdl.type, 'ZLIB'); +strictEqual(typeof hdl.uid, 'number'); +strictEqual(typeof hdl.triggerAsyncId, 'number'); +checkInvocations(hdl, { init: 1 }, 'when created handle'); + +// Store all buffers together so that they do not get +// garbage collected. +const buffers = { + writeResult: new Uint32Array(2), + dictionary: new Uint8Array(0), + inBuf: new Uint8Array([0x78]), + outBuf: new Uint8Array(1) +}; + +handle.init( + constants.Z_DEFAULT_WINDOWBITS, + constants.Z_MIN_LEVEL, + constants.Z_DEFAULT_MEMLEVEL, + constants.Z_DEFAULT_STRATEGY, + buffers.writeResult, + function processCallback() { this.cb(); }, + buffers.dictionary +); +checkInvocations(hdl, { init: 1 }, 'when initialized handle'); + +let count = 2; +handle.cb = mustCall(onwritten, 2); +handle.write(true, buffers.inBuf, 0, 1, buffers.outBuf, 0, 1); +checkInvocations(hdl, { init: 1 }, 'when invoked write() on handle'); + +function onwritten() { + if (--count) { + // first write + checkInvocations(hdl, { init: 1, before: 1 }, + 'when wrote to handle the first time'); + handle.write(true, buffers.inBuf, 0, 1, buffers.outBuf, 0, 1); + } else { + // second write + checkInvocations(hdl, { init: 1, before: 2, after: 1 }, + 'when wrote to handle the second time'); + } +} + +process.on('exit', onexit); + +function onexit() { + hooks.disable(); + hooks.sanityCheck('ZLIB'); + // TODO: destroy never called here even with large amounts of ticks + // is that correct? + checkInvocations(hdl, { init: 1, before: 2, after: 2 }, 'when process exits'); + + // Do something with `buffers` to keep them alive until here. + buffers.buffers = buffers; +} diff --git a/test/async-hooks/verify-graph.mjs b/test/async-hooks/verify-graph.mjs new file mode 100644 index 00000000000000..66d72f92039302 --- /dev/null +++ b/test/async-hooks/verify-graph.mjs @@ -0,0 +1,137 @@ +import '../common/index.mjs'; +import { strictEqual, ok } from 'assert'; +import { inspect as _inspect } from 'util'; + +function findInGraph(graph, type, n) { + let found = 0; + for (let i = 0; i < graph.length; i++) { + const node = graph[i]; + if (node.type === type) found++; + if (found === n) return node; + } +} + +function pruneTickObjects(activities) { + // Remove one TickObject on each pass until none is left anymore + // not super efficient, but simplest especially to handle + // multiple TickObjects in a row + const tickObject = { + found: true, + index: null, + data: null + }; + + if (!Array.isArray(activities)) + return activities; + + while (tickObject.found) { + for (let i = 0; i < activities.length; i++) { + if (activities[i].type === 'TickObject') { + tickObject.index = i; + break; + } else if (i + 1 >= activities.length) { + tickObject.found = false; + } + } + + if (tickObject.found) { + // Point all triggerAsyncIds that point to the tickObject + // to its triggerAsyncId and finally remove it from the activities + tickObject.data = activities[tickObject.index]; + const triggerId = { + new: tickObject.data.triggerAsyncId, + old: tickObject.data.uid + }; + + activities.forEach(function repointTriggerId(x) { + if (x.triggerAsyncId === triggerId.old) + x.triggerAsyncId = triggerId.new; + }); + + activities.splice(tickObject.index, 1); + } + } + return activities; +} + +export default function verifyGraph(hooks, graph) { + pruneTickObjects(hooks); + + // Map actual ids to standin ids defined in the graph + const idtouid = {}; + const uidtoid = {}; + const typeSeen = {}; + const errors = []; + + const activities = pruneTickObjects(hooks.activities); + activities.forEach(processActivity); + + function processActivity(x) { + if (!typeSeen[x.type]) typeSeen[x.type] = 0; + typeSeen[x.type]++; + + const node = findInGraph(graph, x.type, typeSeen[x.type]); + if (node == null) return; + + idtouid[node.id] = x.uid; + uidtoid[x.uid] = node.id; + if (node.triggerAsyncId == null) return; + + const tid = idtouid[node.triggerAsyncId]; + if (x.triggerAsyncId === tid) return; + + errors.push({ + id: node.id, + expectedTid: node.triggerAsyncId, + actualTid: uidtoid[x.triggerAsyncId] + }); + } + + if (errors.length) { + errors.forEach((x) => + console.error( + `'${x.id}' expected to be triggered by '${x.expectedTid}', ` + + `but was triggered by '${x.actualTid}' instead.` + ) + ); + } + strictEqual(errors.length, 0); + + // Verify that all expected types are present (but more/others are allowed) + const expTypes = Object.create(null); + for (let i = 0; i < graph.length; i++) { + if (expTypes[graph[i].type] == null) expTypes[graph[i].type] = 0; + expTypes[graph[i].type]++; + } + + for (const type in expTypes) { + ok(typeSeen[type] >= expTypes[type], + `Type '${type}': expecting: ${expTypes[type]} ` + + `found: ${typeSeen[type]}`); + } +}; + +// +// Helper to generate the input to the verifyGraph tests +// +function inspect(obj, depth) { + console.error(_inspect(obj, false, depth || 5, true)); +} + +export function printGraph(hooks) { + const ids = {}; + const uidtoid = {}; + const activities = pruneTickObjects(hooks.activities); + const graph = []; + activities.forEach(procesNode); + + function procesNode(x) { + const key = x.type.replace(/WRAP/, '').toLowerCase(); + if (!ids[key]) ids[key] = 1; + const id = `${key}:${ids[key]++}`; + uidtoid[x.uid] = id; + const triggerAsyncId = uidtoid[x.triggerAsyncId] || null; + graph.push({ type: x.type, id, triggerAsyncId }); + } + inspect(graph); +}