Skip to content

Commit 2efcf73

Browse files
legendecascheungxi
authored andcommitted
src: per-environment time origin value
According to https://html.spec.whatwg.org/#environment-settings-object, the timeOrigin is a per-environment value. Worker's timeOrigin is the time when the worker is created. PR-URL: nodejs#43781 Reviewed-By: Matteo Collina <matteo.collina@gmail.com> Reviewed-By: Anna Henningsen <anna@addaleax.net> Reviewed-By: Paolo Insogna <paolo@cowtech.it> Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com>
1 parent 7351221 commit 2efcf73

10 files changed

Lines changed: 99 additions & 56 deletions

File tree

Lines changed: 40 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -1,13 +1,26 @@
11
'use strict';
22

3-
const nodeTiming = require('internal/perf/nodetiming');
4-
5-
const { now } = require('internal/perf/utils');
3+
const {
4+
constants: {
5+
NODE_PERFORMANCE_MILESTONE_LOOP_START,
6+
},
7+
loopIdleTime,
8+
milestones,
9+
} = internalBinding('performance');
610

711
function eventLoopUtilization(util1, util2) {
8-
const ls = nodeTiming.loopStart;
12+
// Get the original milestone timestamps that calculated from the beginning
13+
// of the process.
14+
return internalEventLoopUtilization(
15+
milestones[NODE_PERFORMANCE_MILESTONE_LOOP_START] / 1e6,
16+
loopIdleTime(),
17+
util1,
18+
util2
19+
);
20+
}
921

10-
if (ls <= 0) {
22+
function internalEventLoopUtilization(loopStart, loopIdleTime, util1, util2) {
23+
if (loopStart <= 0) {
1124
return { idle: 0, active: 0, utilization: 0 };
1225
}
1326

@@ -17,17 +30,31 @@ function eventLoopUtilization(util1, util2) {
1730
return { idle, active, utilization: active / (idle + active) };
1831
}
1932

20-
const idle = nodeTiming.idleTime;
21-
const active = now() - ls - idle;
33+
// Using process.hrtime() to get the time from the beginning of the process,
34+
// and offset it by the loopStart time (which is also calculated from the
35+
// beginning of the process).
36+
const now = process.hrtime();
37+
const active = now[0] * 1e3 + now[1] / 1e6 - loopStart - loopIdleTime;
2238

2339
if (!util1) {
24-
return { idle, active, utilization: active / (idle + active) };
40+
return {
41+
idle: loopIdleTime,
42+
active,
43+
utilization: active / (loopIdleTime + active),
44+
};
2545
}
2646

27-
const idle_delta = idle - util1.idle;
28-
const active_delta = active - util1.active;
29-
const utilization = active_delta / (idle_delta + active_delta);
30-
return { idle: idle_delta, active: active_delta, utilization };
47+
const idleDelta = loopIdleTime - util1.idle;
48+
const activeDelta = active - util1.active;
49+
const utilization = activeDelta / (idleDelta + activeDelta);
50+
return {
51+
idle: idleDelta,
52+
active: activeDelta,
53+
utilization,
54+
};
3155
}
3256

33-
module.exports = eventLoopUtilization;
57+
module.exports = {
58+
internalEventLoopUtilization,
59+
eventLoopUtilization,
60+
};

lib/internal/perf/performance.js

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -35,7 +35,7 @@ const {
3535
setDispatchBufferFull,
3636
} = require('internal/perf/observe');
3737

38-
const eventLoopUtilization = require('internal/perf/event_loop_utilization');
38+
const { eventLoopUtilization } = require('internal/perf/event_loop_utilization');
3939
const nodeTiming = require('internal/perf/nodetiming');
4040
const timerify = require('internal/perf/timerify');
4141
const { customInspectSymbol: kInspect } = require('internal/util');

lib/internal/worker.js

Lines changed: 9 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -27,7 +27,9 @@ const {
2727
const EventEmitter = require('events');
2828
const assert = require('internal/assert');
2929
const path = require('path');
30-
const { now } = require('internal/perf/utils');
30+
const {
31+
internalEventLoopUtilization
32+
} = require('internal/perf/event_loop_utilization');
3133

3234
const errorCodes = require('internal/errors').codes;
3335
const {
@@ -472,28 +474,12 @@ function eventLoopUtilization(util1, util2) {
472474
return { idle: 0, active: 0, utilization: 0 };
473475
}
474476

475-
if (util2) {
476-
const idle = util1.idle - util2.idle;
477-
const active = util1.active - util2.active;
478-
return { idle, active, utilization: active / (idle + active) };
479-
}
480-
481-
const idle = this[kHandle].loopIdleTime();
482-
483-
// Using performance.now() here is fine since it's always the time from
484-
// the beginning of the process, and is why it needs to be offset by the
485-
// loopStart time (which is also calculated from the beginning of the
486-
// process).
487-
const active = now() - this[kLoopStartTime] - idle;
488-
489-
if (!util1) {
490-
return { idle, active, utilization: active / (idle + active) };
491-
}
492-
493-
const idle_delta = idle - util1.idle;
494-
const active_delta = active - util1.active;
495-
const utilization = active_delta / (idle_delta + active_delta);
496-
return { idle: idle_delta, active: active_delta, utilization };
477+
return internalEventLoopUtilization(
478+
this[kLoopStartTime],
479+
this[kHandle].loopIdleTime(),
480+
util1,
481+
util2
482+
);
497483
}
498484

499485
module.exports = {

src/env.cc

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -663,7 +663,8 @@ Environment::Environment(IsolateData* isolate_data,
663663
stream_base_state_(isolate_,
664664
StreamBase::kNumStreamBaseStateFields,
665665
MAYBE_FIELD_PTR(env_info, stream_base_state)),
666-
environment_start_time_(PERFORMANCE_NOW()),
666+
time_origin_(PERFORMANCE_NOW()),
667+
time_origin_timestamp_(GetCurrentTimeInMicroseconds()),
667668
flags_(flags),
668669
thread_id_(thread_id.id == static_cast<uint64_t>(-1)
669670
? AllocateEnvironmentThreadId().id
@@ -768,7 +769,7 @@ void Environment::InitializeMainContext(Local<Context> context,
768769
set_exiting(false);
769770

770771
performance_state_->Mark(performance::NODE_PERFORMANCE_MILESTONE_ENVIRONMENT,
771-
environment_start_time_);
772+
time_origin_);
772773
performance_state_->Mark(performance::NODE_PERFORMANCE_MILESTONE_NODE_START,
773774
per_process::node_start_time);
774775

src/env.h

Lines changed: 11 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -858,6 +858,13 @@ class Environment : public MemoryRetainer {
858858
inline HandleWrapQueue* handle_wrap_queue() { return &handle_wrap_queue_; }
859859
inline ReqWrapQueue* req_wrap_queue() { return &req_wrap_queue_; }
860860

861+
inline uint64_t time_origin() {
862+
return time_origin_;
863+
}
864+
inline double time_origin_timestamp() {
865+
return time_origin_timestamp_;
866+
}
867+
861868
inline bool EmitProcessEnvWarning() {
862869
bool current_value = emit_env_nonstring_warning_;
863870
emit_env_nonstring_warning_ = false;
@@ -1048,7 +1055,10 @@ class Environment : public MemoryRetainer {
10481055

10491056
AliasedInt32Array stream_base_state_;
10501057

1051-
uint64_t environment_start_time_;
1058+
// https://w3c.github.io/hr-time/#dfn-time-origin
1059+
uint64_t time_origin_;
1060+
// https://w3c.github.io/hr-time/#dfn-get-time-origin-timestamp
1061+
double time_origin_timestamp_;
10521062
std::unique_ptr<performance::PerformanceState> performance_state_;
10531063

10541064
bool has_serialized_options_ = false;

src/node_http2.cc

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -644,7 +644,7 @@ void Http2Stream::EmitStatistics() {
644644
std::unique_ptr<Http2StreamPerformanceEntry> entry =
645645
std::make_unique<Http2StreamPerformanceEntry>(
646646
"Http2Stream",
647-
start - (node::performance::timeOrigin / 1e6),
647+
start - (env()->time_origin() / 1e6),
648648
duration,
649649
statistics_);
650650

@@ -664,7 +664,7 @@ void Http2Session::EmitStatistics() {
664664
std::unique_ptr<Http2SessionPerformanceEntry> entry =
665665
std::make_unique<Http2SessionPerformanceEntry>(
666666
"Http2Session",
667-
start - (node::performance::timeOrigin / 1e6),
667+
start - (env()->time_origin() / 1e6),
668668
duration,
669669
statistics_);
670670

src/node_perf.cc

Lines changed: 12 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -35,11 +35,9 @@ using v8::Value;
3535

3636
// Microseconds in a millisecond, as a float.
3737
#define MICROS_PER_MILLIS 1e3
38+
// Nanoseconds in a millisecond, as a float.
39+
#define NANOS_PER_MILLIS 1e6
3840

39-
// https://w3c.github.io/hr-time/#dfn-time-origin
40-
const uint64_t timeOrigin = PERFORMANCE_NOW();
41-
// https://w3c.github.io/hr-time/#dfn-time-origin-timestamp
42-
const double timeOriginTimestamp = GetCurrentTimeInMicroseconds();
4341
uint64_t performance_v8_start;
4442

4543
PerformanceState::PerformanceState(Isolate* isolate,
@@ -170,9 +168,10 @@ void MarkGarbageCollectionEnd(
170168
return;
171169

172170
double start_time =
173-
(state->performance_last_gc_start_mark - timeOrigin) / 1e6;
174-
double duration =
175-
(PERFORMANCE_NOW() / 1e6) - (state->performance_last_gc_start_mark / 1e6);
171+
(state->performance_last_gc_start_mark - env->time_origin()) /
172+
NANOS_PER_MILLIS;
173+
double duration = (PERFORMANCE_NOW() / NANOS_PER_MILLIS) -
174+
(state->performance_last_gc_start_mark / NANOS_PER_MILLIS);
176175

177176
std::unique_ptr<GCPerformanceEntry> entry =
178177
std::make_unique<GCPerformanceEntry>(
@@ -270,12 +269,15 @@ void CreateELDHistogram(const FunctionCallbackInfo<Value>& args) {
270269
}
271270

272271
void GetTimeOrigin(const FunctionCallbackInfo<Value>& args) {
273-
args.GetReturnValue().Set(Number::New(args.GetIsolate(), timeOrigin / 1e6));
272+
Environment* env = Environment::GetCurrent(args);
273+
args.GetReturnValue().Set(
274+
Number::New(args.GetIsolate(), env->time_origin() / 1e6));
274275
}
275276

276277
void GetTimeOriginTimeStamp(const FunctionCallbackInfo<Value>& args) {
277-
args.GetReturnValue().Set(
278-
Number::New(args.GetIsolate(), timeOriginTimestamp / MICROS_PER_MILLIS));
278+
Environment* env = Environment::GetCurrent(args);
279+
args.GetReturnValue().Set(Number::New(
280+
args.GetIsolate(), env->time_origin_timestamp() / MICROS_PER_MILLIS));
279281
}
280282

281283
void MarkBootstrapComplete(const FunctionCallbackInfo<Value>& args) {

src/node_perf.h

Lines changed: 0 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -21,8 +21,6 @@ class ExternalReferenceRegistry;
2121

2222
namespace performance {
2323

24-
extern const uint64_t timeOrigin;
25-
2624
inline const char* GetPerformanceMilestoneName(
2725
PerformanceMilestone milestone) {
2826
switch (milestone) {

src/node_worker.cc

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -839,8 +839,7 @@ void Worker::LoopStartTime(const FunctionCallbackInfo<Value>& args) {
839839
double loop_start_time = w->env_->performance_state()->milestones[
840840
node::performance::NODE_PERFORMANCE_MILESTONE_LOOP_START];
841841
CHECK_GE(loop_start_time, 0);
842-
args.GetReturnValue().Set(
843-
(loop_start_time - node::performance::timeOrigin) / 1e6);
842+
args.GetReturnValue().Set(loop_start_time / 1e6);
844843
}
845844

846845
namespace {
Lines changed: 20 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,20 @@
1+
'use strict';
2+
3+
const common = require('../common');
4+
const assert = require('assert');
5+
const { Worker } = require('worker_threads');
6+
7+
const w = new Worker(`
8+
require('worker_threads').parentPort.postMessage(performance.timeOrigin);
9+
`, { eval: true });
10+
11+
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);
16+
}));
17+
18+
w.on('exit', common.mustCall((code) => {
19+
assert.strictEqual(code, 0);
20+
}));

0 commit comments

Comments
 (0)