async_hooks: skip sanity checks when disabled #15454

AndreasMadsen · 2017-09-18T12:17:43Z

Checklist

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

Affected core subsystem(s)

async_hooks

While async_hooks is experimental we should skip the sanity checks when async_hooks is disabled. If someone would like a flag as well, we could add another async_hooks_field that is > 0 when either the flag is used or the hooks are enabled. Should be trivial.

This makes the sanity checks stricter when async_hooks is enabled, so be sure to run CITGM before merging this. However, since async_hooks is rarely enabled there shouldn't be any issues.

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

Ref: #14387
Ref: #14722
Ref: #14717
Ref: #15448

AndreasMadsen · 2017-09-18T12:20:27Z

/cc @nodejs/async_hooks @mcollina

refack · 2017-09-18T12:51:14Z

👍
IMO adding a state flag (CLI or ENV) to enable state validation even if there are no hooks, would make this even better. (similar in concept to --abort-on-uncaught-exception or --abort-on-unhandled-rejection)

For debugging, and CI time assertions (even though we have

node/test/common/index.js

Lines 64 to 65 in a4e923f

// If env var is set then enable async_hook hooks for all tests.

if (process.env.NODE_TEST_WITH_ASYNC_HOOKS) {

). Making sure the assertion are active irrespective of transient state seems cleanest.
For use-cases where the state is important for full processes lifespan, but temporarily hooks might not be registered.

As for the current implementation, I'd like to see it more encapsulated, maybe like:
js

const { validateAsyncId, validateTriggerId } = process.binding('async_wrap')
...
const id = validateAsyncId(argId);

cpp

Environment::AsyncHooks::validate_ids(double async_id, double trigger_id);

mcollina

I'm definitely 👍 on this approach. Before landing we should verify that we do not break shot and hapi tests, even with async_hooks enabled: http://npm.im/shot.

There is a plan to move domains on top of async-hooks and the hapi community use domains.

AndreasMadsen · 2017-09-18T13:37:20Z

@refack I've created a validation function on the JS side. On the C++ side, I would prefer to keep it as it. There aren't that many validations and only the line where the macro is used is shown in the error. If I merge those asserts it will be more difficult to know which assert failed.

I will look into adding the flag.

AndreasMadsen · 2017-09-18T14:45:33Z

@refack I've added a --async-hooks-sanity-check flag, please check :)

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

jasnell · 2017-09-18T15:18:50Z

doc/api/cli.md

+-->
+
+Enables sanity checks for async_hooks. These can also be enabled in runtime
+by enabling one of the `async_hooks` hooks.


Is the intent to leave this flag in forever?
Also, would prefer to take -sanity out... just --async-hooks-check

Is the intent to leave this flag in forever?

Hopefully, we can become so robust the checks are always enabled.

Also, would prefer to take -sanity out... just --async-hooks-check

That is fine :)

mscdex · 2017-09-18T16:15:35Z

lib/async_hooks.js

+  if (triggerAsyncId !== null)
+    validateAsyncId(triggerAsyncId, 'triggerAsyncId');
+  if (async_hook_fields[kSanityCheck] > 0 &&
+     (typeof type !== 'string' || type.length <= 0)) {


Indentation is missing a single space here?

I don't know. The linter says it is fine.

hm. another one of those things we do so regularly I didn't realize we needed a linter fix for. If you run this you'll see that >90% of these would have one more space

git grep -A 1 " if (.*[^{);]$" lib/

i'll check on getting a rule into the linter.

AndreasMadsen · 2017-09-18T19:27:06Z

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

addaleax · 2017-09-18T19:30:08Z

I probably should have come up with this sooner, but how about just printing warnings in these cases instead of crashing, and that unconditionally? That should help find bugs while at the same time preventing crashes …

AndreasMadsen · 2017-09-18T19:36:35Z

I probably should have come up with this sooner, but how about just printing warnings in these cases instead of crashing, and that unconditionally? That should help find bugs while at the same time preventing crashes …

My understand from @trevnorris was that it would leave async_hooks in too strange a state to be useful. Perhaps I misunderstood, a warning is reasonable to me.

refack · 2017-09-18T21:30:00Z

I like it. Maybe the names need some bikeshedding, but I have no strong opinions.

refack · 2017-09-18T21:35:20Z

Maybe one more thing, add the CLI flag to NODE_OPTIONS:

node/src/node.cc

Lines 3936 to 3943 in 1a0727d

    
           static void CheckIfAllowedInEnv(const char* exe, bool is_env, 
        
                                           const char* arg) { 
        
             if (!is_env) 
        
               return; 
        
             static const char* whitelist[] = { 
        
               // Node options, sorted in `node --help` order for ease of comparison. 
        
               "--require", "-r",

(had an idea for CLI flag name ~~--abort-on-async-hooks-check~~ not good, implies that without flag might not abort)

AndreasMadsen · 2017-09-19T05:34:19Z

Maybe one more thing, add the CLI flag to NODE_OPTIONS.

Sorry, I don't understand what you mean. Could you be very explicit :)

AndreasMadsen · 2017-09-19T06:47:36Z

I like it. Maybe the names need some bikeshedding, but I have no strong opinions.

Bring it, I'm not so happy about the names either :)

refack · 2017-09-19T13:51:57Z

Maybe one more thing, add the CLI flag to NODE_OPTIONS.

Sorry, I don't understand what you mean. Could you be very explicit :)

NODE_OPTIONS is an environment variable that is used to pass multiple CLI arguments to the node binary - https://nodejs.org/api/cli.html#cli_node_options_options
It only allows CLI args from a whitelist -

node/src/node.cc

Lines 3941 to 3946 in 1a0727d

    
           static const char* whitelist[] = { 
        
             // Node options, sorted in `node --help` order for ease of comparison. 
        
             "--require", "-r", 
        
             "--inspect", 
        
             "--inspect-brk", 
        
             "--inspect-port",

In order for the new arg to be able to be used via NODE_OPTIONS it needs to be added to the whitelist, and probably to the test test/parallel/test-cli-node-options.js (or to the negative test test/parallel/test-cli-node-options-disallowed.js` if we decide to blacklist it).

As for the arg name IMHO it's missing a verb. I think force is a good one, to give us - --force-async-hooks-checks

jasnell · 2017-09-19T14:01:38Z

Bring it, I'm not so happy about the names either :)

I think just avoiding the word "sanity" throughout would be better... everything else looks fine to me.

AndreasMadsen · 2017-09-19T14:02:11Z

src/node.cc

@@ -3953,6 +3959,7 @@ static void CheckIfAllowedInEnv(const char* exe, bool is_env,
    "--trace-warnings",
    "--redirect-warnings",
    "--trace-sync-io",
+    "--async-hooks-check",


@refack is this the line you are talking about?

trevnorris · 2017-09-21T10:35:58Z

lib/_http_outgoing.js

+        let socketAsyncId = this.socket[async_id_symbol];
+        // If the socket was set directly it won't be correctly initialized
+        // with an async_id_symbol.
+        // TODO(AndreasMadsen): @trevnorris sugested some more correct solution


typo: "suggested"

trevnorris · 2017-09-21T10:44:34Z

src/env-inl.h

+  if (fields_[kSanityCheck] > 0) {
+    CHECK_GE(async_id, 0);
+    CHECK_GE(trigger_id, 0);
+  }


hm. this is cool for release builds, but i think they should also always be on in debug builds.

They are always on in tests, and you can `alias node='node --force-async-hooks-check' if you like. I think it is important that we have them opt-in in release builds too.

And export NODE_OPTIONS=--force-async-hooks-check.

trevnorris · 2017-09-21T10:52:39Z

I understand where this comes from but allowing the stack to possibly get corrupted makes my stomach turn. It also inhibits the usefulness of async_hooks.executionAsyncId()/async_hooks.triggerAsyncId(), and since other core utilities are becoming dependent on async hooks we should take into consideration how allowing bad values through would affect them. I understand that being "experimental" means certain things, but even so I wonder if disabling all checks will help. i.e. bugs will get through that'll surface once the checks are always enabled, once it's no longer experimental.

I do like that you've yanked out the value checks into a single function.

AndreasMadsen · 2017-09-21T11:36:12Z

@trevnorris we have been playing this game for a long time. I don't think we can go into LTS with node being this unstable. To my mind, it has little to do with async_hooks being experimental, but rather it is because we keep seeing errors. I think we have reached the point where we need to try a different solution. Also, this PR actually makes some of the checks more strict, but only when async_hooks is enabled or the flag is passed, thus it also helps us to find errors.

Regarding async_hooks.executionAsyncId() and async_hooks.triggerAsyncId() they are already corrupted when promises are used and async_hooks isn't enabled. This is because of how we lazy initialize in the PromiseHooks. If you like we could print a warning suggesting to use the --force-async-hooks-checks.

addaleax · 2017-09-21T19:17:21Z

test/inspector/test-async-hook-teardown-at-debug-end.js

@@ -7,23 +7,12 @@ const spawn = require('child_process').spawn;

 const script = `
 const assert = require('assert');
+const async_wrap = process.binding('async_wrap');
+const {kTotals} = async_wrap.constants;


I think if this were a “real” script out linter would expect spaces inside {} … no big deal, tho :)

refack · 2017-09-21T21:56:26Z

TN: I understand that being "experimental" means certain things, but even so I wonder if disabling all checks will help.

AM: I don't think we can go into LTS with node being this unstable.

So the tl;dr is can we converge on all the errors before LTS (~40 days)? If not then IMHO we need this PR 🤷‍♂️
Otherwise we are entering LTS with (1) an experimental module that's effectively always on (2) adding instability through assertion of invariants that may not be used.

Maybe turn this back to always-on for v9.x, but keeping it opt-in for v8.x LTS?

refack · 2017-09-21T22:00:49Z

P.S. Ironically those that do use async-hooks are happy (from what I'm hearing via: #14794, anecdotes from new-relic, and I assume Iron Source)

AndreasMadsen · 2017-10-19T09:01:24Z

rebased.

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

AndreasMadsen · 2017-10-19T10:26:21Z

Two test failures. Both appear to be unrelated.

Raspbian

fs.js:924
  return binding.readdir(pathModule.toNamespacedPath(path), options.encoding);
                 ^

Error: ENOENT: no such file or directory, scandir '/home/iojs/build/workspace/node-test-binary-arm/out/doc/api'
    at Object.fs.readdirSync (fs.js:924:18)
    at Object.<anonymous> (/home/iojs/build/workspace/node-test-binary-arm/test/sequential/test-make-doc.js:15:17)
    at Module._compile (module.js:607:30)
    at Object.Module._extensions..js (module.js:618:10)
    at Module.load (module.js:526:32)
    at tryModuleLoad (module.js:489:12)
    at Function.Module._load (module.js:481:3)
    at Function.Module.runMain (module.js:648:10)
    at startup (bootstrap_node.js:191:16)
    at bootstrap_node.js:609:3

AIX

/home/iojs/build/workspace/node-test-commit-aix/nodes/aix61-ppc64/test/sequential/test-fs-readfile-tostring-fail.js:57
  throw err;
  ^

AssertionError [ERR_ASSERTION]: false == true
    at /home/iojs/build/workspace/node-test-commit-aix/nodes/aix61-ppc64/test/sequential/test-fs-readfile-tostring-fail.js:31:12
    at /home/iojs/build/workspace/node-test-commit-aix/nodes/aix61-ppc64/test/common/index.js:531:15
    at FSReqWrap.readFileAfterClose [as oncomplete] (fs.js:528:3)

rerunning AIX: https://ci.nodejs.org/job/node-test-commit-aix/nodes=aix61-ppc64/9499/

richardlau · 2017-10-19T10:34:46Z

The AIX failure is being addressed by #16273.

AndreasMadsen · 2017-10-19T10:41:35Z

@richardlau thanks. Found the other too: #16301

We can land :)

AndreasMadsen · 2017-10-19T10:46:32Z

Landed in 7c079d1

AndreasMadsen · 2017-10-19T10:50:04Z

I will prepear the dont-land-on-v8.x PR :)

PR-URL: #15454 Ref: #14387 Ref: #14722 Ref: #14717 Ref: #15448 Reviewed-By: Refael Ackermann <[email protected]> Reviewed-By: Matteo Collina <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Anna Henningsen <[email protected]>

PR-URL: nodejs/node#15454 Ref: nodejs/node#14387 Ref: nodejs/node#14722 Ref: nodejs/node#14717 Ref: nodejs/node#15448 Reviewed-By: Refael Ackermann <[email protected]> Reviewed-By: Matteo Collina <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Anna Henningsen <[email protected]>

Ref: #15454 PR-URL: #16318 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Refael Ackermann <[email protected]>

Ref: nodejs/node#15454 PR-URL: nodejs/node#16318 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Refael Ackermann <[email protected]>

PR-URL: nodejs/node#15454 Ref: nodejs/node#14387 Ref: nodejs/node#14722 Ref: nodejs/node#14717 Ref: nodejs/node#15448 Reviewed-By: Refael Ackermann <[email protected]> Reviewed-By: Matteo Collina <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Anna Henningsen <[email protected]>

Ref: nodejs/node#15454 PR-URL: nodejs/node#16318 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Refael Ackermann <[email protected]>

This removes a comment relevant to runtime checks for `async_hooks`. Even if `async_hooks` is experimental, the check pointed by the comment is performed as default unless either `--no-force-async-hooks-checks` is given from CLI arguments or any async_hook is enabled. Refs: nodejs#16318 Refs: nodejs#15454 (comment) Signed-off-by: Daeyeon Jeong [email protected]

This removes a comment relevant to runtime checks for `async_hooks`. Even if `async_hooks` is experimental, the check pointed by the comment is performed as default unless `--no-force-async-hooks-checks` is given from CLI arguments. Refs: nodejs#16318 Refs: nodejs#15454 (comment) Signed-off-by: Daeyeon Jeong [email protected]

This removes a comment relevant to runtime checks for `async_hooks`. Even if `async_hooks` is experimental, the check pointed by the comment is performed as default unless `--no-force-async-hooks-checks` is given from CLI arguments. Refs: #16318 Refs: #15454 (comment) Signed-off-by: Daeyeon Jeong [email protected] PR-URL: #43317 Reviewed-By: Luigi Pinca <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Juan José Arboleda <[email protected]>

This removes a comment relevant to runtime checks for `async_hooks`. Even if `async_hooks` is experimental, the check pointed by the comment is performed as default unless `--no-force-async-hooks-checks` is given from CLI arguments. Refs: nodejs/node#16318 Refs: nodejs/node#15454 (comment) Signed-off-by: Daeyeon Jeong [email protected] PR-URL: nodejs/node#43317 Reviewed-By: Luigi Pinca <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Juan José Arboleda <[email protected]>

nodejs-github-bot added c++ Issues and PRs that require attention from people who are familiar with C++. lib / src Issues and PRs related to general changes in the lib or src directory. labels Sep 18, 2017

AndreasMadsen added the async_hooks Issues and PRs related to the async hooks subsystem. label Sep 18, 2017

This was referenced Sep 18, 2017

async_hooks: async hook stack assertion shadows "Maximum call stack size exceeded" #15448

Closed

async_hooks experimental status #14717

Closed

mcollina reviewed Sep 18, 2017

View reviewed changes

jasnell reviewed Sep 18, 2017

View reviewed changes

mscdex reviewed Sep 18, 2017

View reviewed changes

refack approved these changes Sep 18, 2017

View reviewed changes

AndreasMadsen commented Sep 19, 2017

View reviewed changes

trevnorris reviewed Sep 21, 2017

View reviewed changes

addaleax approved these changes Sep 21, 2017

View reviewed changes

AndreasMadsen closed this Oct 19, 2017

mcollina added dont-land-on-v4.x and removed tsc-agenda Issues and PRs to discuss during the meetings of the TSC. labels Oct 19, 2017

AndreasMadsen mentioned this pull request Oct 19, 2017

async_hooks: enable runtime checks by default #16318

Closed

4 tasks

AndreasMadsen mentioned this pull request Oct 30, 2017

Proposal: 2017-10-31, Version 9.0.0 (Current) #15135

Merged

jasnell pushed a commit that referenced this pull request Oct 30, 2017

async_hooks: enable runtime checks by default

07d71c9

Ref: #15454 PR-URL: #16318 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Refael Ackermann <[email protected]>

Qard pushed a commit to ayojs/ayo that referenced this pull request Nov 2, 2017

async_hooks: enable runtime checks by default

a9ced7f

Ref: nodejs/node#15454 PR-URL: nodejs/node#16318 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Refael Ackermann <[email protected]>

Qard pushed a commit to ayojs/ayo that referenced this pull request Nov 2, 2017

async_hooks: enable runtime checks by default

13be443

Ref: nodejs/node#15454 PR-URL: nodejs/node#16318 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Refael Ackermann <[email protected]>

addaleax pushed a commit to ayojs/ayo that referenced this pull request Dec 7, 2017

async_hooks: enable runtime checks by default

10b50ab

Ref: nodejs/node#15454 PR-URL: nodejs/node#16318 Reviewed-By: Anna Henningsen <[email protected]> Reviewed-By: Refael Ackermann <[email protected]>

daeyeon mentioned this pull request Jun 5, 2022

src: remove a stale comment in async_hooks #43317

Merged

async_hooks: skip sanity checks when disabled #15454

async_hooks: skip sanity checks when disabled #15454

Conversation

AndreasMadsen commented Sep 18, 2017 • edited Loading

Checklist

Affected core subsystem(s)

AndreasMadsen commented Sep 18, 2017 • edited Loading

refack commented Sep 18, 2017

mcollina left a comment

Choose a reason for hiding this comment

AndreasMadsen commented Sep 18, 2017 • edited Loading

AndreasMadsen commented Sep 18, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

AndreasMadsen commented Sep 18, 2017

addaleax commented Sep 18, 2017

AndreasMadsen commented Sep 18, 2017

refack commented Sep 18, 2017

refack commented Sep 18, 2017 • edited Loading

AndreasMadsen commented Sep 19, 2017

AndreasMadsen commented Sep 19, 2017

refack commented Sep 19, 2017

jasnell commented Sep 19, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

trevnorris commented Sep 21, 2017

AndreasMadsen commented Sep 21, 2017 • edited Loading

Choose a reason for hiding this comment

refack commented Sep 21, 2017

refack commented Sep 21, 2017

AndreasMadsen commented Oct 19, 2017

AndreasMadsen commented Oct 19, 2017 • edited Loading

richardlau commented Oct 19, 2017

AndreasMadsen commented Oct 19, 2017

AndreasMadsen commented Oct 19, 2017

AndreasMadsen commented Oct 19, 2017 • edited Loading

AndreasMadsen commented Sep 18, 2017 •

edited

Loading

AndreasMadsen commented Sep 18, 2017 •

edited

Loading

AndreasMadsen commented Sep 18, 2017 •

edited

Loading

refack commented Sep 18, 2017 •

edited

Loading

AndreasMadsen commented Sep 21, 2017 •

edited

Loading

AndreasMadsen commented Oct 19, 2017 •

edited

Loading

AndreasMadsen commented Oct 19, 2017 •

edited

Loading