lib: add diagnostics_channel events to module loading

Author: Stephen Belanger

lib/internal/modules/cjs/loader.js

@@ -149,6 +149,9 @@ const {
   packageImportsResolve
 } = require('internal/modules/esm/resolve');
 
+const dc = require('diagnostics_channel');
+const onLoad = dc.tracingChannel('module.require');
+
 const isWindows = process.platform === 'win32';
 
 const relativeResolveCache = ObjectCreate(null);
@@ -1102,7 +1105,10 @@ Module.prototype.require = function(id) {
   }
   requireDepth++;
   try {
-    return Module._load(id, this, /* isMain */ false);
+    return onLoad.traceSync(Module._load, {
+      parentFilename: this.filename,
+      id,
+    }, Module, id, this, /* isMain */ false);
   } finally {
     requireDepth--;
   }

lib/internal/modules/esm/loader.js

@@ -56,6 +56,9 @@ function getTranslators() {
 }
 const { getOptionValue } = require('internal/options');
 
+const dc = require('diagnostics_channel');
+const onLoad = dc.tracingChannel('module.import');
+
 /**
  * @typedef {object} ExportedHooks
  * @property {Function} globalPreload Global preload hook.
@@ -374,14 +377,18 @@ class ESMLoader {
       return module;
     };
     const ModuleJob = require('internal/modules/esm/module_job');
-    const job = new ModuleJob(
-      this, url, undefined, evalInstance, false, false);
-    this.moduleMap.set(url, undefined, job);
-    const { module } = await job.run();
+    const namespace = await onLoad.tracePromise(async () => {
+      const job = new ModuleJob(
+        this, url, undefined, evalInstance, false, false);
+      this.moduleMap.set(url, undefined, job);
+
+      const { module } = await job.run();
+      return module.getNamespace();
+    }, { parentURL: '<eval>', url });
 
     return {
       __proto__: null,
-      namespace: module.getNamespace(),
+      namespace,
     };
   }
 
@@ -513,9 +520,14 @@ class ESMLoader {
     const jobs = new Array(count);
 
     for (let i = 0; i < count; i++) {
-      jobs[i] = this.getModuleJob(specifiers[i], parentURL, importAssertions)
-        .then((job) => job.run())
-        .then(({ module }) => module.getNamespace());
+      jobs[i] = onLoad.tracePromise(async () => {
+        const job = await this.getModuleJob(specifiers[i], parentURL, importAssertions);
+        const { module } = await job.run();
+        return module.getNamespace();
+      }, {
+        parentURL,
+        url: specifiers[i]
+      });
     }
 
     const namespaces = await SafePromiseAllReturnArrayLike(jobs);

test/parallel/test-diagnostics-channel-module-import-error.js

@@ -0,0 +1,65 @@
+'use strict';
+const common = require('../common');
+const assert = require('assert');
+const dc = require('diagnostics_channel');
+
+const trace = dc.tracingChannel('module.import');
+const events = [];
+let lastEvent;
+
+function track(name) {
+  return (event) => {
+    // Verify every event after the first is the same object
+    if (events.length) {
+      assert.strictEqual(event, lastEvent);
+    }
+    lastEvent = event;
+
+    events.push({ name, ...event });
+  };
+}
+
+trace.subscribe({
+  start: common.mustCall(track('start')),
+  end: common.mustCall(track('end')),
+  asyncStart: common.mustCall(track('asyncStart')),
+  asyncEnd: common.mustCall(track('asyncEnd')),
+  error: common.mustCall(track('error')),
+});
+
+import('does-not-exist').then(
+  common.mustNotCall(),
+  common.mustCall((error) => {
+    // Verify order and contents of each event
+    assert.deepStrictEqual(events, [
+      {
+        name: 'start',
+        parentURL: `file://${module.filename}`,
+        url: 'does-not-exist',
+      },
+      {
+        name: 'end',
+        parentURL: `file://${module.filename}`,
+        url: 'does-not-exist',
+      },
+      {
+        name: 'error',
+        parentURL: `file://${module.filename}`,
+        url: 'does-not-exist',
+        error,
+      },
+      {
+        name: 'asyncStart',
+        parentURL: `file://${module.filename}`,
+        url: 'does-not-exist',
+        error,
+      },
+      {
+        name: 'asyncEnd',
+        parentURL: `file://${module.filename}`,
+        url: 'does-not-exist',
+        error,
+      },
+    ]);
+  })
+);

test/parallel/test-diagnostics-channel-module-import.js

@@ -0,0 +1,59 @@
+'use strict';
+const common = require('../common');
+const assert = require('assert');
+const dc = require('diagnostics_channel');
+
+const trace = dc.tracingChannel('module.import');
+const events = [];
+let lastEvent;
+
+function track(name) {
+  return (event) => {
+    // Verify every event after the first is the same object
+    if (events.length) {
+      assert.strictEqual(event, lastEvent);
+    }
+    lastEvent = event;
+
+    events.push({ name, ...event });
+  };
+}
+
+trace.subscribe({
+  start: common.mustCall(track('start')),
+  end: common.mustCall(track('end')),
+  asyncStart: common.mustCall(track('asyncStart')),
+  asyncEnd: common.mustCall(track('asyncEnd')),
+  error: common.mustNotCall(track('error')),
+});
+
+import('http').then(
+  common.mustCall((result) => {
+    // Verify order and contents of each event
+    assert.deepStrictEqual(events, [
+      {
+        name: 'start',
+        parentURL: `file://${module.filename}`,
+        url: 'http',
+      },
+      {
+        name: 'end',
+        parentURL: `file://${module.filename}`,
+        url: 'http',
+      },
+      {
+        name: 'asyncStart',
+        parentURL: `file://${module.filename}`,
+        url: 'http',
+        result,
+      },
+      {
+        name: 'asyncEnd',
+        parentURL: `file://${module.filename}`,
+        url: 'http',
+        result,
+      },
+    ]);
+  }),
+  common.mustNotCall(),
+);

test/parallel/test-diagnostics-channel-module-require-error.js

@@ -0,0 +1,56 @@
+'use strict';
+const common = require('../common');
+const assert = require('assert');
+const dc = require('diagnostics_channel');
+
+const trace = dc.tracingChannel('module.require');
+const events = [];
+let lastEvent;
+
+function track(name) {
+  return (event) => {
+    // Verify every event after the first is the same object
+    if (events.length) {
+      assert.strictEqual(event, lastEvent);
+    }
+    lastEvent = event;
+
+    events.push({ name, ...event });
+  };
+}
+
+trace.subscribe({
+  start: common.mustCall(track('start')),
+  end: common.mustCall(track('end')),
+  asyncStart: common.mustNotCall(track('asyncStart')),
+  asyncEnd: common.mustNotCall(track('asyncEnd')),
+  error: common.mustCall(track('error')),
+});
+
+let error;
+try {
+  require('does-not-exist');
+} catch (err) {
+  error = err;
+}
+
+// Verify order and contents of each event
+assert.deepStrictEqual(events, [
+  {
+    name: 'start',
+    parentFilename: module.filename,
+    id: 'does-not-exist',
+  },
+  {
+    name: 'error',
+    parentFilename: module.filename,
+    id: 'does-not-exist',
+    error,
+  },
+  {
+    name: 'end',
+    parentFilename: module.filename,
+    id: 'does-not-exist',
+    error,
+  },
+]);

test/parallel/test-diagnostics-channel-module-require.js

@@ -0,0 +1,45 @@
+'use strict';
+const common = require('../common');
+const assert = require('assert');
+const dc = require('diagnostics_channel');
+
+const trace = dc.tracingChannel('module.require');
+const events = [];
+let lastEvent;
+
+function track(name) {
+  return (event) => {
+    // Verify every event after the first is the same object
+    if (events.length) {
+      assert.strictEqual(event, lastEvent);
+    }
+    lastEvent = event;
+
+    events.push({ name, ...event });
+  };
+}
+
+trace.subscribe({
+  start: common.mustCall(track('start')),
+  end: common.mustCall(track('end')),
+  asyncStart: common.mustNotCall(track('asyncStart')),
+  asyncEnd: common.mustNotCall(track('asyncEnd')),
+  error: common.mustNotCall(track('error')),
+});
+
+const result = require('http');
+
+// Verify order and contents of each event
+assert.deepStrictEqual(events, [
+  {
+    name: 'start',
+    parentFilename: module.filename,
+    id: 'http',
+  },
+  {
+    name: 'end',
+    parentFilename: module.filename,
+    id: 'http',
+    result,
+  },
+]);