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
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
@@ -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
@@ -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`
9 changes: 9 additions & 0 deletions doc/api/tracing.md
Original file line number Diff line number Diff line change
@@ -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
@@ -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.
.
17 changes: 16 additions & 1 deletion src/node.cc
Original file line number Diff line number Diff line change
@@ -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)
@@ -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_);
@@ -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"
@@ -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",
@@ -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) {
5 changes: 3 additions & 2 deletions src/tracing/agent.cc
Original file line number Diff line number Diff line change
@@ -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();
2 changes: 1 addition & 1 deletion src/tracing/agent.h
Original file line number Diff line number Diff line change
@@ -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();

26 changes: 21 additions & 5 deletions src/tracing/node_trace_writer.cc
Original file line number Diff line number Diff line change
@@ -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);
@@ -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);
4 changes: 3 additions & 1 deletion src/tracing/node_trace_writer.h
Original file line number Diff line number Diff line change
@@ -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;
@@ -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;
2 changes: 2 additions & 0 deletions test/parallel/test-cli-node-options.js
Original file line number Diff line number Diff line change
@@ -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');
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);
}));
}));