cli: add `--trace-atomics-wait` flag by addaleax · Pull Request #33292 · nodejs/node

addaleax · 2020-05-07T22:51:35Z

Adds a flag that helps with debugging deadlocks due to incorrectly
implemented Atomics.wait() calls.

Checklist

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

nodejs-github-bot · 2020-05-07T22:52:06Z

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

src/api/environment.cc

doc/api/cli.md

src/api/environment.cc

Adds a flag that helps with debugging deadlocks due to incorrectly implemented `Atomics.wait()` calls.

addaleax · 2020-05-08T01:56:14Z

Fwiw, I had to rewrite the test a bit because there are multiple ways in which the Atomics.wait() calls can behave depending on the order between main thread and Worker thread, @devsnek you may want to take another look

nodejs-github-bot · 2020-05-08T01:57:16Z

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

jasnell · 2020-05-08T01:21:05Z

src/node.cc

+          value,
+          timeout_in_ms,
+          message);
+}


Other places we output diagnostics to the console we typically prepend pid detail. Would be good to be consistent with that here

That would be useful when mixing multiple threads and processes so one wouldn't get [Thread 1] from multiple "thread 1"s concurrently since environment thread ids in Node always start at 0 and increase iirc. (Though the user could probably pretty easily work around that in the code)

Sure, done! 👍

nodejs-github-bot · 2020-05-09T19:14:43Z

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

targos · 2020-05-10T12:07:36Z

The test fails on SmartOS and AIX:

21:31:15 not ok 2240 parallel/test-trace-atomics-wait
21:31:15   ---
21:31:15   duration_ms: 0.945
21:31:15   severity: fail
21:31:15   exitcode: 1
21:31:15   stack: |-
21:31:15     +++ normalized stdout +++
21:31:15     [Thread 0] Atomics.wait(<address> + 0, 1, Inf) started
21:31:15     [Thread 0] Atomics.wait(<address> + 0, 1, Inf) did not wait because the values mismatched
21:31:15     [Thread 0] Atomics.wait(<address> + 0, 0, 10) started
21:31:15     [Thread 0] Atomics.wait(<address> + 0, 0, 10) timed out
21:31:15     [Thread 0] Atomics.wait(<address> + 4, 0, Inf) started
21:31:15     [Thread 1] Atomics.wait(<address> + 4, -1, Inf) started
21:31:15     [Thread 0] Atomics.wait(<address> + 4, 0, Inf) was woken up by another thread
21:31:15     [Thread 1] Atomics.wait(<address> + 4, -1, Inf) was woken up by another thread
21:31:15     --- normalized stdout ---
21:31:15     assert.js:385
21:31:15         throw err;
21:31:15         ^
21:31:15     
21:31:15     AssertionError [ERR_ASSERTION]: The expression evaluated to a falsy value:
21:31:15     
21:31:15       assert(expectedTimelines.includes(actualTimeline))
21:31:15     
21:31:15         at Object.<anonymous> (/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos18-64/test/parallel/test-trace-atomics-wait.js:79:1)
21:31:15         at Module._compile (internal/modules/cjs/loader.js:1176:30)
21:31:15         at Object.Module._extensions..js (internal/modules/cjs/loader.js:1196:10)
21:31:15         at Module.load (internal/modules/cjs/loader.js:1040:32)
21:31:15         at Function.Module._load (internal/modules/cjs/loader.js:929:14)
21:31:15         at Function.executeUserEntryPoint [as runMain] (internal/modules/run_main.js:71:12)
21:31:15         at internal/main/run_main_module.js:17:47 {
21:31:15       generatedMessage: true,
21:31:15       code: 'ERR_ASSERTION',
21:31:15       actual: false,
21:31:15       expected: true,
21:31:15       operator: '=='
21:31:15     }

addaleax · 2020-05-10T18:42:15Z

Okay, relaxed the regexp the test to account for those platforms to account for their non-standard formatting ;)

nodejs-github-bot · 2020-05-10T18:44:24Z

CI: https://ci.nodejs.org/job/node-test-pull-request/31266/ (:green_heart:)

joyeecheung

LGTM with a suggestion

joyeecheung · 2020-05-13T14:38:12Z

doc/api/cli.md

+The output could look like this:
+
+```text
+(node:15701) [Thread 0] Atomics.wait(<address> + 0, 1, inf) started


We might as well just don't print the timeout if it's infinity to match what you'd expect the call would look like

I don’t mind being explicit here.

I prefer being explicit here also. The only think I would worry about is using the abbreviation inf for Infinity. It's a minor issue, however, as folks who would typically be looking at this should be sophisticated enough in their understanding of the mechanism to know what inf means.

addaleax · 2020-05-15T17:37:54Z

Landed in c7eeef5

Adds a flag that helps with debugging deadlocks due to incorrectly implemented `Atomics.wait()` calls. PR-URL: #33292 Reviewed-By: Gus Caplan <me@gus.host> Reviewed-By: David Carlier <devnexen@gmail.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com> Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com>

Trott · 2020-05-17T03:18:56Z

Is it possible this is causing compile failures as seen in https://ci.nodejs.org/job/node-test-commit-linux-containered/nodes=ubi81_sharedlibs_openssl111fips_x64/20234/console?

09:10:33 ../src/node.cc:256:10: error: 'message' may be used uninitialized in this function [-Werror=maybe-uninitialized]
09:10:33    fprintf(stderr,
09:10:33    ~~~~~~~^~~~~~~~
09:10:33            "(node:%d) [Thread %" PRIu64 "] Atomics.wait(%p + %zx, %" PRId64
09:10:33            ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
09:10:33                ", %.f) %s\n",
09:10:33                ~~~~~~~~~~~~~~
09:10:33            static_cast<int>(uv_os_getpid()),
09:10:33            ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
09:10:33            env->thread_id(),
09:10:33            ~~~~~~~~~~~~~~~~~
09:10:33            array_buffer->GetBackingStore()->Data(),
09:10:33            ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
09:10:33            offset_in_bytes,
09:10:33            ~~~~~~~~~~~~~~~~
09:10:33            value,
09:10:33            ~~~~~~
09:10:33            timeout_in_ms,
09:10:33            ~~~~~~~~~~~~~~
09:10:33            message);
09:10:33            ~~~~~~~~
09:10:33 cc1plus: all warnings being treated as errors
09:10:33 make[2]: *** [libnode.target.mk:340: /home/iojs/build/workspace/node-test-commit-linux-containered/out/Release/obj.target/libnode/src/node.o] Error 1

jasnell · 2020-05-17T03:25:29Z

Yeah, that's the err-on-warning configure flag at work.

targos · 2020-05-17T09:04:31Z

Refs: #33392

Notable changes: async_hooks: * (SEMVER-MINOR) move PromiseHook handler to JS (Stephen Belanger) #32891 cli: * (SEMVER-MINOR) add `--trace-atomics-wait` flag (Anna Henningsen) #33292 fs: * (SEMVER-MINOR) add .ref() and .unref() methods to watcher classes (rickyes) #33134 http: * (SEMVER-MINOR) expose http.validate-header-name/value (osher) #33119 repl: * (SEMVER-MINOR) deprecate repl._builtinLibs (Ruben Bridgewater) #33294 * (SEMVER-MINOR) remove obsolete completer variable (Ruben Bridgewater) #33294 * (SEMVER-MINOR) deprecate repl.inputStream and repl.outputStream (Ruben Bridgewater) #33294 * (SEMVER-MINOR) improve repl autocompletion for require calls (Ruben Bridgewater) #33282 * (SEMVER-MINOR) replace hard coded core module list with actual list (Ruben Bridgewater) #33282 * (SEMVER-MINOR) show reference errors during preview (Ruben Bridgewater) #33282 * (SEMVER-MINOR) improve repl preview (Ruben Bridgewater) #33282 src: * add support for TLA (Gus Caplan) #30370 test: * (SEMVER-MINOR) refactor test/parallel/test-bootstrap-modules.js (Ruben Bridgewater) #33282 PR-URL: TODO

Notable changes: async_hooks: * (SEMVER-MINOR) move PromiseHook handler to JS (Stephen Belanger) #32891 cli: * (SEMVER-MINOR) add `--trace-atomics-wait` flag (Anna Henningsen) #33292 fs: * (SEMVER-MINOR) add .ref() and .unref() methods to watcher classes (rickyes) #33134 http: * (SEMVER-MINOR) expose http.validate-header-name/value (osher) #33119 repl: * (SEMVER-MINOR) deprecate repl._builtinLibs (Ruben Bridgewater) #33294 * (SEMVER-MINOR) deprecate repl.inputStream and repl.outputStream (Ruben Bridgewater) #33294 * (SEMVER-MINOR) show reference errors during preview (Ruben Bridgewater) #33282 * (SEMVER-MINOR) improve repl preview (Ruben Bridgewater) #33282 src: * add support for TLA (Gus Caplan) #30370 PR-URL: TODO

Notable changes: async_hooks: * (SEMVER-MINOR) move PromiseHook handler to JS (Stephen Belanger) #32891 cli: * (SEMVER-MINOR) add `--trace-atomics-wait` flag (Anna Henningsen) #33292 fs: * (SEMVER-MINOR) add .ref() and .unref() methods to watcher classes (rickyes) #33134 http: * (SEMVER-MINOR) expose http.validate-header-name/value (osher) #33119 repl: * (SEMVER-MINOR) deprecate repl._builtinLibs (Ruben Bridgewater) #33294 * (SEMVER-MINOR) deprecate repl.inputStream and repl.outputStream (Ruben Bridgewater) #33294 * (SEMVER-MINOR) show reference errors during preview (Ruben Bridgewater) #33282 * (SEMVER-MINOR) improve repl preview (Ruben Bridgewater) #33282 src: * add support for TLA (Gus Caplan) #30370 PR-URL: #33452

addaleax added semver-minor PRs that contain new features and should be released in the next minor version. cli Issues and PRs related to the Node.js command line interface. worker Issues and PRs related to Worker support. labels May 7, 2020

nodejs-github-bot added the c++ Issues and PRs that require attention from people who are familiar with C++. label May 7, 2020

devsnek reviewed May 7, 2020

View reviewed changes

src/api/environment.cc Outdated Show resolved Hide resolved

jasnell reviewed May 8, 2020

View reviewed changes

doc/api/cli.md Outdated Show resolved Hide resolved

jasnell reviewed May 8, 2020

View reviewed changes

src/api/environment.cc Outdated Show resolved Hide resolved

cli: add --trace-atomics-wait flag

6386c1a

Adds a flag that helps with debugging deadlocks due to incorrectly implemented `Atomics.wait()` calls.

addaleax force-pushed the atomics-wait-log branch from 269e467 to 6386c1a Compare May 8, 2020 00:37

fixup! cli: add --trace-atomics-wait flag

1ee0a80

devsnek approved these changes May 8, 2020

View reviewed changes

fixup! cli: add --trace-atomics-wait flag

f982160

fixup! cli: add --trace-atomics-wait flag

4fb193d

addaleax force-pushed the atomics-wait-log branch from 6587e7c to 4fb193d Compare May 8, 2020 01:56

devnexen approved these changes May 8, 2020

View reviewed changes

jasnell reviewed May 8, 2020

View reviewed changes

cjihrig approved these changes May 8, 2020

View reviewed changes

benjamingr approved these changes May 8, 2020

View reviewed changes

fixup! fixup! cli: add --trace-atomics-wait flag

d412f82

addaleax added the author ready PRs that have at least one approval, no pending requests for changes, and a CI started. label May 9, 2020

targos removed the author ready PRs that have at least one approval, no pending requests for changes, and a CI started. label May 10, 2020

fixup! fixup! fixup! cli: add --trace-atomics-wait flag

a32ae40

addaleax added the author ready PRs that have at least one approval, no pending requests for changes, and a CI started. label May 10, 2020

jasnell approved these changes May 11, 2020

View reviewed changes

joyeecheung approved these changes May 13, 2020

View reviewed changes

addaleax closed this May 15, 2020

addaleax deleted the atomics-wait-log branch May 15, 2020 17:38

codebytere mentioned this pull request May 18, 2020

v14.3.0 proposal #33452

Merged

addaleax added the dont-land-on-v12.x label Sep 22, 2020

Uh oh!

Conversation

addaleax commented May 7, 2020

Checklist

Uh oh!

nodejs-github-bot commented May 7, 2020

Uh oh!

Uh oh!

Uh oh!

Uh oh!

addaleax commented May 8, 2020

Uh oh!

nodejs-github-bot commented May 8, 2020

Uh oh!

jasnell May 8, 2020

Choose a reason for hiding this comment

Uh oh!

benjamingr May 8, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

addaleax May 8, 2020

Choose a reason for hiding this comment

Uh oh!

nodejs-github-bot commented May 9, 2020

Uh oh!

targos commented May 10, 2020

Uh oh!

addaleax commented May 10, 2020

Uh oh!

nodejs-github-bot commented May 10, 2020 • edited by addaleax Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

joyeecheung left a comment

Choose a reason for hiding this comment

Uh oh!

joyeecheung May 13, 2020

Choose a reason for hiding this comment

Uh oh!

addaleax May 13, 2020

Choose a reason for hiding this comment

Uh oh!

jasnell May 13, 2020

Choose a reason for hiding this comment

Uh oh!

addaleax commented May 15, 2020

Uh oh!

Trott commented May 17, 2020

Uh oh!

jasnell commented May 17, 2020

Uh oh!

targos commented May 17, 2020

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

10 participants

benjamingr May 8, 2020 •

edited

Loading

nodejs-github-bot commented May 10, 2020 •

edited by addaleax

Loading