Skip to content

Commit

Permalink
src: per-environment time origin value
Browse files Browse the repository at this point in the history
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 <[email protected]>
Reviewed-By: Anna Henningsen <[email protected]>
Reviewed-By: Paolo Insogna <[email protected]>
Reviewed-By: Joyee Cheung <[email protected]>
  • Loading branch information
legendecas authored and juanarbol committed Nov 4, 2022
1 parent b8290ff commit 11b0ad4
Show file tree
Hide file tree
Showing 10 changed files with 99 additions and 56 deletions.
53 changes: 40 additions & 13 deletions lib/internal/perf/event_loop_utilization.js
Original file line number Diff line number Diff line change
@@ -1,13 +1,26 @@
'use strict';

const nodeTiming = require('internal/perf/nodetiming');

const { now } = require('internal/perf/utils');
const {
constants: {
NODE_PERFORMANCE_MILESTONE_LOOP_START,
},
loopIdleTime,
milestones,
} = internalBinding('performance');

function eventLoopUtilization(util1, util2) {
const ls = nodeTiming.loopStart;
// Get the original milestone timestamps that calculated from the beginning
// of the process.
return internalEventLoopUtilization(
milestones[NODE_PERFORMANCE_MILESTONE_LOOP_START] / 1e6,
loopIdleTime(),
util1,
util2
);
}

if (ls <= 0) {
function internalEventLoopUtilization(loopStart, loopIdleTime, util1, util2) {
if (loopStart <= 0) {
return { idle: 0, active: 0, utilization: 0 };
}

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

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

if (!util1) {
return { idle, active, utilization: active / (idle + active) };
return {
idle: loopIdleTime,
active,
utilization: active / (loopIdleTime + active),
};
}

const idle_delta = idle - util1.idle;
const active_delta = active - util1.active;
const utilization = active_delta / (idle_delta + active_delta);
return { idle: idle_delta, active: active_delta, utilization };
const idleDelta = loopIdleTime - util1.idle;
const activeDelta = active - util1.active;
const utilization = activeDelta / (idleDelta + activeDelta);
return {
idle: idleDelta,
active: activeDelta,
utilization,
};
}

module.exports = eventLoopUtilization;
module.exports = {
internalEventLoopUtilization,
eventLoopUtilization,
};
2 changes: 1 addition & 1 deletion lib/internal/perf/performance.js
Original file line number Diff line number Diff line change
Expand Up @@ -35,7 +35,7 @@ const {
setDispatchBufferFull,
} = require('internal/perf/observe');

const eventLoopUtilization = require('internal/perf/event_loop_utilization');
const { eventLoopUtilization } = require('internal/perf/event_loop_utilization');
const nodeTiming = require('internal/perf/nodetiming');
const timerify = require('internal/perf/timerify');
const { customInspectSymbol: kInspect } = require('internal/util');
Expand Down
32 changes: 9 additions & 23 deletions lib/internal/worker.js
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,9 @@ const {
const EventEmitter = require('events');
const assert = require('internal/assert');
const path = require('path');
const { now } = require('internal/perf/utils');
const {
internalEventLoopUtilization
} = require('internal/perf/event_loop_utilization');

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

if (util2) {
const idle = util1.idle - util2.idle;
const active = util1.active - util2.active;
return { idle, active, utilization: active / (idle + active) };
}

const idle = this[kHandle].loopIdleTime();

// Using performance.now() here is fine since it's always the time from
// the beginning of the process, and is why it needs to be offset by the
// loopStart time (which is also calculated from the beginning of the
// process).
const active = now() - this[kLoopStartTime] - idle;

if (!util1) {
return { idle, active, utilization: active / (idle + active) };
}

const idle_delta = idle - util1.idle;
const active_delta = active - util1.active;
const utilization = active_delta / (idle_delta + active_delta);
return { idle: idle_delta, active: active_delta, utilization };
return internalEventLoopUtilization(
this[kLoopStartTime],
this[kHandle].loopIdleTime(),
util1,
util2
);
}

module.exports = {
Expand Down
5 changes: 3 additions & 2 deletions src/env.cc
Original file line number Diff line number Diff line change
Expand Up @@ -679,7 +679,8 @@ Environment::Environment(IsolateData* isolate_data,
stream_base_state_(isolate_,
StreamBase::kNumStreamBaseStateFields,
MAYBE_FIELD_PTR(env_info, stream_base_state)),
environment_start_time_(PERFORMANCE_NOW()),
time_origin_(PERFORMANCE_NOW()),
time_origin_timestamp_(GetCurrentTimeInMicroseconds()),
flags_(flags),
thread_id_(thread_id.id == static_cast<uint64_t>(-1)
? AllocateEnvironmentThreadId().id
Expand Down Expand Up @@ -785,7 +786,7 @@ void Environment::InitializeMainContext(Local<Context> context,
set_exiting(false);

performance_state_->Mark(performance::NODE_PERFORMANCE_MILESTONE_ENVIRONMENT,
environment_start_time_);
time_origin_);
performance_state_->Mark(performance::NODE_PERFORMANCE_MILESTONE_NODE_START,
per_process::node_start_time);

Expand Down
12 changes: 11 additions & 1 deletion src/env.h
Original file line number Diff line number Diff line change
Expand Up @@ -1316,6 +1316,13 @@ class Environment : public MemoryRetainer {
inline HandleWrapQueue* handle_wrap_queue() { return &handle_wrap_queue_; }
inline ReqWrapQueue* req_wrap_queue() { return &req_wrap_queue_; }

inline uint64_t time_origin() {
return time_origin_;
}
inline double time_origin_timestamp() {
return time_origin_timestamp_;
}

inline bool EmitProcessEnvWarning() {
bool current_value = emit_env_nonstring_warning_;
emit_env_nonstring_warning_ = false;
Expand Down Expand Up @@ -1513,7 +1520,10 @@ class Environment : public MemoryRetainer {

AliasedInt32Array stream_base_state_;

uint64_t environment_start_time_;
// https://w3c.github.io/hr-time/#dfn-time-origin
uint64_t time_origin_;
// https://w3c.github.io/hr-time/#dfn-get-time-origin-timestamp
double time_origin_timestamp_;
std::unique_ptr<performance::PerformanceState> performance_state_;

bool has_run_bootstrapping_code_ = false;
Expand Down
4 changes: 2 additions & 2 deletions src/node_http2.cc
Original file line number Diff line number Diff line change
Expand Up @@ -640,7 +640,7 @@ void Http2Stream::EmitStatistics() {
std::unique_ptr<Http2StreamPerformanceEntry> entry =
std::make_unique<Http2StreamPerformanceEntry>(
"Http2Stream",
start - (node::performance::timeOrigin / 1e6),
start - (env()->time_origin() / 1e6),
duration,
statistics_);

Expand All @@ -660,7 +660,7 @@ void Http2Session::EmitStatistics() {
std::unique_ptr<Http2SessionPerformanceEntry> entry =
std::make_unique<Http2SessionPerformanceEntry>(
"Http2Session",
start - (node::performance::timeOrigin / 1e6),
start - (env()->time_origin() / 1e6),
duration,
statistics_);

Expand Down
22 changes: 12 additions & 10 deletions src/node_perf.cc
Original file line number Diff line number Diff line change
Expand Up @@ -35,11 +35,9 @@ using v8::Value;

// Microseconds in a millisecond, as a float.
#define MICROS_PER_MILLIS 1e3
// Nanoseconds in a millisecond, as a float.
#define NANOS_PER_MILLIS 1e6

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

PerformanceState::PerformanceState(Isolate* isolate,
Expand Down Expand Up @@ -170,9 +168,10 @@ void MarkGarbageCollectionEnd(
return;

double start_time =
(state->performance_last_gc_start_mark - timeOrigin) / 1e6;
double duration =
(PERFORMANCE_NOW() / 1e6) - (state->performance_last_gc_start_mark / 1e6);
(state->performance_last_gc_start_mark - env->time_origin()) /
NANOS_PER_MILLIS;
double duration = (PERFORMANCE_NOW() / NANOS_PER_MILLIS) -
(state->performance_last_gc_start_mark / NANOS_PER_MILLIS);

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

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

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

void MarkBootstrapComplete(const FunctionCallbackInfo<Value>& args) {
Expand Down
2 changes: 0 additions & 2 deletions src/node_perf.h
Original file line number Diff line number Diff line change
Expand Up @@ -21,8 +21,6 @@ class ExternalReferenceRegistry;

namespace performance {

extern const uint64_t timeOrigin;

inline const char* GetPerformanceMilestoneName(
PerformanceMilestone milestone) {
switch (milestone) {
Expand Down
3 changes: 1 addition & 2 deletions src/node_worker.cc
Original file line number Diff line number Diff line change
Expand Up @@ -845,8 +845,7 @@ void Worker::LoopStartTime(const FunctionCallbackInfo<Value>& args) {
double loop_start_time = w->env_->performance_state()->milestones[
node::performance::NODE_PERFORMANCE_MILESTONE_LOOP_START];
CHECK_GE(loop_start_time, 0);
args.GetReturnValue().Set(
(loop_start_time - node::performance::timeOrigin) / 1e6);
args.GetReturnValue().Set(loop_start_time / 1e6);
}

namespace {
Expand Down
20 changes: 20 additions & 0 deletions test/parallel/test-perf-hooks-worker-timeorigin.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,20 @@
'use strict';

const common = require('../common');
const assert = require('assert');
const { Worker } = require('worker_threads');

const w = new Worker(`
require('worker_threads').parentPort.postMessage(performance.timeOrigin);
`, { eval: true });

w.on('message', common.mustCall((timeOrigin) => {
// Worker is created after this main context, it's
// `performance.timeOrigin` must be greater than this
// main context's.
assert.ok(timeOrigin > performance.timeOrigin);
}));

w.on('exit', common.mustCall((code) => {
assert.strictEqual(code, 0);
}));

0 comments on commit 11b0ad4

Please sign in to comment.