test_runner: improve enqueue and dequeue

benchmark/test_runner/multi-files.js

@@ -0,0 +1,27 @@
+'use strict';
+const common = require('../common');
+
+const bench = common.createBenchmark(main, {
+  patterns: ['test/fixtures/test-runner/**/*.?(c|m)js', 'test/parallel/test-runner-*'],
+  concurrency: ['yes', 'no'],
+}, {
+  flags: ['--expose-internals'],
+});
+
+
+function main({ patterns, concurrency }) {
+  const { run } = require('node:test');
+  const { Glob } = require('internal/fs/glob');
+  const glob = new Glob([patterns]);
+  const files = glob.globSync().filter((f) => !f.includes('never_ending') && !f.includes('watch-mode'));
+  concurrency = concurrency === 'yes';
+  let tests = 0;
+
+  bench.start();
+  (async function() {
+    const stream = run({ concurrency, files });
+    for await (const { type } of stream) {
+      if (type === 'test:start') tests++;
+    }
+  })().then(() => bench.end(tests));
+}

lib/internal/test_runner/harness.js

@@ -2,7 +2,6 @@
 const {
   ArrayPrototypeForEach,
   FunctionPrototypeBind,
-  PromiseResolve,
   SafeMap,
 } = primordials;
 const { getCallerLocation } = internalBinding('util');
@@ -210,20 +209,21 @@ function getGlobalRoot() {
   return globalRoot;
 }
 
-async function startSubtest(subtest) {
+async function startSubtest(subtest, parent) {
   await reportersSetup;
   getGlobalRoot().harness.bootstrapComplete = true;
-  await subtest.start();
+  if (parent instanceof Suite) {
+    subtest.enqueue();
+  } else {
+    await subtest.start();
+  }
 }
 
 function runInParentContext(Factory) {
   function run(name, options, fn, overrides) {
     const parent = testResources.get(executionAsyncId()) || getGlobalRoot();
     const subtest = parent.createSubtest(Factory, name, options, fn, overrides);
-    if (!(parent instanceof Suite)) {
-      return startSubtest(subtest);
-    }
-    return PromiseResolve();
+    return startSubtest(subtest, parent);
   }
 
   const test = (name, options, fn) => {

lib/internal/test_runner/test.js

@@ -318,6 +318,7 @@ class Test extends AsyncResource {
     this.fn = fn;
     this.harness = null; // Configured on the root test by the test harness.
     this.mock = null;
+    this.enqueued = null;
     this.cancelled = false;
     this.skipped = skip !== undefined && skip !== false;
     this.isTodo = todo !== undefined && todo !== false;
@@ -366,13 +367,11 @@ class Test extends AsyncResource {
     ArrayPrototypePush(this.pendingSubtests, deferred);
   }
 
-  async processPendingSubtests() {
+  processPendingSubtests() {
     while (this.pendingSubtests.length > 0 && this.hasConcurrency()) {
       const deferred = ArrayPrototypeShift(this.pendingSubtests);
       const test = deferred.test;
-      this.reporter.dequeue(test.nesting, test.loc, test.name);
-      await test.run();
-      deferred.resolve();
+      PromisePrototypeThen(test.dequeue(), deferred.resolve);
     }
   }
 
@@ -525,21 +524,32 @@ class Test extends AsyncResource {
     ArrayPrototypePush(this.diagnostics, message);
   }
 
+  dequeue() {
+    this.reporter.dequeue(this.nesting, this.loc, this.name);
+    this.parent.activeSubtests++;
+    return this.run();
+  }
+
+  enqueue() {
+    if (this.enqueued) {
+      return this.enqueued.promise;
+    }
+    this.reporter.enqueue(this.nesting, kFilename, this.name);
+    this.enqueued = createDeferredPromise();
+    this.enqueued.test = this;
+    this.parent.addPendingSubtest(this.enqueued);
+    return this.enqueued.promise;
+  }
+
   start() {
     // If there is enough available concurrency to run the test now, then do
     // it. Otherwise, return a Promise to the caller and mark the test as
     // pending for later execution.
-    this.reporter.enqueue(this.nesting, this.loc, this.name);
-    if (!this.parent.hasConcurrency()) {
-      const deferred = createDeferredPromise();
-
-      deferred.test = this;
-      this.parent.addPendingSubtest(deferred);
-      return deferred.promise;
+    if (this.enqueued || !this.parent.hasConcurrency()) {
+      return this.enqueue();
     }
-
-    this.reporter.dequeue(this.nesting, this.loc, this.name);
-    return this.run();
+    this.reporter.enqueue(this.nesting, kFilename, this.name);
+    return this.dequeue();
   }
 
   [kShouldAbort]() {
@@ -575,9 +585,6 @@ class Test extends AsyncResource {
   }
 
   async run() {
-    if (this.parent !== null) {
-      this.parent.activeSubtests++;
-    }
     this.startTime = hrtime();
 
     if (this[kShouldAbort]()) {
@@ -925,7 +932,6 @@ class Suite extends Test {
 
     let stopPromise;
     try {
-      this.parent.activeSubtests++;
       await this.buildSuite;
       this.startTime = hrtime();
 
@@ -940,7 +946,7 @@ class Suite extends Test {
       }
 
       await this.runHook('before', hookArgs);
-
+      this.processPendingSubtests();
       stopPromise = stopTest(this.timeout, this.signal);
       const subtests = this.skipped || this.error ? [] : this.subtests;
       const promise = SafePromiseAll(subtests, (subtests) => subtests.start());

test/fixtures/test-runner/output/default_output.snapshot

@@ -8,6 +8,7 @@
   *[39m
   *[39m
   *[39m
+  *[39m
 
 [90m﹣ should skip [90m(*ms)[39m # SKIP[39m
 ▶ parent
@@ -18,6 +19,7 @@
     *[39m
     *[39m
     *[39m
+    *[39m
 
   [31m✖ should pass but parent fail [90m(*ms)[39m[39m
     [32m'test did not finish before its parent and was cancelled'[39m
@@ -45,6 +47,7 @@
   *[39m
   *[39m
   *[39m
+  *[39m
 
 *
 [31m✖ should fail [90m(*ms)[39m[39m
@@ -54,6 +57,7 @@
   *[39m
   *[39m
   *[39m
+  *[39m
 
 *
 [31m✖ should pass but parent fail [90m(*ms)[39m[39m

test/fixtures/test-runner/output/describe_it.js

@@ -290,12 +290,12 @@ describe('subtest sync throw fails', () => {
 });
 
 describe('describe sync throw fails', () => {
-  it('should not run', () => {});
+  it('should run', () => {});
   throw new Error('thrown from describe');
 });
 
 describe('describe async throw fails', async () => {
-  it('should not run', () => {});
+  it('should run', () => {});
   throw new Error('thrown from describe');
 });
 

test/fixtures/test-runner/output/describe_it.snapshot

@@ -25,6 +25,7 @@ not ok 3 - sync todo # TODO
     *
     *
     *
+    *
   ...
 # Subtest: sync todo with message
 not ok 4 - sync todo with message # TODO this is a failing todo
@@ -42,6 +43,7 @@ not ok 4 - sync todo with message # TODO this is a failing todo
     *
     *
     *
+    *
   ...
 # Subtest: sync skip pass
 ok 5 - sync skip pass # SKIP
@@ -74,6 +76,7 @@ not ok 8 - sync throw fail
     *
     *
     *
+    *
   ...
 # Subtest: async skip pass
 ok 9 - async skip pass # SKIP
@@ -106,6 +109,7 @@ not ok 12 - async throw fail
     *
     *
     *
+    *
   ...
 # Subtest: async skip fail
 not ok 13 - async skip fail # SKIP
@@ -140,6 +144,7 @@ not ok 14 - async assertion fail
     *
     *
     *
+    *
   ...
 # Subtest: resolve pass
 ok 15 - resolve pass
@@ -162,6 +167,7 @@ not ok 16 - reject fail
     *
     *
     *
+    *
   ...
 # Subtest: unhandled rejection - passes but warns
 ok 17 - unhandled rejection - passes but warns
@@ -204,10 +210,7 @@ ok 21 - immediate resolve pass
         *
         *
         *
-        new Promise (<anonymous>)
-        *
         *
-        Array.map (<anonymous>)
       ...
     # Subtest: mixing describe/it and test should work
     ok 2 - mixing describe/it and test should work
@@ -292,6 +295,7 @@ not ok 28 - sync skip option is false fail
     *
     *
     *
+    *
   ...
 # Subtest: <anonymous>
 ok 29 - <anonymous>
@@ -390,6 +394,7 @@ not ok 43 - callback throw
     *
     *
     *
+    *
   ...
 # Subtest: callback called twice
 not ok 44 - callback called twice
@@ -474,10 +479,10 @@ not ok 50 - custom inspect symbol that throws fail
         *
         *
         *
-        new Promise (<anonymous>)
         *
         *
-        Array.map (<anonymous>)
+        *
+        *
       ...
     # Subtest: sync throw fails at second
     not ok 2 - sync throw fails at second
@@ -497,7 +502,7 @@ not ok 50 - custom inspect symbol that throws fail
         *
         *
         *
-        async Promise.all (index 0)
+        *
       ...
     1..2
 not ok 51 - subtest sync throw fails
@@ -510,14 +515,10 @@ not ok 51 - subtest sync throw fails
   code: 'ERR_TEST_FAILURE'
   ...
 # Subtest: describe sync throw fails
-    # Subtest: should not run
-    not ok 1 - should not run
+    # Subtest: should run
+    ok 1 - should run
       ---
-      duration_ms: ZERO
-      location: '/test/fixtures/test-runner/output/describe_it.js:(LINE):3'
-      failureType: 'cancelledByParent'
-      error: 'test did not finish before its parent and was cancelled'
-      code: 'ERR_TEST_FAILURE'
+      duration_ms: *
       ...
     1..1
 not ok 52 - describe sync throw fails
@@ -541,14 +542,10 @@ not ok 52 - describe sync throw fails
     *
   ...
 # Subtest: describe async throw fails
-    # Subtest: should not run
-    not ok 1 - should not run
+    # Subtest: should run
+    ok 1 - should run
       ---
-      duration_ms: ZERO
-      location: '/test/fixtures/test-runner/output/describe_it.js:(LINE):3'
-      failureType: 'cancelledByParent'
-      error: 'test did not finish before its parent and was cancelled'
-      code: 'ERR_TEST_FAILURE'
+      duration_ms: *
       ...
     1..1
 not ok 53 - describe async throw fails
@@ -591,6 +588,8 @@ not ok 53 - describe async throw fails
       failureType: 'testTimeoutFailure'
       error: 'test timed out after 5ms'
       code: 'ERR_TEST_FAILURE'
+      stack: |-
+        async Promise.all (index 1)
       ...
     # Subtest: large timeout async test is ok
     ok 3 - large timeout async test is ok
@@ -701,9 +700,9 @@ not ok 58 - invalid subtest fail
 # Warning: Test "callback async throw after done" generated asynchronous activity after the test ended. This activity created the error "Error: thrown from callback async throw after done" and would have caused the test to fail, but instead triggered an uncaughtException event.
 # tests 67
 # suites 11
-# pass 31
+# pass 33
 # fail 19
-# cancelled 4
+# cancelled 2
 # skipped 9
 # todo 4
 # duration_ms *