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

cli: add --trace-exit cli option #30516

Closed
wants to merge 3 commits into from
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
9 changes: 9 additions & 0 deletions doc/api/cli.md
Expand Up @@ -774,6 +774,14 @@ added: v7.7.0

Enables the collection of trace event tracing information.

### `--trace-exit`
<!-- YAML
added: REPLACEME
legendecas marked this conversation as resolved.
Show resolved Hide resolved
-->

Prints a stack trace whenever an environment is exited proactively,
i.e. invoking `process.exit()`.

### `--trace-sync-io`
<!-- YAML
added: v2.1.0
Expand Down Expand Up @@ -1101,6 +1109,7 @@ Node.js options that are allowed are:
* `--trace-event-categories`
* `--trace-event-file-pattern`
* `--trace-events-enabled`
* `--trace-exit`
* `--trace-sync-io`
* `--trace-tls`
* `--trace-uncaught`
Expand Down
4 changes: 4 additions & 0 deletions doc/node.1
Expand Up @@ -349,6 +349,10 @@ and
.It Fl -trace-events-enabled
Enable the collection of trace event tracing information.
.
.It Fl -trace-exit
Prints a stack trace whenever an environment is exited proactively,
i.e. invoking `process.exit()`.
.
.It Fl -trace-sync-io
Print a stack trace whenever synchronous I/O is detected after the first turn of the event loop.
.
Expand Down
15 changes: 15 additions & 0 deletions src/env.cc
Expand Up @@ -940,6 +940,21 @@ void AsyncHooks::grow_async_ids_stack() {
uv_key_t Environment::thread_local_env = {};

void Environment::Exit(int exit_code) {
if (options()->trace_exit) {
HandleScope handle_scope(isolate());

if (is_main_thread()) {
fprintf(stderr, "(node:%d) ", uv_os_getpid());
} else {
fprintf(stderr, "(node:%d, thread:%llu) ", uv_os_getpid(), thread_id());
}
Copy link
Contributor

Choose a reason for hiding this comment

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

Ditto, are this function called always from exceptions?


fprintf(
stderr, "WARNING: Exited the environment with code %d\n", exit_code);
Copy link
Contributor

Choose a reason for hiding this comment

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

Why do we mark this as a warning and pipe to stderr?

Copy link
Member Author

Choose a reason for hiding this comment

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

Other traces were printed as warnings and piped to stderr. Do you have any suggestions on the format of the traces?

Copy link
Contributor

Choose a reason for hiding this comment

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

Feel free to resolve this by yourself, I'm okay if this is a default behavior :)

PrintStackTrace(
isolate(),
StackTrace::CurrentStackTrace(isolate(), 10, StackTrace::kDetailed));
legendecas marked this conversation as resolved.
Show resolved Hide resolved
yorkie marked this conversation as resolved.
Show resolved Hide resolved
}
if (is_main_thread()) {
stop_sub_worker_contexts();
DisposePlatform();
Expand Down
4 changes: 4 additions & 0 deletions src/node_options.cc
Expand Up @@ -476,6 +476,10 @@ EnvironmentOptionsParser::EnvironmentOptionsParser() {
"show stack traces on deprecations",
&EnvironmentOptions::trace_deprecation,
kAllowedInEnvironment);
AddOption("--trace-exit",
"show stack trace when an environment exits",
&EnvironmentOptions::trace_exit,
kAllowedInEnvironment);
AddOption("--trace-sync-io",
"show stack trace when use of sync IO is detected after the "
"first tick",
Expand Down
1 change: 1 addition & 0 deletions src/node_options.h
Expand Up @@ -141,6 +141,7 @@ class EnvironmentOptions : public Options {
bool test_udp_no_try_send = false;
bool throw_deprecation = false;
bool trace_deprecation = false;
bool trace_exit = false;
bool trace_sync_io = false;
bool trace_tls = false;
bool trace_uncaught = false;
Expand Down
59 changes: 59 additions & 0 deletions test/parallel/test-trace-exit.js
@@ -0,0 +1,59 @@
'use strict';
const common = require('../common');
const assert = require('assert');
const { promisify } = require('util');
const execFile = promisify(require('child_process').execFile);
const { Worker, isMainThread, workerData } = require('worker_threads');

const variant = process.argv[process.argv.length - 1];
switch (true) {
case variant === 'main-thread': {
return;
}
case variant === 'main-thread-exit': {
return process.exit(0);
}
case variant.startsWith('worker-thread'): {
const worker = new Worker(__filename, { workerData: variant });
worker.on('error', common.mustNotCall());
worker.on('exit', common.mustCall((code) => {
assert.strictEqual(code, 0);
}));
return;
}
case !isMainThread: {
if (workerData === 'worker-thread-exit') {
process.exit(0);
}
return;
}
}

(async function() {
for (const { execArgv, variant, warnings } of [
{ execArgv: ['--trace-exit'], variant: 'main-thread-exit', warnings: 1 },
{ execArgv: [], variant: 'main-thread-exit', warnings: 0 },
{ execArgv: ['--trace-exit'], variant: 'main-thread', warnings: 0 },
{ execArgv: [], variant: 'main-thread', warnings: 0 },
{ execArgv: ['--trace-exit'], variant: 'worker-thread-exit', warnings: 1 },
{ execArgv: [], variant: 'worker-thread-exit', warnings: 0 },
{ execArgv: ['--trace-exit'], variant: 'worker-thread', warnings: 0 },
{ execArgv: [], variant: 'worker-thread', warnings: 0 },
]) {
const { stdout, stderr } =
await execFile(process.execPath, [...execArgv, __filename, variant]);
assert.strictEqual(stdout, '');
const actualWarnings =
stderr.match(/WARNING: Exited the environment with code 0/g);
if (warnings === 0) {
assert.strictEqual(actualWarnings, null);
return;

Choose a reason for hiding this comment

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

This return; terminates the whole async function i.e. terminates the enclosing for cycle after the second iteration (i.e. the first iteration with warnings === 0). I assume that continue; should have been here instead.

Copy link
Contributor

Choose a reason for hiding this comment

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

Thank you for identifying this. Would you mind opening an issue for it (preferably with a snippet showing the bug if you have one)? It will get more attention as an issue that a comment here.

}
assert.strictEqual(actualWarnings.length, warnings);

if (variant.startsWith('worker')) {
const workerIds = stderr.match(/\(node:\d+, thread:\d+)/g);

Choose a reason for hiding this comment

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

This regular expression in invalid. It contains an unmatched ) i.e. ) at the end should be \). This was not noticed because there is a lazy syntax check of regular expressions in V8 and this statement is never reached because of the incorrect return; mentioned above.

Copy link
Member Author

Choose a reason for hiding this comment

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

Thanks for reporting this! I've submitted a fix for this #33769.

assert.strictEqual(workerIds.length, warnings);
}
}
})().then(common.mustCall());