Assertion errors are not formatted correctly when using node.js built-in test runner

[gustav-olsen-groupone]

Something about the UnexpectedError object makes breaks the output formatting of the default spec reporter in the built-in node.js test runner.

$ FORCE_COLOR=0 node --test
▶ unexpected-node-test-serialization-issue
  ✖ should be a function (1.835808ms)
    "Error [UnexpectedError]: \nexpected 'not a function' to be a function\n\n    at TestContext.<anonymous> (file:///home/gno/Scratch/unexpected-node-test-serialization-issue/test/unexpected-node-test-serialization-issue.spec.js:7:5)\n    at Test.runInAsyncScope (node:async_hooks:211:14)\n    at Test.run (node:internal/test_runner/test:931:25)\n    at Test.start (node:internal/test_runner/test:829:17)\n    at node:internal/test_runner/test:1308:71\n    at node:internal/per_context/primordials:483:82\n    at new Promise (<anonymous>)\n    at new SafePromise (node:internal/per_context/primordials:451:29)\n    at node:internal/per_context/primordials:483:9\n    at Array.map (<anonymous>)\n    set UNEXPECTED_FULL_TRACE=true to see the full stack trace {\n  errorMode: 'default',\n  parent: Error [UnexpectedError]\n      at expectPrototype._callInNestedContext (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1843:26)\n      at wrappedExpect (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1402:26)\n      at Object.handler (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/assertions.js:148:7)\n      at expectPrototype._executeExpect (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1517:44)\n      at /home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1402:81\n      at expectPrototype._callInNestedContext (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1824:30)\n      at wrappedExpect (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1402:26)\n      at Object.handler (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/assertions.js:191:7)\n      at expectPrototype._executeExpect (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1517:44)\n      at expectPrototype._expect (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1538:23)\n      at expect (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:2017:19)\n      at TestContext.<anonymous> (file:///home/gno/Scratch/unexpected-node-test-serialization-issue/test/unexpected-node-test-serialization-issue.spec.js:7:5)\n      at Test.runInAsyncScope (node:async_hooks:211:14)\n      at Test.run (node:internal/test_runner/test:931:25)\n      at Test.start (node:internal/test_runner/test:829:17)\n      at node:internal/test_runner/test:1308:71 {\n    errorMode: 'default',\n    parent: Error [UnexpectedError]\n        at expectPrototype._callInNestedContext (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1843:26)\n        at expectPrototype.fail (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1743:10)\n        at Object.handler (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/assertions.js:13:14)\n        at expectPrototype._executeExpect (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1517:44)\n        at /home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1402:81\n        at expectPrototype._callInNestedContext (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1824:30)\n        at wrappedExpect (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1402:26)\n        at Object.handler (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/assertions.js:148:7)\n        at expectPrototype._executeExpect (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1517:44)\n        at /home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1402:81\n        at expectPrototype._callInNestedContext (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1824:30)\n        at wrappedExpect (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1402:26)\n        at Object.handler (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/assertions.js:191:7)\n        at expectPrototype._executeExpect (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1517:44)\n        at expectPrototype._expect (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:1538:23)\n        at expect (/home/gno/Scratch/unexpected-node-test-serialization-issue/node_modules/unexpected/build/lib/createTopLevelExpect.js:2017:19) {\n      errorMode: 'default',\n      parent: [Error],\n      originalError: undefined\n    },\n    originalError: undefined\n  },\n  originalError: undefined,\n  _hasSerializedErrorMessage: true\n}"

The output works as expected with the tap reporter

$ node --test --test-reporter=tap
TAP version 13
# Subtest: unexpected-node-test-serialization-issue
    # Subtest: should be a function
    not ok 1 - should be a function
      ---
      duration_ms: 1.98512
      location: '/home/gno/Scratch/unexpected-node-test-serialization-issue/test/unexpected-node-test-serialization-issue.spec.js:6:3'
      failureType: 'testCodeFailure'
      error: |-

        expected 'not a function' to be a function

      code: 'ERR_TEST_FAILURE'
      stack: |-
        new Promise (<anonymous>)
        Array.map (<anonymous>)
        new Promise (<anonymous>)
      ...
    1..1
not ok 1 - unexpected-node-test-serialization-issue
  ---
  duration_ms: 2.357206
  type: 'suite'
  location: '/home/gno/Scratch/unexpected-node-test-serialization-issue/test/unexpected-node-test-serialization-issue.spec.js:5:1'
  failureType: 'subtestsFailed'
  error: '1 subtest failed'
  code: 'ERR_TEST_FAILURE'
  ...
1..1
# tests 1
# suites 1
# pass 0
# fail 1
# cancelled 0
# skipped 0
# todo 0
# duration_ms 70.995069

I have not yet had the chance to root-cause this issue, but I wanted to document it here in case anyone else runs into it.

I made a repo which reproduces the issue: https://github.com/gustav-olsen-groupone/unexpected-node-test-serialization-issue

[gustav-olsen-groupone]

Wrapping the output in assert.fail seems to fix the serialization issue. It's not a solution, but it could be a hint as to what causes the problem. Just wrapping the UnexpectedError object is not enough.

gustav-olsen-groupone/unexpected-node-test-serialization-issue@e2bf40f