FazBrowse GitHub Viewer | Trending |
URL:
| Home
Tools: [Download Repo ZIP]   [Original HTTPS Page]

src: fix negative nodeTiming milestone values · nodejs/node@6740679 · GitHub

/ node Public

Commit 6740679

Browse files
legendecas
authored and
targos
committed
src: fix negative nodeTiming milestone values
PR-URL: #46588 Fixes: #45958 Refs: #43781 Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Minwoo Jung <nodecorelab@gmail.com>
1 parent 074692a commit 6740679

6 files changed

Lines changed: 73 additions & 12 deletions

File tree

‎src/env.cc‎

Lines changed: 4 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -670,8 +670,9 @@ Environment::Environment(IsolateData* isolate_data,
670670
stream_base_state_(isolate_,
671671
StreamBase::kNumStreamBaseStateFields,
672672
MAYBE_FIELD_PTR(env_info, stream_base_state)),
673-
time_origin_(PERFORMANCE_NOW()),
674-
time_origin_timestamp_(GetCurrentTimeInMicroseconds()),
673+
time_origin_(performance::performance_process_start),
674+
time_origin_timestamp_(performance::performance_process_start_timestamp),
675+
environment_start_(PERFORMANCE_NOW()),
675676
flags_(flags),
676677
thread_id_(thread_id.id == static_cast<uint64_t>(-1)
677678
? AllocateEnvironmentThreadId().id
@@ -777,7 +778,7 @@ void Environment::InitializeMainContext(Local<Context> context,
777778
set_exiting(false);
778779

779780
performance_state_->Mark(performance::NODE_PERFORMANCE_MILESTONE_ENVIRONMENT,
780-
time_origin_);
781+
environment_start_);
781782
performance_state_->Mark(performance::NODE_PERFORMANCE_MILESTONE_NODE_START,
782783
per_process::node_start_time);
783784

‎src/env.h‎

Lines changed: 13 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -842,9 +842,11 @@ class Environment : public MemoryRetainer {
842842
inline HandleWrapQueue* handle_wrap_queue() { return &handle_wrap_queue_; }
843843
inline ReqWrapQueue* req_wrap_queue() { return &req_wrap_queue_; }
844844

845+
// https://w3c.github.io/hr-time/#dfn-time-origin
845846
inline uint64_t time_origin() {
846847
return time_origin_;
847848
}
849+
// https://w3c.github.io/hr-time/#dfn-get-time-origin-timestamp
848850
inline double time_origin_timestamp() {
849851
return time_origin_timestamp_;
850852
}
@@ -1044,10 +1046,17 @@ class Environment : public MemoryRetainer {
10441046

10451047
AliasedInt32Array stream_base_state_;
10461048

1047-
// https://w3c.github.io/hr-time/#dfn-time-origin
1048-
uint64_t time_origin_;
1049-
// https://w3c.github.io/hr-time/#dfn-get-time-origin-timestamp
1050-
double time_origin_timestamp_;
1049+
// As PerformanceNodeTiming is exposed in worker_threads, the per_process
1050+
// time origin is exposed in the worker threads. This is an intentional
1051+
// diverge from the HTML spec of web workers.
1052+
// Process start time from the monotonic clock. This should not be used as an
1053+
// absolute time, but only as a time relative to another monotonic clock time.
1054+
const uint64_t time_origin_;
1055+
// Process start timestamp from the wall clock. This is an absolute time
1056+
// exposed as `performance.timeOrigin`.
1057+
const double time_origin_timestamp_;
1058+
// This is the time when the environment is created.
1059+
const uint64_t environment_start_;
10511060
std::unique_ptr<performance::PerformanceState> performance_state_;
10521061

10531062
bool has_serialized_options_ = false;

‎src/node_perf.cc‎

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -38,6 +38,9 @@ using v8::Value;
3838
// Nanoseconds in a millisecond, as a float.
3939
#define NANOS_PER_MILLIS 1e6
4040

41+
const uint64_t performance_process_start = PERFORMANCE_NOW();
42+
const double performance_process_start_timestamp =
43+
GetCurrentTimeInMicroseconds();
4144
uint64_t performance_v8_start;
4245

4346
PerformanceState::PerformanceState(Isolate* isolate,
@@ -271,7 +274,7 @@ void CreateELDHistogram(const FunctionCallbackInfo<Value>& args) {
271274
void GetTimeOrigin(const FunctionCallbackInfo<Value>& args) {
272275
Environment* env = Environment::GetCurrent(args);
273276
args.GetReturnValue().Set(
274-
Number::New(args.GetIsolate(), env->time_origin() / 1e6));
277+
Number::New(args.GetIsolate(), env->time_origin() / NANOS_PER_MILLIS));
275278
}
276279

277280
void GetTimeOriginTimeStamp(const FunctionCallbackInfo<Value>& args) {

‎src/node_perf_common.h‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,8 @@ namespace performance {
2020

2121
// These occur before the environment is created. Cache them
2222
// here and add them to the milestones when the env is init'd.
23+
extern const uint64_t performance_process_start;
24+
extern const double performance_process_start_timestamp;
2325
extern uint64_t performance_v8_start;
2426

2527
#define NODE_PERFORMANCE_MILESTONES(V) \

‎test/parallel/test-perf-hooks-worker-timeorigin.js‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -9,10 +9,10 @@ require('worker_threads').parentPort.postMessage(performance.timeOrigin);
99
`, { eval: true });
1010

1111
w.on('message', common.mustCall((timeOrigin) => {
12-
// Worker is created after this main context, it's
13-
// `performance.timeOrigin` must be greater than this
14-
// main context's.
15-
assert.ok(timeOrigin > performance.timeOrigin);
12+
// PerformanceNodeTiming exposes process milestones so the
13+
// `performance.timeOrigin` in the `worker_threads.Worker` must be the start
14+
// time of the process.
15+
assert.strictEqual(timeOrigin, performance.timeOrigin);
1616
}));
1717

1818
w.on('exit', common.mustCall((code) => {

‎test/parallel/test-performance-nodetiming.js‎

Lines changed: 46 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,46 @@
1+
'use strict';
2+
3+
const common = require('../common');
4+
const assert = require('assert');
5+
const { performance } = require('perf_hooks');
6+
const { isMainThread } = require('worker_threads');
7+
8+
const { nodeTiming } = performance;
9+
assert.strictEqual(nodeTiming.name, 'node');
10+
assert.strictEqual(nodeTiming.entryType, 'node');
11+
12+
assert.strictEqual(nodeTiming.startTime, 0);
13+
const now = performance.now();
14+
assert.ok(nodeTiming.duration >= now);
15+
16+
// Check that the nodeTiming milestone values are in the correct order and greater than 0.
17+
const keys = ['nodeStart', 'v8Start', 'environment', 'bootstrapComplete'];
18+
for (let idx = 0; idx < keys.length; idx++) {
19+
if (idx === 0) {
20+
assert.ok(nodeTiming[keys[idx]] >= 0);
21+
continue;
22+
}
23+
assert.ok(nodeTiming[keys[idx]] > nodeTiming[keys[idx - 1]], `expect nodeTiming['${keys[idx]}'] > nodeTiming['${keys[idx - 1]}']`);
24+
}
25+
26+
// loop milestones.
27+
assert.strictEqual(nodeTiming.idleTime, 0);
28+
if (isMainThread) {
29+
// Main thread does not start loop until the first tick is finished.
30+
assert.strictEqual(nodeTiming.loopStart, -1);
31+
} else {
32+
// Worker threads run the user script after loop is started.
33+
assert.ok(nodeTiming.loopStart >= nodeTiming.bootstrapComplete);
34+
}
35+
assert.strictEqual(nodeTiming.loopExit, -1);
36+
37+
setTimeout(common.mustCall(() => {
38+
assert.ok(nodeTiming.idleTime >= 0);
39+
assert.ok(nodeTiming.idleTime + nodeTiming.loopExit <= nodeTiming.duration);
40+
assert.ok(nodeTiming.loopStart >= nodeTiming.bootstrapComplete);
41+
}, 1), 1);
42+
43+
// Can not be wrapped in common.mustCall().
44+
process.on('exit', () => {
45+
assert.ok(nodeTiming.loopExit > 0);
46+
});

0 commit comments

Comments
 (0)
Back | FazBrowse Home | New Git URL