Skip to content

Commit

Permalink
trace_events: adds a new trace_events api
Browse files Browse the repository at this point in the history
Removes the requirement to use `--trace-events-enabled` to enable
trace events. Tracing is enabled automatically if there are any
enabled categories.

Adds a new `trace_events` module with an API for enabling/disabling
trace events at runtime without a command line flag.

```js
const trace_events = require('trace_events');
const categories = [ 'node.perf', 'node.async_hooks' ];
const tracing = trace_events.createTracing({ categories });
tracing.enable();
// do stuff
tracing.disable();
```

Multiple `Tracing` objects may exist and be enabled at any point
in time. The enabled trace event categories is the union of all
enabled `Tracing` objects and the `--trace-event-categories`
flag.

PR-URL: #19803
Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
Reviewed-By: Ali Ijaz Sheikh <ofrobots@google.com>
Reviewed-By: Franziska Hinkelmann <franziska.hinkelmann@gmail.com>
  • Loading branch information
jasnell committed Apr 17, 2018
1 parent 54a2e93 commit da5d818
Show file tree
Hide file tree
Showing 25 changed files with 677 additions and 87 deletions.
2 changes: 1 addition & 1 deletion doc/api/_toc.md
Original file line number Diff line number Diff line change
Expand Up @@ -46,7 +46,7 @@
* [String Decoder](string_decoder.html)
* [Timers](timers.html)
* [TLS/SSL](tls.html)
* [Tracing](tracing.html)
* [Trace Events](tracing.html)
* [TTY](tty.html)
* [UDP/Datagram](dgram.html)
* [URL](url.html)
Expand Down
12 changes: 12 additions & 0 deletions doc/api/errors.md
Original file line number Diff line number Diff line change
Expand Up @@ -1550,6 +1550,18 @@ 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_CATEGORY_REQUIRED"></a>
### ERR_TRACE_EVENTS_CATEGORY_REQUIRED

The `trace_events.createTracing()` method requires at least one trace event
category.

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

The `trace_events` module could not be loaded because Node.js was compiled with
the `--without-v8-platform` flag.

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

Expand Down
162 changes: 153 additions & 9 deletions doc/api/tracing.md
Original file line number Diff line number Diff line change
@@ -1,16 +1,15 @@
# Tracing
# Trace Events

<!--introduced_in=v7.7.0-->

> Stability: 1 - Experimental
Trace Event provides a mechanism to centralize tracing information generated by
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 with the `--trace-event-categories` command-line flag
or by using the trace_events module. The `--trace-event-categories` flag accepts
a list of comma-separated category names.

The available categories are:

Expand All @@ -27,7 +26,32 @@ The available categories are:
By default the `node`, `node.async_hooks`, and `v8` categories are enabled.

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

Prior versions of Node.js required the use of the `--trace-events-enabled`
flag to enable trace events. This requirement has been removed. However, the
`--trace-events-enabled` flag *may* still be used and will enable the
`node`, `node.async_hooks`, and `v8` trace event categories by default.

```txt
node --trace-events-enabled
// is equivalent to
node --trace-event-categories v8,node,node.async_hooks
```

Alternatively, trace events may be enabled using the `trace_events` module:

```js
const trace_events = require('trace_events');
const tracing = trace_events.createTracing({ categories: ['node.perf'] });
tracing.enable(); // Enable trace event capture for the 'node.perf' category

// do work

tracing.disable(); // Disable trace event capture for the 'node.perf' category
```

Running Node.js with tracing enabled will produce log files that can be opened
Expand All @@ -40,12 +64,132 @@ 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-categories v8 --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.

## The `trace_events` module
<!-- YAML
added: REPLACEME
-->

### `Tracing` object
<!-- YAML
added: REPLACEME
-->

The `Tracing` object is used to enable or disable tracing for sets of
categories. Instances are created using the `trace_events.createTracing()`
method.

When created, the `Tracing` object is disabled. Calling the
`tracing.enable()` method adds the categories to the set of enabled trace event
categories. Calling `tracing.disable()` will remove the categories from the
set of enabled trace event categories.

#### `tracing.categories`
<!-- YAML
added: REPLACEME
-->

* {string}

A comma-separated list of the trace event categories covered by this
`Tracing` object.

#### `tracing.disable()`
<!-- YAML
added: REPLACEME
-->

Disables this `Tracing` object.

Only trace event categories *not* covered by other enabled `Tracing` objects
and *not* specified by the `--trace-event-categories` flag will be disabled.

```js
const trace_events = require('trace_events');
const t1 = trace_events.createTracing({ categories: ['node', 'v8'] });
const t2 = trace_events.createTracing({ categories: ['node.perf', 'node'] });
t1.enable();
t2.enable();

// Prints 'node,node.perf,v8'
console.log(trace_events.getEnabledCategories());

t2.disable(); // will only disable emission of the 'node.perf' category

// Prints 'node,v8'
console.log(trace_events.getEnabledCategories());
```

#### `tracing.enable()`
<!-- YAML
added: REPLACEME
-->

Enables this `Tracing` object for the set of categories covered by the
`Tracing` object.

#### `tracing.enabled`
<!-- YAML
added: REPLACEME
-->

* {boolean} `true` only if the `Tracing` object has been enabled.

### `trace_events.createTracing(options)`
<!-- YAML
added: REPLACEME
-->

* `options` {Object}
* `categories` {string[]} An array of trace category names. Values included
in the array are coerced to a string when possible. An error will be
thrown if the value cannot be coerced.
* Returns: {Tracing}.

Creates and returns a `Tracing` object for the given set of `categories`.

```js
const trace_events = require('trace_events');
const categories = ['node.perf', 'node.async_hooks'];
const tracing = trace_events.createTracing({ categories });
tracing.enable();
// do stuff
tracing.disable();
```

### `trace_events.getEnabledCategories()`
<!-- YAML
added: REPLACEME
-->

* Returns: {string}

Returns a comma-separated list of all currently-enabled trace event
categories. The current set of enabled trace event categories is determined
by the *union* of all currently-enabled `Tracing` objects and any categories
enabled using the `--trace-event-categories` flag.

Given the file `test.js` below, the command
`node --trace-event-categories node.perf test.js` will print
`'node.async_hooks,node.perf'` to the console.

```js
const trace_events = require('trace_events');
const t1 = trace_events.createTracing({ categories: ['node.async_hooks'] });
const t2 = trace_events.createTracing({ categories: ['node.perf'] });
const t3 = trace_events.createTracing({ categories: ['v8'] });

t1.enable();
t2.enable();

console.log(trace_events.getEnabledCategories());
```

[Performance API]: perf_hooks.html
3 changes: 3 additions & 0 deletions lib/internal/errors.js
Original file line number Diff line number Diff line change
Expand Up @@ -984,6 +984,9 @@ 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_CATEGORY_REQUIRED',
'At least one category is required', TypeError);
E('ERR_TRACE_EVENTS_UNAVAILABLE', 'Trace events are unavailable', Error);
E('ERR_TRANSFORM_ALREADY_TRANSFORMING',
'Calling transform done when still transforming', Error);

Expand Down
3 changes: 2 additions & 1 deletion lib/internal/modules/cjs/helpers.js
Original file line number Diff line number Diff line change
Expand Up @@ -101,7 +101,8 @@ const builtinLibs = [
'assert', 'async_hooks', 'buffer', 'child_process', 'cluster', 'crypto',
'dgram', 'dns', 'domain', 'events', 'fs', 'http', 'http2', 'https', 'net',
'os', 'path', 'perf_hooks', 'punycode', 'querystring', 'readline', 'repl',
'stream', 'string_decoder', 'tls', 'tty', 'url', 'util', 'v8', 'vm', 'zlib'
'stream', 'string_decoder', 'tls', 'trace_events', 'tty', 'url', 'util',
'v8', 'vm', 'zlib'
];

if (typeof process.binding('inspector').open === 'function') {
Expand Down
89 changes: 89 additions & 0 deletions lib/trace_events.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,89 @@
'use strict';

const { hasTracing } = process.binding('config');
const kHandle = Symbol('handle');
const kEnabled = Symbol('enabled');
const kCategories = Symbol('categories');

const kMaxTracingCount = 10;

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

if (!hasTracing)
throw new ERR_TRACE_EVENTS_UNAVAILABLE();

const { CategorySet, getEnabledCategories } = process.binding('trace_events');
const { customInspectSymbol } = require('internal/util');
const { format } = require('util');

const enabledTracingObjects = new Set();

class Tracing {
constructor(categories) {
this[kHandle] = new CategorySet(categories);
this[kCategories] = categories;
this[kEnabled] = false;
}

enable() {
if (!this[kEnabled]) {
this[kEnabled] = true;
this[kHandle].enable();
enabledTracingObjects.add(this);
if (enabledTracingObjects.size > kMaxTracingCount) {
process.emitWarning(
'Possible trace_events memory leak detected. There are more than ' +
`${kMaxTracingCount} enabled Tracing objects.`
);
}
}
}

disable() {
if (this[kEnabled]) {
this[kEnabled] = false;
this[kHandle].disable();
enabledTracingObjects.delete(this);
}
}

get enabled() {
return this[kEnabled];
}

get categories() {
return this[kCategories].join(',');
}

[customInspectSymbol](depth, opts) {
const obj = {
enabled: this.enabled,
categories: this.categories
};
return `Tracing ${format(obj)}`;
}
}

function createTracing(options) {
if (typeof options !== 'object' || options == null)
throw new ERR_INVALID_ARG_TYPE('options', 'object', options);

if (!Array.isArray(options.categories)) {
throw new ERR_INVALID_ARG_TYPE('options.categories', 'string[]',
options.categories);
}

if (options.categories.length <= 0)
throw new ERR_TRACE_EVENTS_CATEGORY_REQUIRED();

return new Tracing(options.categories);
}

module.exports = {
createTracing,
getEnabledCategories
};
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
5 changes: 5 additions & 0 deletions src/env-inl.h
Original file line number Diff line number Diff line change
Expand Up @@ -32,6 +32,7 @@
#include "v8.h"
#include "node_perf_common.h"
#include "node_context_data.h"
#include "tracing/agent.h"

#include <stddef.h>
#include <stdint.h>
Expand Down Expand Up @@ -325,6 +326,10 @@ inline v8::Isolate* Environment::isolate() const {
return isolate_;
}

inline tracing::Agent* Environment::tracing_agent() const {
return tracing_agent_;
}

inline Environment* Environment::from_immediate_check_handle(
uv_check_t* handle) {
return ContainerOf(&Environment::immediate_check_handle_, handle);
Expand Down
5 changes: 4 additions & 1 deletion src/env.cc
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@
#include "node_buffer.h"
#include "node_platform.h"
#include "node_file.h"
#include "tracing/agent.h"

#include <stdio.h>
#include <algorithm>
Expand Down Expand Up @@ -87,9 +88,11 @@ void InitThreadLocalOnce() {
}

Environment::Environment(IsolateData* isolate_data,
Local<Context> context)
Local<Context> context,
tracing::Agent* tracing_agent)
: isolate_(context->GetIsolate()),
isolate_data_(isolate_data),
tracing_agent_(tracing_agent),
immediate_info_(context->GetIsolate()),
tick_info_(context->GetIsolate()),
timer_base_(uv_now(isolate_data->event_loop())),
Expand Down

0 comments on commit da5d818

Please sign in to comment.