summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
-rw-r--r--doc/api/tracing.md1
-rw-r--r--src/env.cc17
-rw-r--r--src/node.cc6
-rw-r--r--src/node_perf.cc16
-rw-r--r--src/node_perf.h18
-rw-r--r--src/node_perf_common.h9
-rw-r--r--test/parallel/test-trace-events-bootstrap.js53
7 files changed, 92 insertions, 28 deletions
diff --git a/doc/api/tracing.md b/doc/api/tracing.md
index ef58eb72ba..b53197b810 100644
--- a/doc/api/tracing.md
+++ b/doc/api/tracing.md
@@ -16,6 +16,7 @@ The available categories are:
* `node`
* `node.async_hooks` - Enables capture of detailed async_hooks trace data.
+* `node.bootstrap` - Enables capture of Node.js bootstrap milestones.
* `node.perf` - Enables capture of [Performance API] measurements.
* `node.perf.usertiming` - Enables capture of only Performance API User Timing
measures and marks.
diff --git a/src/env.cc b/src/env.cc
index 3d1e5d3ac1..c876103972 100644
--- a/src/env.cc
+++ b/src/env.cc
@@ -115,15 +115,14 @@ Environment::Environment(IsolateData* isolate_data,
destroy_async_id_list_.reserve(512);
performance_state_.reset(new performance::performance_state(isolate()));
- performance_state_->milestones[
- performance::NODE_PERFORMANCE_MILESTONE_ENVIRONMENT] =
- PERFORMANCE_NOW();
- performance_state_->milestones[
- performance::NODE_PERFORMANCE_MILESTONE_NODE_START] =
- performance::performance_node_start;
- performance_state_->milestones[
- performance::NODE_PERFORMANCE_MILESTONE_V8_START] =
- performance::performance_v8_start;
+ performance_state_->Mark(
+ performance::NODE_PERFORMANCE_MILESTONE_ENVIRONMENT);
+ performance_state_->Mark(
+ performance::NODE_PERFORMANCE_MILESTONE_NODE_START,
+ performance::performance_node_start);
+ performance_state_->Mark(
+ performance::NODE_PERFORMANCE_MILESTONE_V8_START,
+ performance::performance_v8_start);
// By default, always abort when --abort-on-uncaught-exception was passed.
should_abort_on_uncaught_toggle_[0] = 1;
diff --git a/src/node.cc b/src/node.cc
index 4833ef0fd1..e7dd666934 100644
--- a/src/node.cc
+++ b/src/node.cc
@@ -4474,7 +4474,8 @@ inline int Start(Isolate* isolate, IsolateData* isolate_data,
{
SealHandleScope seal(isolate);
bool more;
- PERFORMANCE_MARK(&env, LOOP_START);
+ env.performance_state()->Mark(
+ node::performance::NODE_PERFORMANCE_MILESTONE_LOOP_START);
do {
uv_run(env.event_loop(), UV_RUN_DEFAULT);
@@ -4490,7 +4491,8 @@ inline int Start(Isolate* isolate, IsolateData* isolate_data,
// event, or after running some callbacks.
more = uv_loop_alive(env.event_loop());
} while (more == true);
- PERFORMANCE_MARK(&env, LOOP_EXIT);
+ env.performance_state()->Mark(
+ node::performance::NODE_PERFORMANCE_MILESTONE_LOOP_EXIT);
}
env.set_trace_sync_io(false);
diff --git a/src/node_perf.cc b/src/node_perf.cc
index 8260d78c32..8b476890e1 100644
--- a/src/node_perf.cc
+++ b/src/node_perf.cc
@@ -40,6 +40,15 @@ uint64_t performance_v8_start;
uint64_t performance_last_gc_start_mark_ = 0;
v8::GCType performance_last_gc_type_ = v8::GCType::kGCTypeAll;
+void performance_state::Mark(enum PerformanceMilestone milestone,
+ uint64_t ts) {
+ this->milestones[milestone] = ts;
+ TRACE_EVENT_INSTANT_WITH_TIMESTAMP0(
+ TRACING_CATEGORY_NODE1(bootstrap),
+ GetPerformanceMilestoneName(milestone),
+ TRACE_EVENT_SCOPE_THREAD, ts);
+}
+
double GetCurrentTimeInMicroseconds() {
#ifdef _WIN32
// The difference between the Unix Epoch and the Windows Epoch in 100-ns ticks.
@@ -200,14 +209,11 @@ void Measure(const FunctionCallbackInfo<Value>& args) {
void MarkMilestone(const FunctionCallbackInfo<Value>& args) {
Environment* env = Environment::GetCurrent(args);
Local<Context> context = env->context();
- AliasedBuffer<double, v8::Float64Array>& milestones =
- env->performance_state()->milestones;
PerformanceMilestone milestone =
static_cast<PerformanceMilestone>(
args[0]->Int32Value(context).ToChecked());
- if (milestone != NODE_PERFORMANCE_MILESTONE_INVALID) {
- milestones[milestone] = PERFORMANCE_NOW();
- }
+ if (milestone != NODE_PERFORMANCE_MILESTONE_INVALID)
+ env->performance_state()->Mark(milestone);
}
diff --git a/src/node_perf.h b/src/node_perf.h
index 0db99acd03..703ef81ce4 100644
--- a/src/node_perf.h
+++ b/src/node_perf.h
@@ -27,6 +27,18 @@ extern const uint64_t timeOrigin;
double GetCurrentTimeInMicroseconds();
+static inline const char* GetPerformanceMilestoneName(
+ enum PerformanceMilestone milestone) {
+ switch (milestone) {
+#define V(name, label) case NODE_PERFORMANCE_MILESTONE_##name: return label;
+ NODE_PERFORMANCE_MILESTONES(V)
+#undef V
+ default:
+ UNREACHABLE();
+ return 0;
+ }
+}
+
static inline PerformanceMilestone ToPerformanceMilestoneEnum(const char* str) {
#define V(name, label) \
if (strcmp(str, label) == 0) return NODE_PERFORMANCE_MILESTONE_##name;
@@ -44,12 +56,6 @@ static inline PerformanceEntryType ToPerformanceEntryTypeEnum(
return NODE_PERFORMANCE_ENTRY_TYPE_INVALID;
}
-NODE_EXTERN inline void MarkPerformanceMilestone(
- Environment* env,
- PerformanceMilestone milestone) {
- env->performance_state()->milestones[milestone] = PERFORMANCE_NOW();
-}
-
class PerformanceEntry {
public:
static void Notify(Environment* env,
diff --git a/src/node_perf_common.h b/src/node_perf_common.h
index 7ff57359ba..9754e1e66f 100644
--- a/src/node_perf_common.h
+++ b/src/node_perf_common.h
@@ -56,12 +56,6 @@ enum PerformanceEntryType {
NODE_PERFORMANCE_ENTRY_TYPE_INVALID
};
-#define PERFORMANCE_MARK(env, n) \
- do { \
- node::performance::MarkPerformanceMilestone(env, \
- node::performance::NODE_PERFORMANCE_MILESTONE_##n); \
- } while (0);
-
class performance_state {
public:
explicit performance_state(v8::Isolate* isolate) :
@@ -86,6 +80,9 @@ class performance_state {
AliasedBuffer<double, v8::Float64Array> milestones;
AliasedBuffer<uint32_t, v8::Uint32Array> observers;
+ void Mark(enum PerformanceMilestone milestone,
+ uint64_t ts = PERFORMANCE_NOW());
+
private:
struct performance_state_internal {
// doubles first so that they are always sizeof(double)-aligned
diff --git a/test/parallel/test-trace-events-bootstrap.js b/test/parallel/test-trace-events-bootstrap.js
new file mode 100644
index 0000000000..6693291664
--- /dev/null
+++ b/test/parallel/test-trace-events-bootstrap.js
@@ -0,0 +1,53 @@
+'use strict';
+const common = require('../common');
+const assert = require('assert');
+const cp = require('child_process');
+const path = require('path');
+const fs = require('fs');
+const tmpdir = require('../common/tmpdir');
+
+const names = [
+ 'environment',
+ 'nodeStart',
+ 'v8Start',
+ 'loopStart',
+ 'loopExit',
+ 'bootstrapComplete',
+ 'thirdPartyMainStart',
+ 'thirdPartyMainEnd',
+ 'clusterSetupStart',
+ 'clusterSetupEnd',
+ 'moduleLoadStart',
+ 'moduleLoadEnd',
+ 'preloadModulesLoadStart',
+ 'preloadModulesLoadEnd'
+];
+
+if (process.argv[2] === 'child') {
+ 1 + 1;
+} else {
+ tmpdir.refresh();
+ process.chdir(tmpdir.path);
+
+ const proc = cp.fork(__filename,
+ [ 'child' ], {
+ execArgv: [
+ '--trace-events-enabled',
+ '--trace-event-categories',
+ 'node.bootstrap'
+ ]
+ });
+
+ proc.once('exit', common.mustCall(() => {
+ const file = path.join(tmpdir.path, 'node_trace.1.log');
+
+ assert(common.fileExists(file));
+ fs.readFile(file, common.mustCall((err, data) => {
+ const traces = JSON.parse(data.toString()).traceEvents;
+ traces.forEach((trace) => {
+ assert.strictEqual(trace.pid, proc.pid);
+ assert(names.includes(trace.name));
+ });
+ }));
+ }));
+}