test: make common.mustNotCall show file:linenumber by lance · Pull Request #17257 · nodejs/node · GitHub

When a test fails via common.mustNotCall it is sometimes hard to
determine exactly what was called. This modification stores the
caller's file and line number by using the V8 Error API to capture
a stack at the time common.mustNotCall() is called. In the event
of failure, this information is printed.

I tried to write a test for this, but common.mustNotCall() ultimately
calls assert.fail() which made it difficult to do. I did simulate a
failure, and this is what the output looked like:

assert.js:42
  throw new errors.AssertionError({
  ^

AssertionError [ERR_ASSERTION]: function should not have been called at /Users/lanceball/src/node/test/parallel/test-http-host-headers.js:60
    at ClientRequest.mustNotCall (/Users/lanceball/src/node/test/common/index.js:587:12)
    at ClientRequest.emit (events.js:159:13)
    at Socket.socketErrorListener (_http_client.js:389:9)
    at Socket.emit (events.js:159:13)
    at emitErrorNT (internal/streams/destroy.js:64:8)
    at _combinedTickCallback (internal/process/next_tick.js:137:11)
    at process._tickCallback (internal/process/next_tick.js:179:9)

@nodejs/collaborators if you have a recommendation for testing this, I'm all ears.

Checklist

make -j4 test (UNIX), or vcbuild test (Windows) passes
documentation is changed or added
tests and/or benchmarks are included
commit message follows commit guidelines

Affected core subsystem(s)

test

if you have a recommendation for testing this, I'm all ears.

with a message test?

@jasnell @targos I pushed a new commit with some minor modifications. I think it makes the code easier to read. Just FYI since you've already approved.

@targos do you mean by testing the message against an expected value? The only way I can think of achieving that without resulting in a call to assert.fail() is by exposing common.getCallSite() via exports and testing that value. Is there something else you had in mind?

I mean adding a test in test/message that results in the output you want to check.

I don't understand how this works. There is no return.

Stupid mistake. Fixed and test added.

@targos test added - it actually wasn't very complicated.

CI: https://ci.nodejs.org/job/node-test-pull-request/11645/

Lance... CI was generally good but I bumped the freebsd run to later in the queue to get another one of the code-and-learn PRs finished up first https://ci.nodejs.org/job/node-test-commit-freebsd/13516/

Could you export this, it might be useful in other places.
AFAIK the second argument to Error.captureStackTrace is a function pointer so this should be:

function getCallSite(level) {
...
Error.prepareStackTrace = (err, stack) =>
    `${stack[0].getFileName()}:${stack[0].getLineNumber()}`;
...
Error.captureStackTrace(err, level);
...
const callSite = getCallSite(exports.mustNotCall);

You are right. I'm not sure why I put level as the second arg. I will take 'hours before Thanksgiving holiday' as my excuse this time. In any case, it seems that Error.captureStackTrace just quietly ignores that parameter it if it's not a function pointer, so things still worked.

I agree though that using the function pointer is probably a more reliable, and easier to grok way of indexing into the stack than by using an index number. Change coming soon.

You cracked half of #13115. 🤸‍♀️

@refack changes addressed. However, by exporting common.getCallSite() I think I've added a new task to document it...

This fits into one line.

Another CI: https://ci.nodejs.org/job/node-test-pull-request/11688/

The first one indicated some inconsistent failures on Windows. E.g.

not ok 88 parallel/test-common-must-not-call
  ---
  duration_ms: 0.318
  severity: fail
  stack: |-
    assert.js:42
      throw new errors.AssertionError({
      ^
    
    AssertionError [ERR_ASSERTION]: 'c' strictEqual 'test-common-must-not-call.js'
        at common.mustCall (c:\workspace\node-test-binary-windows\test\parallel\test-common-must-not-call.js:15:10)
        at c:\workspace\node-test-binary-windows\test\common\index.js:522:15
        at Object.<anonymous> (c:\workspace\node-test-binary-windows\test\parallel\test-common-must-not-call.js:22:3)
        at Module._compile (module.js:647:30)
        at Object.Module._extensions..js (module.js:658:10)
        at Module.load (module.js:566:32)
        at tryModuleLoad (module.js:506:12)
        at Function.Module._load (module.js:498:3)
        at Function.Module.runMain (module.js:688:10)
        at startup (bootstrap_node.js:192:16)

And... just as I pasted this, I realized the problem...

Another CI after changes to accommodate Windows paths.

https://ci.nodejs.org/job/node-test-pull-request/11781/

CI looks good, with the exception of the following unrelated errors.

centos6-64

/usr/bin/python tools/test.py -j 2 -p tap --logfile test.tap \
	--mode=release --flaky-tests=dontcare \
	 async-hooks default addons addons-napi \
	doctool known_issues
Traceback (most recent call last):
  File "tools/test.py", line 1759, in 
    sys.exit(Main())
  File "tools/test.py", line 1662, in Main
    'type': get_env_type(vm, options.type),
  File "tools/test.py", line 1569, in get_env_type
    if "fips" in subprocess.check_output([vm, "-p",
AttributeError: 'module' object has no attribute 'check_output'
Makefile:408: recipe for target 'test-ci' failed
make[1]: *** [test-ci] Error 1
Makefile:608: recipe for target 'run-ci' failed
make: *** [run-ci] Error 2
Build step 'Execute shell' marked build as failure

ubuntu1604_sharedlibs_openssl110_x64

12:36:00 gyp info ok 
12:36:00 touch test/addons-napi/.buildstamp
12:36:00 make[1]: write error: stdout
12:36:00 Makefile:608: recipe for target 'run-ci' failed

@refack if this looks good to you now, I can land it.

Shouldn't there be a > after Function?

Would it be better if we validated that if top is actually a function?

It doesn't really matter, in my opinion. The only place it is used is in Error.captureStackTrace() which does that checking for us. I.e. if it's not a function, the parameter is ignored and the top frame in the stack will be where Error.captureStackTrace() was called.

> const common = require('./test/common');
undefined
> let x = common.getCallSite()
undefined
> x
'/Users/lanceball/src/node/test/common/index.js:576'
> x = common.getCallSite('abc');
'/Users/lanceball/src/node/test/common/index.js:576'
> x = common.getCallSite(123)
'/Users/lanceball/src/node/test/common/index.js:576'
>

When a test fails via `common.mustNotCall` it is sometimes hard to determine exactly what was called. This modification stores the caller's file and line number by using the V8 Error API to capture a stack at the time `common.mustNotCall()` is called. In the event of failure, this information is printed.

Instead of indexing into the call stack to find the right level to store, just use the `Error.captureStackTrace()` function's second parameter - a function pointer.

Because of the way this test splits up the message string on ':' we need to ensure that the initial drive letter does not affect the string manipulation. Shortening it by 2 characters solves this.

Landed in: a322b8e

When a test fails via `common.mustNotCall` it is sometimes hard to determine exactly what was called. This modification stores the caller's file and line number by using the V8 Error API to capture a stack at the time `common.mustNotCall()` is called. In the event of failure, this information is printed. This change also exposes a new function in test/common, `getCallSite()` which accepts a `function` and returns a `String` with the file name and line number for the function. PR-URL: #17257 Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Michaël Zasso <targos@protonmail.com> Reviewed-By: Gibson Fahnestock <gibfahn@gmail.com> Reviewed-By: Tobias Nießen <tniessen@tnie.de> Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com> Reviewed-By: Sakthipriyan Vairamani <thechargingvolcano@gmail.com> Reviewed-By: Khaidi Chu <i@2333.moe>

Should this be backported to v6.x-staging? If yes please follow the guide and raise a backport PR, if no let me know or add the dont-land-on label.

When a test fails via `common.mustNotCall` it is sometimes hard to determine exactly what was called. This modification stores the caller's file and line number by using the V8 Error API to capture a stack at the time `common.mustNotCall()` is called. In the event of failure, this information is printed. This change also exposes a new function in test/common, `getCallSite()` which accepts a `function` and returns a `String` with the file name and line number for the function. PR-URL: #17257 Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Michaël Zasso <targos@protonmail.com> Reviewed-By: Gibson Fahnestock <gibfahn@gmail.com> Reviewed-By: Tobias Nießen <tniessen@tnie.de> Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com> Reviewed-By: Sakthipriyan Vairamani <thechargingvolcano@gmail.com> Reviewed-By: Khaidi Chu <i@2333.moe>

@gibfahn apologies for the delay on this. I am only now coming up from a lot of internal work that has prevented me from contributing to node as much as I would have liked. In any case, I'm a little more open now and will look into a backport to 6.x for this.

When a test fails via `common.mustNotCall` it is sometimes hard to determine exactly what was called. This modification stores the caller's file and line number by using the V8 Error API to capture a stack at the time `common.mustNotCall()` is called. In the event of failure, this information is printed. This change also exposes a new function in test/common, `getCallSite()` which accepts a `function` and returns a `String` with the file name and line number for the function. Backport-PR-URL: #19355 PR-URL: #17257 Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Michaël Zasso <targos@protonmail.com> Reviewed-By: Gibson Fahnestock <gibfahn@gmail.com> Reviewed-By: Tobias Nießen <tniessen@tnie.de> Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com> Reviewed-By: Sakthipriyan Vairamani <thechargingvolcano@gmail.com> Reviewed-By: Khaidi Chu <i@2333.moe>

lance added the test Issues and PRs related to the tests. label Nov 22, 2017

jasnell approved these changes Nov 22, 2017

View reviewed changes

targos approved these changes Nov 22, 2017

View reviewed changes

targos reviewed Nov 22, 2017

View reviewed changes

targos approved these changes Nov 22, 2017

View reviewed changes

gibfahn approved these changes Nov 22, 2017

View reviewed changes

refack reviewed Nov 23, 2017

View reviewed changes

lance self-assigned this Nov 23, 2017

tniessen approved these changes Nov 24, 2017

View reviewed changes

joyeecheung approved these changes Nov 29, 2017

View reviewed changes

thefourtheye approved these changes Dec 1, 2017

View reviewed changes

XadillaX approved these changes Dec 4, 2017

View reviewed changes

targos approved these changes Dec 4, 2017

View reviewed changes

lance added 4 commits December 4, 2017 11:14

test: add test for common.mustNotCall

c54e1e1

test: export commmon.getCallSite

b9402b7

test: change common.getCallSite to take a function

9e0363d

Instead of indexing into the call stack to find the right level to store, just use the `Error.captureStackTrace()` function's second parameter - a function pointer.

lance added 4 commits December 4, 2017 11:14

test: fix comment formatting

451ea32

test: document common.getCallSite()

ae47bce

test: add check for win32 and modify message

9e23ec2

Because of the way this test splits up the message string on ':' we need to ensure that the initial drive letter does not affect the string manipulation. Shortening it by 2 characters solves this.

test: fix typo in common.getCallSite doc

8e7589c

lance closed this Dec 4, 2017

MylesBorins mentioned this pull request Dec 12, 2017

v9.3.0 proposal #17631

Merged

gibfahn added backport-requested-v6.x labels Dec 20, 2017

gibfahn mentioned this pull request Dec 20, 2017

v8.9.4 proposal #17772

Closed

gibfahn mentioned this pull request Dec 20, 2017

v8.9.4 proposal #17774

Merged

lance mentioned this pull request Mar 14, 2018

[v6.x backport] test: make common.mustNotCall show file:linenumber #19355

Closed

4 tasks

MylesBorins added backported-to-v6.x and removed backport-requested-v6.x labels Mar 20, 2018

MylesBorins mentioned this pull request Apr 13, 2018

v6.14.2 proposal #19996

Merged

test: make common.mustNotCall show file:linenumber by lance · Pull Request #17257 · nodejs/node · GitHub

Uh oh!

Uh oh!

test: make common.mustNotCall show file:linenumber - #17257

test: make common.mustNotCall show file:linenumber#17257lance wants to merge 8 commits intonodejs:masternodejs/node:masterfrom lance:test-common-must-not-call-improvementsCopy head branch name to clipboard

Conversation

lance commented Nov 22, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Checklist

Affected core subsystem(s)

Uh oh!

targos commented Nov 22, 2017

Uh oh!

lance commented Nov 22, 2017

Uh oh!

lance commented Nov 22, 2017

Uh oh!

targos commented Nov 22, 2017

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

lance commented Nov 22, 2017

Uh oh!

lance commented Nov 22, 2017

Uh oh!

jasnell commented Nov 23, 2017

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

refack commented Nov 23, 2017

Uh oh!

lance commented Nov 23, 2017

Uh oh!

Choose a reason for hiding this comment

Uh oh!

lance commented Nov 24, 2017

Uh oh!

lance commented Nov 28, 2017

Uh oh!

lance commented Nov 28, 2017

Uh oh!

lance commented Nov 28, 2017

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

lance commented Dec 4, 2017

Uh oh!

gibfahn commented Dec 20, 2017

Uh oh!

lance commented Mar 13, 2018

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

10 participants

test: make common.mustNotCall show file:linenumber#17257
lance wants to merge 8 commits into
nodejs:masterfrom
lance:test-common-must-not-call-improvements

lance commented Nov 22, 2017 •
edited
Loading