Skip to content

Commit dabda03

Browse files
legendecaslegendecas
committed
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: #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 73ba883 commit dabda03

File tree

10 files changed

+99
-56
lines changed

10 files changed

+99
-56
lines changed

‎lib/internal/perf/event_loop_utilization.js‎

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
@@ -31,7 +31,7 @@ const {
3131
filterBufferMapByNameAndType,
3232
} = require('internal/perf/observe');
3333

34-
const eventLoopUtilization = require('internal/perf/event_loop_utilization');
34+
const { eventLoopUtilization } = require('internal/perf/event_loop_utilization');
3535
const nodeTiming = require('internal/perf/nodetiming');
3636
const timerify = require('internal/perf/timerify');
3737
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
@@ -743,7 +743,8 @@ Environment::Environment(IsolateData* isolate_data,
743743
stream_base_state_(isolate_,
744744
StreamBase::kNumStreamBaseStateFields,
745745
MAYBE_FIELD_PTR(env_info, stream_base_state)),
746-
environment_start_time_(PERFORMANCE_NOW()),
746+
time_origin_(PERFORMANCE_NOW()),
747+
time_origin_timestamp_(GetCurrentTimeInMicroseconds()),
747748
flags_(flags),
748749
thread_id_(thread_id.id == static_cast<uint64_t>(-1)
749750
? AllocateEnvironmentThreadId().id
@@ -843,7 +844,7 @@ void Environment::InitializeMainContext(Local<Context> context,
843844
should_abort_on_uncaught_toggle_[0] = 1;
844845

845846
performance_state_->Mark(performance::NODE_PERFORMANCE_MILESTONE_ENVIRONMENT,
846-
environment_start_time_);
847+
time_origin_);
847848
performance_state_->Mark(performance::NODE_PERFORMANCE_MILESTONE_NODE_START,
848849
per_process::node_start_time);
849850

‎src/env.h‎

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

1366+
inline uint64_t time_origin() {
1367+
return time_origin_;
1368+
}
1369+
inline double time_origin_timestamp() {
1370+
return time_origin_timestamp_;
1371+
}
1372+
13661373
inline bool EmitProcessEnvWarning() {
13671374
bool current_value = emit_env_nonstring_warning_;
13681375
emit_env_nonstring_warning_ = false;
@@ -1550,7 +1557,10 @@ class Environment : public MemoryRetainer {
15501557

15511558
AliasedInt32Array stream_base_state_;
15521559

1553-
uint64_t environment_start_time_;
1560+
// https://w3c.github.io/hr-time/#dfn-time-origin
1561+
uint64_t time_origin_;
1562+
// https://w3c.github.io/hr-time/#dfn-get-time-origin-timestamp
1563+
double time_origin_timestamp_;
15541564
std::unique_ptr<performance::PerformanceState> performance_state_;
15551565

15561566
bool has_run_bootstrapping_code_ = false;

‎src/node_http2.cc‎

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

@@ -660,7 +660,7 @@ void Http2Session::EmitStatistics() {
660660
std::unique_ptr<Http2SessionPerformanceEntry> entry =
661661
std::make_unique<Http2SessionPerformanceEntry>(
662662
"Http2Session",
663-
start - (node::performance::timeOrigin / 1e6),
663+
start - (env()->time_origin() / 1e6),
664664
duration,
665665
statistics_);
666666

‎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,
@@ -160,9 +158,10 @@ void MarkGarbageCollectionEnd(
160158
return;
161159

162160
double start_time =
163-
(state->performance_last_gc_start_mark - timeOrigin) / 1e6;
164-
double duration =
165-
(PERFORMANCE_NOW() / 1e6) - (state->performance_last_gc_start_mark / 1e6);
161+
(state->performance_last_gc_start_mark - env->time_origin()) /
162+
NANOS_PER_MILLIS;
163+
double duration = (PERFORMANCE_NOW() / NANOS_PER_MILLIS) -
164+
(state->performance_last_gc_start_mark / NANOS_PER_MILLIS);
166165

167166
std::unique_ptr<GCPerformanceEntry> entry =
168167
std::make_unique<GCPerformanceEntry>(
@@ -257,12 +256,15 @@ void CreateELDHistogram(const FunctionCallbackInfo<Value>& args) {
257256
}
258257

259258
void GetTimeOrigin(const FunctionCallbackInfo<Value>& args) {
260-
args.GetReturnValue().Set(Number::New(args.GetIsolate(), timeOrigin / 1e6));
259+
Environment* env = Environment::GetCurrent(args);
260+
args.GetReturnValue().Set(
261+
Number::New(args.GetIsolate(), env->time_origin() / 1e6));
261262
}
262263

263264
void GetTimeOriginTimeStamp(const FunctionCallbackInfo<Value>& args) {
264-
args.GetReturnValue().Set(
265-
Number::New(args.GetIsolate(), timeOriginTimestamp / MICROS_PER_MILLIS));
265+
Environment* env = Environment::GetCurrent(args);
266+
args.GetReturnValue().Set(Number::New(
267+
args.GetIsolate(), env->time_origin_timestamp() / MICROS_PER_MILLIS));
266268
}
267269

268270
void Initialize(Local<Object> target,

‎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
@@ -816,8 +816,7 @@ void Worker::LoopStartTime(const FunctionCallbackInfo<Value>& args) {
816816
double loop_start_time = w->env_->performance_state()->milestones[
817817
node::performance::NODE_PERFORMANCE_MILESTONE_LOOP_START];
818818
CHECK_GE(loop_start_time, 0);
819-
args.GetReturnValue().Set(
820-
(loop_start_time - node::performance::timeOrigin) / 1e6);
819+
args.GetReturnValue().Set(loop_start_time / 1e6);
821820
}
822821

823822
namespace {

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

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)