test: duplicate async_hooks tests in esm

Author: GeoffreyBooth

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);
+    }
+  }
+}

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
+  });
+};

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();