Skip to content

trace_events: enable trace events implicitly, add module #19233

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

Closed
wants to merge 6 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.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 8 additions & 0 deletions doc/api/errors.md
Original file line number Diff line number Diff line change
Expand Up @@ -1510,6 +1510,14 @@ socket, which is only valid from a client.

An attempt was made to renegotiate TLS on a socket instance with TLS disabled.

<a id="ERR_TRACE_EVENTS_UNAVAILABLE"></a>
### ERR_TRACE_EVENTS_UNAVAILABLE

The trace events mechanism is not available for use in the Node.js binary.
Copy link
Member

Choose a reason for hiding this comment

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

How about adding:

This is the case when Node.js was compiled with the `--without-v8-platform` flag.


This is the case when Node.js was compiled with the `--without-v8-platform`
flag.

<a id="ERR_TRANSFORM_ALREADY_TRANSFORMING"></a>
### ERR_TRANSFORM_ALREADY_TRANSFORMING

Expand Down
84 changes: 72 additions & 12 deletions doc/api/tracing.md
Original file line number Diff line number Diff line change
Expand Up @@ -5,12 +5,9 @@
Trace Event provides a mechanism to centralize tracing information generated by
Copy link
Member

Choose a reason for hiding this comment

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

It doesn't have to be in this PR, but we really need to rename this file to trace_events.md and give it a correct title :D

Copy link
Member Author

Choose a reason for hiding this comment

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

Yes, definitely :-) ... I can mark that as a todo for another PR.

V8, Node.js core, and userspace code.

Tracing can be enabled by passing the `--trace-events-enabled` flag when
starting a Node.js application.

The set of categories for which traces are recorded can be specified using the
`--trace-event-categories` flag followed by a list of comma separated category
names.
Tracing can be enabled either by using the `--trace-event-categories` flag
followed by a list of comma separated category names, or by using the
`trace_events.setTracingCategories()` method.

The available categories are:

Expand All @@ -23,28 +20,91 @@ The available categories are:
measurements.
* `v8`

By default the `node`, `node.async_hooks`, and `v8` categories are enabled.
Copy link
Member

Choose a reason for hiding this comment

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

Since --trace-events-enabled does not enable all categories we should still document this default list for that option.


```txt
node --trace-events-enabled --trace-event-categories v8,node,node.async_hooks server.js
node --trace-event-categories v8,node,node.async_hooks server.js
```

```js
const trace_events = require('trace_events');
trace_events.enableTracingCategories('v8', 'node,node.async_hooks');
```

Running Node.js with tracing enabled will produce log files that can be opened
in the [`chrome://tracing`](https://www.chromium.org/developers/how-tos/trace-event-profiling-tool)
tab of Chrome.
in the [`chrome://tracing`][] tab of Chrome.

The logging file is by default called `node_trace.${rotation}.log`, where
`${rotation}` is an incrementing log-rotation id. The filepath pattern can
be specified with `--trace-event-file-pattern` that accepts a template
string that supports `${rotation}` and `${pid}`. For example:

```txt
node --trace-events-enabled --trace-event-file-pattern '${pid}-${rotation}.log' server.js
node --trace-event-file-pattern '${pid}-${rotation}.log' server.js
```

Starting with Node.js 10.0.0, the tracing system uses the same time source
as the one used by `process.hrtime()`
however the trace-event timestamps are expressed in microseconds,
unlike `process.hrtime()` which returns nanoseconds.

Previous versions of Node.js required use of the `--trace-events-enabled`
command line flag to enable trace event capture. This flag is no longer
required to enable trace events. If it is used, however, trace events are
enabled using the default categories: `v8`, `node`, and `node.async_hooks`.

## The `trace_events` module

The `trace_events` module may be used to turn trace event reporting on and off.

It is accessible using `require('trace_events')`.

### trace_events.disableTracingCategories(...categories)

* `...categories` {string} One or more category names.

Disables trace event capture for the given set of category names.

An error will be thrown if trace event support is not enabled in the Node.js
binary.

```js
const trace_events = require('trace_events');
trace_events.disableTracingCategories('v8', 'node.async_hooks');
```

To disable all currently enabled trace event categories, the
`trace_events.getTracingCategories()` method may be used together with
`trace_events.disableTracingCategories()`:

```js
const trace_events = require('trace_events');
trace_events.disableTracingCategories(
...trace_events.getTracingCategories());
```

### trace_events.enableTracingCategories(...categories)

* `...categories` {string} One or more category names.

Enables trace event capture for the given set of category names.

An error will be thrown if trace event support is not enabled in the Node.js
binary.

```js
const trace_events = require('trace_events');
trace_events.enableTracingCategories('v8', 'node.async_hooks');
```

### trace_events.getTracingCategories()

* Returns: {string[]}

Returns an Array of the currently enabled trace event categories.

```js
const trace_events = require('trace_events');
console.log(trace_events.getTracingCategories());
```

[`chrome://tracing`]: https://www.chromium.org/developers/how-tos/trace-event-profiling-tool
[Performance API]: perf_hooks.html
1 change: 1 addition & 0 deletions lib/internal/errors.js
Original file line number Diff line number Diff line change
Expand Up @@ -866,6 +866,7 @@ E('ERR_TLS_REQUIRED_SERVER_NAME',
E('ERR_TLS_SESSION_ATTACK', 'TLS session renegotiation attack detected', Error);
E('ERR_TLS_SNI_FROM_SERVER',
'Cannot issue SNI from a TLS server-side socket', Error);
E('ERR_TRACE_EVENTS_UNAVAILABLE', 'Trace events are not available', Error);
E('ERR_TRANSFORM_ALREADY_TRANSFORMING',
'Calling transform done when still transforming', Error);

Expand Down
46 changes: 46 additions & 0 deletions lib/trace_events.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,46 @@
'use strict';

const {
enableTracingCategories: _enableTracingCategories,
disableTracingCategories: _disableTracingCategories,
getTracingCategories
} = process.binding('trace_events');

const { trace_events_enabled } = process.binding('config');

const {
codes: {
ERR_INVALID_ARG_TYPE,
ERR_TRACE_EVENTS_UNAVAILABLE
}
} = require('internal/errors');

function enableTracingCategories(...categories) {
if (!trace_events_enabled)
throw new ERR_TRACE_EVENTS_UNAVAILABLE();

for (var n = 0; n < categories.length; n++) {
if (typeof categories[n] !== 'string')
throw new ERR_INVALID_ARG_TYPE('category', 'string');
}

_enableTracingCategories(categories);
}

function disableTracingCategories(...categories) {
if (!trace_events_enabled)
throw new ERR_TRACE_EVENTS_UNAVAILABLE();

for (var n = 0; n < categories.length; n++) {
if (typeof categories[n] !== 'string')
throw new ERR_INVALID_ARG_TYPE('category', 'string');
}

_disableTracingCategories(categories);
}

module.exports = {
enableTracingCategories,
disableTracingCategories,
getTracingCategories
};
1 change: 1 addition & 0 deletions node.gyp
Original file line number Diff line number Diff line change
Expand Up @@ -73,6 +73,7 @@
'lib/tls.js',
'lib/_tls_common.js',
'lib/_tls_wrap.js',
'lib/trace_events.js',
'lib/tty.js',
'lib/url.js',
'lib/util.js',
Expand Down
94 changes: 59 additions & 35 deletions src/node.cc
Original file line number Diff line number Diff line change
Expand Up @@ -82,6 +82,7 @@

#include <string>
#include <vector>
#include <unordered_set>

#if defined(NODE_HAVE_I18N_SUPPORT)
#include <unicode/uvernum.h>
Expand Down Expand Up @@ -190,7 +191,6 @@ static node_module* modlist_builtin;
static node_module* modlist_internal;
static node_module* modlist_linked;
static node_module* modlist_addon;
static bool trace_enabled = false;
static std::string trace_enabled_categories; // NOLINT(runtime/string)
static std::string trace_file_pattern = // NOLINT(runtime/string)
"node_trace.${rotation}.log";
Expand Down Expand Up @@ -276,20 +276,11 @@ DebugOptions debug_options;
static struct {
#if NODE_USE_V8_PLATFORM
void Initialize(int thread_pool_size) {
if (trace_enabled) {
tracing_agent_.reset(new tracing::Agent(trace_file_pattern));
platform_ = new NodePlatform(thread_pool_size,
tracing_agent_->GetTracingController());
V8::InitializePlatform(platform_);
tracing::TraceEventHelper::SetTracingController(
tracing_agent_->GetTracingController());
} else {
tracing_agent_.reset(nullptr);
platform_ = new NodePlatform(thread_pool_size, nullptr);
V8::InitializePlatform(platform_);
tracing::TraceEventHelper::SetTracingController(
new v8::TracingController());
}
tracing_agent_.reset(new tracing::Agent(trace_file_pattern));
v8::TracingController* controller = tracing_agent_->GetTracingController();
platform_ = new NodePlatform(thread_pool_size, controller);
tracing::TraceEventHelper::SetTracingController(controller);
V8::InitializePlatform(platform_);
}

void Dispose() {
Expand Down Expand Up @@ -321,8 +312,24 @@ static struct {
}
#endif // HAVE_INSPECTOR

void StartTracingAgent() {
tracing_agent_->Start(trace_enabled_categories);
void EnableTracingCategories(const std::string& categories) {
tracing_agent_->EnableCategories(categories);
}

void EnableTracingCategories(const std::vector<std::string>& categories) {
tracing_agent_->EnableCategories(categories);
}

void DisableTracingCategories(const std::vector<std::string>& categories) {
tracing_agent_->DisableCategories(categories);
}

const std::unordered_set<std::string>& GetEnabledTracingCategories() {
return tracing_agent_->GetEnabledCategories();
}

void StopTracing() {
tracing_agent_->StopTracing();
}

void StopTracingAgent() {
Expand All @@ -346,15 +353,20 @@ static struct {
return true;
}

void StartTracingAgent() {
fprintf(stderr, "Node compiled with NODE_USE_V8_PLATFORM=0, "
"so event tracing is not available.\n");
void EnableTracingCategories(const std::string& categories) {}
void EnableTracingCategories(const std::vector<std::string> categories) {}
void DisableTracingCategories(const std::vector<std::string> categories) {}
const std::unordered_set<std::string>& GetEnabledTracingCategories() {
return categories_;
}
void StopTracing() {}
void StopTracingAgent() {}

NodePlatform* Platform() {
return nullptr;
}

std::unordered_set<std::string> categories_;
#endif // !NODE_USE_V8_PLATFORM

#if !NODE_USE_V8_PLATFORM || !HAVE_INSPECTOR
Expand All @@ -364,6 +376,20 @@ static struct {
#endif // !NODE_USE_V8_PLATFORM || !HAVE_INSPECTOR
} v8_platform;

void EnableTracingCategories(const std::vector<std::string>& categories) {
v8_platform.EnableTracingCategories(categories);
}

void DisableTracingCategories(const std::vector<std::string>& categories) {
v8_platform.DisableTracingCategories(categories);
}

const std::unordered_set<std::string>& GetEnabledTracingCategories() {
return v8_platform.GetEnabledTracingCategories();
}

void StopTracing() { v8_platform.StopTracing(); }

#ifdef __POSIX__
static const unsigned kMaxSignal = 32;
#endif
Expand Down Expand Up @@ -1987,9 +2013,7 @@ static void WaitForInspectorDisconnect(Environment* env) {

static void Exit(const FunctionCallbackInfo<Value>& args) {
WaitForInspectorDisconnect(Environment::GetCurrent(args));
if (trace_enabled) {
v8_platform.StopTracingAgent();
}
v8_platform.StopTracingAgent();
exit(args[0]->Int32Value());
}

Expand Down Expand Up @@ -3287,9 +3311,7 @@ void SetupProcessObject(Environment* env,

void SignalExit(int signo) {
uv_tty_reset_mode();
if (trace_enabled) {
v8_platform.StopTracingAgent();
}
v8_platform.StopTracingAgent();
#ifdef __FreeBSD__
// FreeBSD has a nasty bug, see RegisterSignalHandler for details
struct sigaction sa;
Expand Down Expand Up @@ -3491,13 +3513,15 @@ static void PrintHelp() {
" is detected after the first tick\n"
" --no-force-async-hooks-checks\n"
" disable checks for async_hooks\n"
#if NODE_USE_V8_PLATFORM
" --trace-events-enabled track trace events\n"
" --trace-event-categories comma separated list of trace event\n"
" categories to record\n"
" --trace-event-file-pattern Template string specifying the\n"
" filepath for the trace-events data, it\n"
" supports ${rotation} and ${pid}\n"
" log-rotation id. %%2$u is the pid.\n"
#endif
" --track-heap-objects track heap object allocations for heap "
"snapshots\n"
" --prof-process process v8 profiler output generated\n"
Expand Down Expand Up @@ -3624,9 +3648,11 @@ static void CheckIfAllowedInEnv(const char* exe, bool is_env,
"--redirect-warnings",
"--trace-sync-io",
"--no-force-async-hooks-checks",
#if NODE_USE_V8_PLATFORM
"--trace-events-enabled",
"--trace-event-categories",
"--trace-event-file-pattern",
#endif
"--track-heap-objects",
"--zero-fill-buffers",
"--v8-pool-size",
Expand Down Expand Up @@ -3768,8 +3794,11 @@ static void ParseArgs(int* argc,
trace_sync_io = true;
} else if (strcmp(arg, "--no-force-async-hooks-checks") == 0) {
no_force_async_hooks_checks = true;
#if NODE_USE_V8_PLATFORM
} else if (strcmp(arg, "--trace-events-enabled") == 0) {
trace_enabled = true;
if (trace_enabled_categories.empty()) {
trace_enabled_categories = "v8,node,node.async_hooks";
}
} else if (strcmp(arg, "--trace-event-categories") == 0) {
const char* categories = argv[index + 1];
if (categories == nullptr) {
Expand All @@ -3786,6 +3815,7 @@ static void ParseArgs(int* argc,
}
args_consumed += 1;
trace_file_pattern = file_pattern;
#endif
} else if (strcmp(arg, "--track-heap-objects") == 0) {
track_heap_objects = true;
} else if (strcmp(arg, "--throw-deprecation") == 0) {
Expand Down Expand Up @@ -4595,19 +4625,13 @@ int Start(int argc, char** argv) {

v8_platform.Initialize(v8_thread_pool_size);
// Enable tracing when argv has --trace-events-enabled.
if (trace_enabled) {
fprintf(stderr, "Warning: Trace event is an experimental feature "
"and could change at any time.\n");
v8_platform.StartTracingAgent();
}
v8_platform.EnableTracingCategories(trace_enabled_categories);
V8::Initialize();
performance::performance_v8_start = PERFORMANCE_NOW();
v8_initialized = true;
const int exit_code =
Start(uv_default_loop(), argc, argv, exec_argc, exec_argv);
if (trace_enabled) {
v8_platform.StopTracingAgent();
}
v8_platform.StopTracingAgent();
v8_initialized = false;
V8::Dispose();

Expand Down
Loading