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

trace_events: add file pattern cli option #18480

Closed
wants to merge 2 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
9 changes: 9 additions & 0 deletions doc/api/cli.md
Original file line number Diff line number Diff line change
Expand Up @@ -235,6 +235,14 @@ added: v7.7.0
A comma separated list of categories that should be traced when trace event
tracing is enabled using `--trace-events-enabled`.

### `--trace-event-file-pattern`
<!-- YAML
added: REPLACEME
-->

Template string specifying the filepath for the trace event data, it
supports `${rotation}` and `${pid}`.

### `--zero-fill-buffers`
<!-- YAML
added: v6.0.0
Expand Down Expand Up @@ -464,6 +472,7 @@ Node options that are allowed are:
- `--trace-deprecation`
- `--trace-events-categories`
- `--trace-events-enabled`
- `--trace-event-file-pattern`
- `--trace-sync-io`
- `--trace-warnings`
- `--track-heap-objects`
Expand Down
9 changes: 9 additions & 0 deletions doc/api/tracing.md
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,15 @@ 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.

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

Starting with Node 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.
4 changes: 4 additions & 0 deletions doc/node.1
Original file line number Diff line number Diff line change
Expand Up @@ -156,6 +156,10 @@ Enable the collection of trace event tracing information.
A comma-separated list of categories that should be traced when trace event tracing is enabled using
.Fl -trace-events-enabled .
.
.It Fl -trace-event-file-pattern Ar pattern
Template string specifying the filepath for the trace event data, it
supports \fB${rotation}\fR and \fB${pid}\fR.
.
.It Fl -zero-fill-buffers
Automatically zero-fills all newly allocated Buffer and SlowBuffer instances.
.
Expand Down
17 changes: 16 additions & 1 deletion src/node.cc
Original file line number Diff line number Diff line change
Expand Up @@ -196,6 +196,8 @@ 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";
static bool abort_on_uncaught_exception = false;

// Bit flag used to track security reverts (see node_revert.h)
Expand Down Expand Up @@ -279,7 +281,7 @@ static struct {
#if NODE_USE_V8_PLATFORM
void Initialize(int thread_pool_size) {
if (trace_enabled) {
tracing_agent_.reset(new tracing::Agent());
tracing_agent_.reset(new tracing::Agent(trace_file_pattern));
platform_ = new NodePlatform(thread_pool_size,
tracing_agent_->GetTracingController());
V8::InitializePlatform(platform_);
Expand Down Expand Up @@ -3397,6 +3399,10 @@ static void PrintHelp() {
" --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"
" --track-heap-objects track heap object allocations for heap "
"snapshots\n"
" --prof-process process v8 profiler output generated\n"
Expand Down Expand Up @@ -3525,6 +3531,7 @@ static void CheckIfAllowedInEnv(const char* exe, bool is_env,
"--no-force-async-hooks-checks",
"--trace-events-enabled",
"--trace-event-categories",
"--trace-event-file-pattern",
Copy link
Member

Choose a reason for hiding this comment

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

Please could you also update the list of whitelisted options in the NODE_OPTIONS section of the CLI documentation?

"--track-heap-objects",
"--zero-fill-buffers",
"--v8-pool-size",
Expand Down Expand Up @@ -3676,6 +3683,14 @@ static void ParseArgs(int* argc,
}
args_consumed += 1;
trace_enabled_categories = categories;
} else if (strcmp(arg, "--trace-event-file-pattern") == 0) {
const char* file_pattern = argv[index + 1];
if (file_pattern == nullptr) {
fprintf(stderr, "%s: %s requires an argument\n", argv[0], arg);
exit(9);
}
args_consumed += 1;
trace_file_pattern = file_pattern;
} else if (strcmp(arg, "--track-heap-objects") == 0) {
track_heap_objects = true;
} else if (strcmp(arg, "--throw-deprecation") == 0) {
Expand Down
5 changes: 3 additions & 2 deletions src/tracing/agent.cc
Original file line number Diff line number Diff line change
Expand Up @@ -13,11 +13,12 @@ namespace tracing {
using v8::platform::tracing::TraceConfig;
using std::string;

Agent::Agent() {
Agent::Agent(const std::string& log_file_pattern) {
int err = uv_loop_init(&tracing_loop_);
CHECK_EQ(err, 0);

NodeTraceWriter* trace_writer = new NodeTraceWriter(&tracing_loop_);
NodeTraceWriter* trace_writer = new NodeTraceWriter(
log_file_pattern, &tracing_loop_);
TraceBuffer* trace_buffer = new NodeTraceBuffer(
NodeTraceBuffer::kBufferChunks, trace_writer, &tracing_loop_);
tracing_controller_ = new TracingController();
Expand Down
2 changes: 1 addition & 1 deletion src/tracing/agent.h
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,7 @@ class TracingController : public v8::platform::tracing::TracingController {

class Agent {
public:
Agent();
explicit Agent(const std::string& log_file_pattern);
void Start(const std::string& enabled_categories);
void Stop();

Expand Down
26 changes: 21 additions & 5 deletions src/tracing/node_trace_writer.cc
Original file line number Diff line number Diff line change
Expand Up @@ -8,8 +8,9 @@
namespace node {
namespace tracing {

NodeTraceWriter::NodeTraceWriter(uv_loop_t* tracing_loop)
: tracing_loop_(tracing_loop) {
NodeTraceWriter::NodeTraceWriter(const std::string& log_file_pattern,
uv_loop_t* tracing_loop)
: tracing_loop_(tracing_loop), log_file_pattern_(log_file_pattern) {
flush_signal_.data = this;
int err = uv_async_init(tracing_loop_, &flush_signal_, FlushSignalCb);
CHECK_EQ(err, 0);
Expand Down Expand Up @@ -54,12 +55,27 @@ NodeTraceWriter::~NodeTraceWriter() {
}
}

void replace_substring(std::string* target,
const std::string& search,
const std::string& insert) {
size_t pos = target->find(search);
for (; pos != std::string::npos; pos = target->find(search, pos)) {
target->replace(pos, search.size(), insert);
pos += insert.size();
}
}

void NodeTraceWriter::OpenNewFileForStreaming() {
++file_num_;
uv_fs_t req;
std::ostringstream log_file;
log_file << "node_trace." << file_num_ << ".log";
fd_ = uv_fs_open(tracing_loop_, &req, log_file.str().c_str(),

// Evaluate a JS-style template string, it accepts the values ${pid} and
// ${rotation}
std::string filepath(log_file_pattern_);
replace_substring(&filepath, "${pid}", std::to_string(uv_os_getpid()));
replace_substring(&filepath, "${rotation}", std::to_string(file_num_));

fd_ = uv_fs_open(tracing_loop_, &req, filepath.c_str(),
O_CREAT | O_WRONLY | O_TRUNC, 0644, nullptr);
CHECK_NE(fd_, -1);
uv_fs_req_cleanup(&req);
Expand Down
4 changes: 3 additions & 1 deletion src/tracing/node_trace_writer.h
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,8 @@ using v8::platform::tracing::TraceWriter;

class NodeTraceWriter : public TraceWriter {
public:
explicit NodeTraceWriter(uv_loop_t* tracing_loop);
explicit NodeTraceWriter(const std::string& log_file_pattern,
uv_loop_t* tracing_loop);
~NodeTraceWriter();

void AppendTraceEvent(TraceObject* trace_event) override;
Expand Down Expand Up @@ -62,6 +63,7 @@ class NodeTraceWriter : public TraceWriter {
int highest_request_id_completed_ = 0;
int total_traces_ = 0;
int file_num_ = 0;
const std::string& log_file_pattern_;
std::ostringstream stream_;
TraceWriter* json_trace_writer_ = nullptr;
bool exited_ = false;
Expand Down
2 changes: 2 additions & 0 deletions test/parallel/test-cli-node-options.js
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,8 @@ expect('--throw-deprecation', 'B\n');
expect('--zero-fill-buffers', 'B\n');
expect('--v8-pool-size=10', 'B\n');
expect('--trace-event-categories node', 'B\n');
// eslint-disable-next-line no-template-curly-in-string
expect('--trace-event-file-pattern {pid}-${rotation}.trace_events', 'B\n');

if (!common.isWindows) {
expect('--perf-basic-prof', 'B\n');
Expand Down
30 changes: 30 additions & 0 deletions test/parallel/test-trace-events-file-pattern.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,30 @@
'use strict';
const common = require('../common');
const tmpdir = require('../common/tmpdir');
const assert = require('assert');
const cp = require('child_process');
const fs = require('fs');

tmpdir.refresh();
process.chdir(tmpdir.path);

const CODE =
'setTimeout(() => { for (var i = 0; i < 100000; i++) { "test" + i } }, 1)';

const proc = cp.spawn(process.execPath, [
'--trace-events-enabled',
'--trace-event-file-pattern',
// eslint-disable-next-line no-template-curly-in-string
'${pid}-${rotation}-${pid}-${rotation}.tracing.log',
'-e', CODE
]);

proc.once('exit', common.mustCall(() => {
const expectedFilename = `${proc.pid}-1-${proc.pid}-1.tracing.log`;

assert(common.fileExists(expectedFilename));
fs.readFile(expectedFilename, common.mustCall((err, data) => {
const traces = JSON.parse(data.toString()).traceEvents;
assert(traces.length > 0);
}));
}));