Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
wants to merge 8 commits into from
Closed

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

wants to merge 8 commits into from

Conversation

lance
Copy link
Member

@lance lance commented Nov 22, 2017

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

@lance lance added the test Issues and PRs related to the tests. label Nov 22, 2017
@targos
Copy link
Member

targos commented Nov 22, 2017

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

with a message test?

@lance
Copy link
Member Author

lance commented Nov 22, 2017

@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.

@lance
Copy link
Member Author

lance commented Nov 22, 2017

@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?

@targos
Copy link
Member

targos commented Nov 22, 2017

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

err.stack;
Error.prepareStackTrace = originalStackFormatter;
err.stack;
}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Stupid mistake. Fixed and test added.

@lance
Copy link
Member Author

lance commented Nov 22, 2017

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

@lance
Copy link
Member Author

lance commented Nov 22, 2017

@jasnell
Copy link
Member

jasnell commented Nov 23, 2017

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/

@@ -568,9 +568,24 @@ exports.canCreateSymLink = function() {
return true;
};

function getCallSite(level = 2) {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

  1. Could you export this, it might be useful in other places.
  2. 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);

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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.

@refack
Copy link
Contributor

refack commented Nov 23, 2017

You cracked half of #13115. 🤸‍♀️

@lance
Copy link
Member Author

lance commented Nov 23, 2017

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

@lance lance self-assigned this Nov 23, 2017
const err = new Error();
Error.captureStackTrace(err, top);
// the way V8 Error API works, the stack is not
// formatted until it is accessed
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This fits into one line.

@lance
Copy link
Member Author

lance commented Nov 24, 2017

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...

@lance
Copy link
Member Author

lance commented Nov 28, 2017

Another CI after changes to accommodate Windows paths.

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

@lance
Copy link
Member Author

lance commented Nov 28, 2017

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

@lance
Copy link
Member Author

lance commented Nov 28, 2017

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

@@ -136,6 +136,12 @@ Path to the 'fixtures' directory.

Returns an instance of all possible `ArrayBufferView`s of the provided Buffer.

### getCallSite(func)
* `func` [&lt;Function]
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Shouldn't there be a > after Function?

@@ -568,9 +568,23 @@ exports.canCreateSymLink = function() {
return true;
};

exports.getCallSite = function getCallSite(top) {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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.
@lance
Copy link
Member Author

lance commented Dec 4, 2017

Landed in: a322b8e

@lance lance closed this Dec 4, 2017
MylesBorins pushed a commit that referenced this pull request Dec 12, 2017
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>
MylesBorins pushed a commit that referenced this pull request Dec 12, 2017
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>
@MylesBorins MylesBorins mentioned this pull request Dec 12, 2017
gibfahn pushed a commit that referenced this pull request Dec 20, 2017
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
Copy link
Member

gibfahn commented Dec 20, 2017

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.

@gibfahn gibfahn mentioned this pull request Dec 20, 2017
gibfahn pushed a commit that referenced this pull request Dec 20, 2017
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 gibfahn mentioned this pull request Dec 20, 2017
@lance
Copy link
Member Author

lance commented Mar 13, 2018

@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.

MylesBorins pushed a commit that referenced this pull request Mar 20, 2018
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>
MylesBorins pushed a commit that referenced this pull request Mar 28, 2018
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>
MylesBorins pushed a commit that referenced this pull request Mar 30, 2018
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>
@MylesBorins MylesBorins mentioned this pull request Apr 13, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
test Issues and PRs related to the tests.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

10 participants