Skip to content

Commit

Permalink
trace_events: add file pattern cli option
Browse files Browse the repository at this point in the history
Allow the user to specify the filepath for the trace_events log file
using a template string.

Backport-PR-URL: #19145
PR-URL: #18480
Reviewed-By: Ali Ijaz Sheikh <ofrobots@google.com>
Reviewed-By: Richard Lau <riclau@uk.ibm.com>
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Ruben Bridgewater <ruben@bridgewater.de>
  • Loading branch information
AndreasMadsen authored and rvagg committed Aug 16, 2018
1 parent 7cf26e5 commit e602726
Show file tree
Hide file tree
Showing 10 changed files with 103 additions and 10 deletions.
9 changes: 9 additions & 0 deletions doc/api/cli.md
Original file line number Diff line number Diff line change
Expand Up @@ -238,6 +238,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 @@ -474,6 +482,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
13 changes: 13 additions & 0 deletions doc/api/tracing.md
Original file line number Diff line number Diff line change
Expand Up @@ -19,3 +19,16 @@ node --trace-events-enabled --trace-event-categories v8,node,node.async_hooks se
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.
5 changes: 5 additions & 0 deletions doc/node.1
Original file line number Diff line number Diff line change
Expand Up @@ -166,6 +166,11 @@ Enables the collection of trace event tracing information.
A comma separated list of categories that should be traced when trace event
tracing is enabled using \fB--trace-events-enabled\fR.

.TP
.BR \-\-trace-event\-file\-pattern " " \fIpattern\fR
Template string specifying the filepath for the trace event data, it
supports \fB${rotation}\fR and \fB${pid}\fR.

.TP
.BR \-\-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 @@ -192,6 +192,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 @@ -273,7 +275,7 @@ static struct {
#if NODE_USE_V8_PLATFORM
void Initialize(int thread_pool_size, uv_loop_t* loop) {
if (trace_enabled) {
tracing_agent_.reset(new tracing::Agent());
tracing_agent_.reset(new tracing::Agent(trace_file_pattern));
platform_ = new NodePlatform(thread_pool_size, loop,
tracing_agent_->GetTracingController());
V8::InitializePlatform(platform_);
Expand Down Expand Up @@ -3853,6 +3855,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 @@ -3979,6 +3985,7 @@ static void CheckIfAllowedInEnv(const char* exe, bool is_env,
"--force-async-hooks-checks",
"--trace-events-enabled",
"--trace-event-categories",
"--trace-event-file-pattern",
"--track-heap-objects",
"--zero-fill-buffers",
"--v8-pool-size",
Expand Down Expand Up @@ -4128,6 +4135,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 @@ -12,7 +12,7 @@ using 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.hasCrypto) {
expect('--use-openssl-ca', '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);
}));
}));

0 comments on commit e602726

Please sign in to comment.