node icon indicating copy to clipboard operation
node copied to clipboard

deepStrictEqual diff is unhelpful when prototype mismatches

Open Pyrolistical opened this issue 2 years ago • 6 comments

Version

v20.8.0

Platform

Darwin Me.local 23.0.0 Darwin Kernel Version 23.0.0: Fri Sep 15 14:41:34 PDT 2023; root:xnu-10002.1.13~1/RELEASE_ARM64_T8103 arm64

Subsystem

No response

What steps will reproduce the bug?

Given repo.js

import { test } from "node:test";
import { deepStrictEqual, notDeepStrictEqual } from "node:assert";

class ExtendedArray extends Array {
  constructor() {
    super();
  }
}

test("deepStrictEqual should print prototype diff", () => {
  const actual = new ExtendedArray();
  actual[0] = "hello";
  const expected = ["hello"];

  notDeepStrictEqual(
    Object.getPrototypeOf(actual),
    Object.getPrototypeOf(expected)
  );

  deepStrictEqual(actual, expected);
});

Run node --test repo.js.

How often does it reproduce? Is there a required condition?

Always

What is the expected behavior? Why is that the expected behavior?

deepStrictEquals requires actual and expected to have the same prototype, but fails to show error message describing if they are not the same.

A more helpful diff would be:

$ node --test repo.js
✖ deepStrictEqual should print prototype diff (1.581625ms)
  AssertionError [ERR_ASSERTION]: Expected values to be strictly deep-equal:
  + actual - expected
  
  + ExtendedArray(1) [
  - [
      'hello'
    ]
      at TestContext.<anonymous> (file://.../repo.js:20:3)
      at Test.runInAsyncScope (node:async_hooks:206:9)
      at Test.run (node:internal/test_runner/test:631:25)
      at Test.start (node:internal/test_runner/test:542:17)
      at startSubtest (node:internal/test_runner/harness:208:17) {
    generatedMessage: true,
    code: 'ERR_ASSERTION',
    actual prototype: Array {}
    expected prototype: Object(0) [],
    operator: 'deepStrictEqual'
  }

What do you see instead?

Only the contents of the arrays are diffed.

$ node --test repo.js
✖ deepStrictEqual should print prototype diff (1.581625ms)
  AssertionError [ERR_ASSERTION]: Expected values to be strictly deep-equal:
  + actual - expected
  
  + ExtendedArray(1) [
  - [
      'hello'
    ]
      at TestContext.<anonymous> (file://.../repo.js:20:3)
      at Test.runInAsyncScope (node:async_hooks:206:9)
      at Test.run (node:internal/test_runner/test:631:25)
      at Test.start (node:internal/test_runner/test:542:17)
      at startSubtest (node:internal/test_runner/harness:208:17) {
    generatedMessage: true,
    code: 'ERR_ASSERTION',
    actual: [ 'hello' ],
    expected: [ 'hello' ],
    operator: 'deepStrictEqual'
  }

Additional information

No response

Pyrolistical avatar Oct 25 '23 19:10 Pyrolistical

Only the contents of the arrays are diffed.

That's not accurate, did you miss the first two lines?

+ Foo(1) [
- [
    'hello'
  ]

This diff does show the different prototypes – albeit in a not very clear way – in addition to the content of the objects.

Anyways, contributions to improve the error message would be welcome :)

aduh95 avatar Oct 26 '23 12:10 aduh95

It seems the issue is caused somewhere in the test reporter, rather than being an issue with deepStrictEqual for example running the following

import { deepStrictEqual, notDeepStrictEqual } from "node:assert";

class ExtendedArray extends Array {
  constructor() {
    super();
  }
}

const actual = new ExtendedArray();
actual[0] = "hello";
const expected = ["hello"];

deepStrictEqual(actual, expected);

gives the following error:

node:internal/process/esm_loader:40
      internalBinding('errors').triggerUncaughtException(
                                ^

AssertionError [ERR_ASSERTION]: Expected values to be strictly deep-equal:
+ actual - expected

+ ExtendedArray(1) [
- [
    'hello'
  ]
    at file:///Users/debadreechatterjee/Documents/personal/node/test6.mjs:13:1
    at ModuleJob.run (node:internal/modules/esm/module_job:218:25)
    at async ModuleLoader.import (node:internal/modules/esm/loader:329:24)
    at async loadESM (node:internal/process/esm_loader:34:7)
    at async handleMainPromise (node:internal/modules/run_main:113:12) {
  generatedMessage: true,
  code: 'ERR_ASSERTION',
  actual: ExtendedArray(1) [ 'hello' ],
  expected: [ 'hello' ],
  operator: 'deepStrictEqual'
}

Node.js v22.0.0-pre

which includes the prototype somehwere along the way the test runner seems to be mangling the error message? spent some time digging but i am yet to find out!

debadree25 avatar Oct 26 '23 17:10 debadree25

@aduh95 Good catch. You also caught me renaming Foo to ExtendedArray 😅

Pyrolistical avatar Oct 26 '23 18:10 Pyrolistical

@debadree25 interesting find. Found another test runner output. If you run the original node repo.js, you get this output:

$ node repo.js 
✖ deepStrictEqual should print prototype diff (1.771583ms)
  AssertionError [ERR_ASSERTION]: Expected values to be strictly deep-equal:
  + actual - expected
  
  + ExtendedArray(1) [
  - [
      'hello'
    ]
      at TestContext.<anonymous> (file://.../repo.js:20:3)
      at Test.runInAsyncScope (node:async_hooks:206:9)
      at Test.run (node:internal/test_runner/test:631:25)
      at Test.start (node:internal/test_runner/test:542:17)
      at startSubtest (node:internal/test_runner/harness:208:17) {
    generatedMessage: true,
    code: 'ERR_ASSERTION',
    actual: [ExtendedArray],
    expected: [Array],
    operator: 'deepStrictEqual'
  }

It is something to do with the node --test cli.

What I was asking for is already implemented. Then the bug is AssertionError output is inconsistent in the follow cases:

  1. node --test with node:test: prints array contents but not type. actual: [ 'hello' ],
  2. node/node --test without node:test: prints type in front of array contents. actual: ExtendedArray(1) [ 'hello' ],
  3. node with node:test: print type but not array contents. actual: [ExtendedArray],

Case 3 is similar to case 2 as both seem to use inspect, except case 3 is using depth: 0.

Pyrolistical avatar Oct 26 '23 18:10 Pyrolistical

@Pyrolistical great finding, the 3 cases use inspect to print objects, in case 3, it calls from https://github.com/nodejs/node/blob/main/lib/internal/assert/assertion_error.js#L474-L482, as the comment says, it uses depth: 0 to reduce verbose compared to the actual error message , in case 2, it caculatedepth: 5, so the information about actual and expected is more specific, as for case 1, it uses the default depth in inspect, it is 2.

I have doubts about the different behaviors of the same interface. In my view, perhaps we should consider not using a mininum depth at least in case 3. If this is acceptable, I'm willing to do the work. @debadree25 @aduh95

zz0808 avatar Oct 30 '23 15:10 zz0808

@zz0808 the issue is that util.inspect() uses a depth first algorithm and it would have to switch to a width first algorithm. That's not a trivial undertaking though to rewrite all the code in a performant way. The performance impact can just be too high depending on the inspected objects for regular usage otherwise. The default was changed in the past and it was reverted due to these performance implications.

BridgeAR avatar Feb 12 '24 16:02 BridgeAR