test_runner: fix afterEach not running on test failures

test_runner: fix afterEach not running on test failures

PR-URL: nodejs/node#45204
Fixes: nodejs/node#45192
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
Reviewed-By: Moshe Atlow <moshe@atlow.co.il>
(cherry picked from commit 3759935ee29d8042d917d3ceaa768521c14413ff)

lib/internal/per_context/primordials.js

@@ -59,6 +59,7 @@ exports.StringPrototypeSlice = (str, ...args) => str.slice(...args)
 exports.StringPrototypeSplit = (str, search, limit) => str.split(search, limit)
 exports.Symbol = Symbol
 exports.SymbolFor = repr => Symbol.for(repr)
+exports.ReflectApply = (target, self, args) => Reflect.apply(target, self, args)
 exports.RegExpPrototypeExec = (reg, str) => reg.exec(str)
 exports.RegExpPrototypeSymbolReplace = (regexp, str, replacement) =>
   regexp[Symbol.replace](str, replacement)

lib/internal/test_runner/test.js

@@ -1,4 +1,4 @@
-// https://github.com/nodejs/node/blob/3e57891ee2fde0971e18fc383c25acf8f90def05/lib/internal/test_runner/test.js
+// https://github.com/nodejs/node/blob/3759935ee29d8042d917d3ceaa768521c14413ff/lib/internal/test_runner/test.js
 
 'use strict'
 
@@ -43,7 +43,8 @@ const {
 } = require('#internal/test_runner/utils')
 const {
   createDeferredPromise,
-  kEmptyObject
+  kEmptyObject,
+  once: runOnce
 } = require('#internal/util')
 const { isPromise } = require('#internal/util/types')
 const {
@@ -486,8 +487,14 @@ class Test extends AsyncResource {
       return
     }
 
+    const { args, ctx } = this.getRunArgs()
+    const afterEach = runOnce(async () => {
+      if (this.parent?.hooks.afterEach.length > 0) {
+        await this.parent[kRunHook]('afterEach', { args, ctx })
+      }
+    })
+
     try {
-      const { args, ctx } = this.getRunArgs()
       if (this.parent?.hooks.beforeEach.length > 0) {
         await this.parent[kRunHook]('beforeEach', { args, ctx })
       }
@@ -522,12 +529,10 @@ class Test extends AsyncResource {
         return
       }
 
-      if (this.parent?.hooks.afterEach.length > 0) {
-        await this.parent[kRunHook]('afterEach', { args, ctx })
-      }
-
+      await afterEach()
       this.pass()
     } catch (err) {
+      try { await afterEach() } catch { /* test is already failing, let's the error */ }
       if (isTestFailureError(err)) {
         if (err.failureType === kTestTimeoutFailure) {
           this.cancel(err)
@@ -735,6 +740,12 @@ class Suite extends Test {
   }
 
   async run () {
+    const hookArgs = this.getRunArgs()
+    const afterEach = runOnce(async () => {
+      if (this.parent?.hooks.afterEach.length > 0) {
+        await this.parent[kRunHook]('afterEach', hookArgs)
+      }
+    })
     try {
       this.parent.activeSubtests++
       await this.buildSuite
@@ -746,8 +757,6 @@ class Suite extends Test {
         return
       }
 
-      const hookArgs = this.getRunArgs()
-
       if (this.parent?.hooks.beforeEach.length > 0) {
         await this.parent[kRunHook]('beforeEach', hookArgs)
       }
@@ -760,13 +769,11 @@ class Suite extends Test {
 
       await SafePromiseRace([promise, stopPromise])
       await this[kRunHook]('after', hookArgs)
-
-      if (this.parent?.hooks.afterEach.length > 0) {
-        await this.parent[kRunHook]('afterEach', hookArgs)
-      }
+      await afterEach()
 
       this.pass()
     } catch (err) {
+      try { await afterEach() } catch { /* test is already failing, let's the error */ }
       if (isTestFailureError(err)) {
         this.fail(err)
       } else {

lib/internal/util.js

@@ -1,9 +1,10 @@
-// https://github.com/nodejs/node/blob/a9b1fd3987fae5ad5340859a6088b86179b576c5/lib/internal/util.js
+// https://github.com/nodejs/node/blob/3759935ee29d8042d917d3ceaa768521c14413ff/lib/internal/util.js
 'use strict'
 
 const {
   ObjectCreate,
-  ObjectFreeze
+  ObjectFreeze,
+  ReflectApply
 } = require('#internal/per_context/primordials')
 const {
   types: { isNativeError }
@@ -27,10 +28,20 @@ function isError (e) {
   return isNativeError(e) || e instanceof Error
 }
 
+function once (callback) {
+  let called = false
+  return function (...args) {
+    if (called) return
+    called = true
+    return ReflectApply(callback, this, args)
+  }
+}
+
 const kEmptyObject = ObjectFreeze(ObjectCreate(null))
 
 module.exports = {
   createDeferredPromise,
   isError,
-  kEmptyObject
+  kEmptyObject,
+  once
 }

test/message/test_runner_desctibe_it.out

@@ -42,8 +42,6 @@ not ok 4 - sync fail todo with message # TODO this is a failing todo
     *
     *
     *
-    *
-    *
   ...
 # Subtest: sync skip pass
 ok 5 - sync skip pass # SKIP

test/message/test_runner_hooks.js

@@ -1,7 +1,7 @@
-// https://github.com/nodejs/node/blob/a69a30016cf3395b0bd775c1340ab6ecbac58296/test/message/test_runner_hooks.js
+// https://github.com/nodejs/node/blob/3759935ee29d8042d917d3ceaa768521c14413ff/test/message/test_runner_hooks.js
 // Flags: --no-warnings
 'use strict'
-require('../common')
+const common = require('../common')
 const assert = require('assert')
 const { test, describe, it, before, after, beforeEach, afterEach } = require('#node:test')
 
@@ -77,6 +77,18 @@ describe('afterEach throws', () => {
   it('2', () => {})
 })
 
+describe('afterEach when test fails', () => {
+  afterEach(common.mustCall(2))
+  it('1', () => { throw new Error('test') })
+  it('2', () => {})
+})
+
+describe('afterEach throws and test fails', () => {
+  afterEach(() => { throw new Error('afterEach') })
+  it('1', () => { throw new Error('test') })
+  it('2', () => {})
+})
+
 test('test hooks', async (t) => {
   const testArr = []
   t.beforeEach((t) => testArr.push('beforeEach ' + t.name))
@@ -112,3 +124,15 @@ test('t.afterEach throws', async (t) => {
   await t.test('1', () => {})
   await t.test('2', () => {})
 })
+
+test('afterEach when test fails', async (t) => {
+  t.afterEach(common.mustCall(2))
+  await t.test('1', () => { throw new Error('test') })
+  await t.test('2', () => {})
+})
+
+test('afterEach throws and test fails', async (t) => {
+  afterEach(() => { throw new Error('afterEach') })
+  await t.test('1', () => { throw new Error('test') })
+  await t.test('2', () => {})
+})

test/message/test_runner_hooks.out

@@ -189,6 +189,86 @@ not ok 5 - afterEach throws
   error: '2 subtests failed'
   code: 'ERR_TEST_FAILURE'
   ...
+# Subtest: afterEach when test fails
+    # Subtest: 1
+    not ok 1 - 1
+      ---
+      duration_ms: *
+      failureType: 'testCodeFailure'
+      error: 'test'
+      code: 'ERR_TEST_FAILURE'
+      stack: |-
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+      ...
+    # Subtest: 2
+    ok 2 - 2
+      ---
+      duration_ms: *
+      ...
+    1..2
+not ok 6 - afterEach when test fails
+  ---
+  duration_ms: *
+  failureType: 'subtestsFailed'
+  error: '1 subtest failed'
+  code: 'ERR_TEST_FAILURE'
+  ...
+# Subtest: afterEach throws and test fails
+    # Subtest: 1
+    not ok 1 - 1
+      ---
+      duration_ms: *
+      failureType: 'testCodeFailure'
+      error: 'test'
+      code: 'ERR_TEST_FAILURE'
+      stack: |-
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+      ...
+    # Subtest: 2
+    not ok 2 - 2
+      ---
+      duration_ms: *
+      failureType: 'hookFailed'
+      error: 'failed running afterEach hook'
+      code: 'ERR_TEST_FAILURE'
+      stack: |-
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+      ...
+    1..2
+not ok 7 - afterEach throws and test fails
+  ---
+  duration_ms: *
+  failureType: 'subtestsFailed'
+  error: '2 subtests failed'
+  code: 'ERR_TEST_FAILURE'
+  ...
 # Subtest: test hooks
     # Subtest: 1
     ok 1 - 1
@@ -217,7 +297,7 @@ not ok 5 - afterEach throws
       duration_ms: *
       ...
     1..3
-ok 6 - test hooks
+ok 8 - test hooks
   ---
   duration_ms: *
   ...
@@ -261,7 +341,7 @@ ok 6 - test hooks
         *
       ...
     1..2
-not ok 7 - t.beforeEach throws
+not ok 9 - t.beforeEach throws
   ---
   duration_ms: *
   failureType: 'subtestsFailed'
@@ -308,17 +388,97 @@ not ok 7 - t.beforeEach throws
         *
       ...
     1..2
-not ok 8 - t.afterEach throws
+not ok 10 - t.afterEach throws
+  ---
+  duration_ms: *
+  failureType: 'subtestsFailed'
+  error: '2 subtests failed'
+  code: 'ERR_TEST_FAILURE'
+  ...
+# Subtest: afterEach when test fails
+    # Subtest: 1
+    not ok 1 - 1
+      ---
+      duration_ms: *
+      failureType: 'testCodeFailure'
+      error: 'test'
+      code: 'ERR_TEST_FAILURE'
+      stack: |-
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+      ...
+    # Subtest: 2
+    ok 2 - 2
+      ---
+      duration_ms: *
+      ...
+    1..2
+not ok 11 - afterEach when test fails
+  ---
+  duration_ms: *
+  failureType: 'subtestsFailed'
+  error: '1 subtest failed'
+  code: 'ERR_TEST_FAILURE'
+  ...
+# Subtest: afterEach throws and test fails
+    # Subtest: 1
+    not ok 1 - 1
+      ---
+      duration_ms: *
+      failureType: 'testCodeFailure'
+      error: 'test'
+      code: 'ERR_TEST_FAILURE'
+      stack: |-
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+      ...
+    # Subtest: 2
+    not ok 2 - 2
+      ---
+      duration_ms: *
+      failureType: 'hookFailed'
+      error: 'failed running afterEach hook'
+      code: 'ERR_TEST_FAILURE'
+      stack: |-
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+        *
+      ...
+    1..2
+not ok 12 - afterEach throws and test fails
   ---
   duration_ms: *
   failureType: 'subtestsFailed'
   error: '2 subtests failed'
   code: 'ERR_TEST_FAILURE'
   ...
-1..8
-# tests 8
+1..12
+# tests 12
 # pass 2
-# fail 6
+# fail 10
 # cancelled 0
 # skipped 0
 # todo 0

test/message/test_runner_output.out

@@ -42,8 +42,6 @@ not ok 4 - sync fail todo with message # TODO this is a failing todo
     *
     *
     *
-    *
-    *
   ...
 # Subtest: sync skip pass
 ok 5 - sync skip pass # SKIP