-
-
Notifications
You must be signed in to change notification settings - Fork 31.9k
trace_events: adds a new trace_events api #19803
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
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
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: | ||
|
||
|
@@ -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 | ||
|
@@ -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. | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I'm not truly fond of returning a comma-separated list of things. Can we return an Array? Do we expect this API to be sitting in hot paths where doing that would be too expensive? There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. The main reason I went with the comma separated list is that it uses the same format at that accepted by the |
||
|
||
#### `tracing.disable()` | ||
<!-- YAML | ||
added: REPLACEME | ||
--> | ||
|
||
Disables this `Tracing` object. | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Do we also want to mention somewhere that the traced categories will get disabled if the There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Likely a good idea. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I don't really like that the categories are disabled if the trace_events.createTracing({ categories: ['node.http'] }).enable(); without ever disabling it again. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. In that case, however, it would be trivial to put this call into a context where it is never garbage collected, then you'd accomplish the same goal. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
I'm not really buying that as a good argument. You could say that about a lot of APIs we have. As a general rule, I don't think garbage collection should have side-effects. Could we turn this discussion around, where you argue why it should have this side effect? There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I do think letting users lose a reference to I agree that this matches the behavior of async_hooks.
I keep disagreeing with this approach, however let's land this and iterate separately, as it would need to be changed in async_hooks as well.
I find it as bad as allocating resources that could not be collected in the future. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
Another possible approach on this is to encourage folks to proactively disable the handles rather than wait for gc the same way we do with the new There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
What do we mean by Other examples:
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. For For the other examples: |
||
|
||
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 |
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 | ||
}; |
Uh oh!
There was an error while loading. Please reload this page.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Not a feedback on this PR, but I don't think
node.async_hooks
are good candidates for the default set of events to enable. They are a bit too low level. Higher level tracing of at the APIs level would be a lot more useful to most users. Sincetrace_events
is experimental, I expect we should be able to change this in the future.There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think it is for backward compatibility, ultimately I think
--trace-events-enabled
should be removed. A default set oftrace_events
doesn't really make sense to me.There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Yes, it's for backwards compatibility only. Once this lands I plan to open a PR deprecating
--trace-events-enabled
and removing it from thenode --help
output. It will still be there for legacy support and can eventually be removed.There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
sgtm