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: https://github.com/nodejs/node/pull/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>
This commit is contained in:
legendecas 2022-07-12 00:26:17 +08:00
parent 73ba8830d5
commit dabda03ea9
No known key found for this signature in database
GPG key ID: CB3C9EC2BC27057C
10 changed files with 99 additions and 56 deletions

View file

@ -1,13 +1,26 @@
'use strict'; 'use strict';
const nodeTiming = require('internal/perf/nodetiming'); const {
constants: {
const { now } = require('internal/perf/utils'); NODE_PERFORMANCE_MILESTONE_LOOP_START,
},
loopIdleTime,
milestones,
} = internalBinding('performance');
function eventLoopUtilization(util1, util2) { 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 }; return { idle: 0, active: 0, utilization: 0 };
} }
@ -17,17 +30,31 @@ function eventLoopUtilization(util1, util2) {
return { idle, active, utilization: active / (idle + active) }; return { idle, active, utilization: active / (idle + active) };
} }
const idle = nodeTiming.idleTime; // Using process.hrtime() to get the time from the beginning of the process,
const active = now() - ls - idle; // 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) { if (!util1) {
return { idle, active, utilization: active / (idle + active) }; return {
idle: loopIdleTime,
active,
utilization: active / (loopIdleTime + active),
};
} }
const idle_delta = idle - util1.idle; const idleDelta = loopIdleTime - util1.idle;
const active_delta = active - util1.active; const activeDelta = active - util1.active;
const utilization = active_delta / (idle_delta + active_delta); const utilization = activeDelta / (idleDelta + activeDelta);
return { idle: idle_delta, active: active_delta, utilization }; return {
idle: idleDelta,
active: activeDelta,
utilization,
};
} }
module.exports = eventLoopUtilization; module.exports = {
internalEventLoopUtilization,
eventLoopUtilization,
};

View file

@ -31,7 +31,7 @@ const {
filterBufferMapByNameAndType, filterBufferMapByNameAndType,
} = require('internal/perf/observe'); } = 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 nodeTiming = require('internal/perf/nodetiming');
const timerify = require('internal/perf/timerify'); const timerify = require('internal/perf/timerify');
const { customInspectSymbol: kInspect } = require('internal/util'); const { customInspectSymbol: kInspect } = require('internal/util');

View file

@ -27,7 +27,9 @@ const {
const EventEmitter = require('events'); const EventEmitter = require('events');
const assert = require('internal/assert'); const assert = require('internal/assert');
const path = require('path'); 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 errorCodes = require('internal/errors').codes;
const { const {
@ -472,28 +474,12 @@ function eventLoopUtilization(util1, util2) {
return { idle: 0, active: 0, utilization: 0 }; return { idle: 0, active: 0, utilization: 0 };
} }
if (util2) { return internalEventLoopUtilization(
const idle = util1.idle - util2.idle; this[kLoopStartTime],
const active = util1.active - util2.active; this[kHandle].loopIdleTime(),
return { idle, active, utilization: active / (idle + active) }; util1,
} util2
);
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 };
} }
module.exports = { module.exports = {

View file

@ -743,7 +743,8 @@ Environment::Environment(IsolateData* isolate_data,
stream_base_state_(isolate_, stream_base_state_(isolate_,
StreamBase::kNumStreamBaseStateFields, StreamBase::kNumStreamBaseStateFields,
MAYBE_FIELD_PTR(env_info, stream_base_state)), MAYBE_FIELD_PTR(env_info, stream_base_state)),
environment_start_time_(PERFORMANCE_NOW()), time_origin_(PERFORMANCE_NOW()),
time_origin_timestamp_(GetCurrentTimeInMicroseconds()),
flags_(flags), flags_(flags),
thread_id_(thread_id.id == static_cast<uint64_t>(-1) thread_id_(thread_id.id == static_cast<uint64_t>(-1)
? AllocateEnvironmentThreadId().id ? AllocateEnvironmentThreadId().id
@ -843,7 +844,7 @@ void Environment::InitializeMainContext(Local<Context> context,
should_abort_on_uncaught_toggle_[0] = 1; should_abort_on_uncaught_toggle_[0] = 1;
performance_state_->Mark(performance::NODE_PERFORMANCE_MILESTONE_ENVIRONMENT, performance_state_->Mark(performance::NODE_PERFORMANCE_MILESTONE_ENVIRONMENT,
environment_start_time_); time_origin_);
performance_state_->Mark(performance::NODE_PERFORMANCE_MILESTONE_NODE_START, performance_state_->Mark(performance::NODE_PERFORMANCE_MILESTONE_NODE_START,
per_process::node_start_time); per_process::node_start_time);

View file

@ -1363,6 +1363,13 @@ class Environment : public MemoryRetainer {
inline HandleWrapQueue* handle_wrap_queue() { return &handle_wrap_queue_; } inline HandleWrapQueue* handle_wrap_queue() { return &handle_wrap_queue_; }
inline ReqWrapQueue* req_wrap_queue() { return &req_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() { inline bool EmitProcessEnvWarning() {
bool current_value = emit_env_nonstring_warning_; bool current_value = emit_env_nonstring_warning_;
emit_env_nonstring_warning_ = false; emit_env_nonstring_warning_ = false;
@ -1550,7 +1557,10 @@ class Environment : public MemoryRetainer {
AliasedInt32Array stream_base_state_; 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_; std::unique_ptr<performance::PerformanceState> performance_state_;
bool has_run_bootstrapping_code_ = false; bool has_run_bootstrapping_code_ = false;

View file

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

View file

@ -35,11 +35,9 @@ using v8::Value;
// Microseconds in a millisecond, as a float. // Microseconds in a millisecond, as a float.
#define MICROS_PER_MILLIS 1e3 #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; uint64_t performance_v8_start;
PerformanceState::PerformanceState(Isolate* isolate, PerformanceState::PerformanceState(Isolate* isolate,
@ -160,9 +158,10 @@ void MarkGarbageCollectionEnd(
return; return;
double start_time = double start_time =
(state->performance_last_gc_start_mark - timeOrigin) / 1e6; (state->performance_last_gc_start_mark - env->time_origin()) /
double duration = NANOS_PER_MILLIS;
(PERFORMANCE_NOW() / 1e6) - (state->performance_last_gc_start_mark / 1e6); double duration = (PERFORMANCE_NOW() / NANOS_PER_MILLIS) -
(state->performance_last_gc_start_mark / NANOS_PER_MILLIS);
std::unique_ptr<GCPerformanceEntry> entry = std::unique_ptr<GCPerformanceEntry> entry =
std::make_unique<GCPerformanceEntry>( std::make_unique<GCPerformanceEntry>(
@ -257,12 +256,15 @@ void CreateELDHistogram(const FunctionCallbackInfo<Value>& args) {
} }
void GetTimeOrigin(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) { void GetTimeOriginTimeStamp(const FunctionCallbackInfo<Value>& args) {
args.GetReturnValue().Set( Environment* env = Environment::GetCurrent(args);
Number::New(args.GetIsolate(), timeOriginTimestamp / MICROS_PER_MILLIS)); args.GetReturnValue().Set(Number::New(
args.GetIsolate(), env->time_origin_timestamp() / MICROS_PER_MILLIS));
} }
void Initialize(Local<Object> target, void Initialize(Local<Object> target,

View file

@ -21,8 +21,6 @@ class ExternalReferenceRegistry;
namespace performance { namespace performance {
extern const uint64_t timeOrigin;
inline const char* GetPerformanceMilestoneName( inline const char* GetPerformanceMilestoneName(
PerformanceMilestone milestone) { PerformanceMilestone milestone) {
switch (milestone) { switch (milestone) {

View file

@ -816,8 +816,7 @@ void Worker::LoopStartTime(const FunctionCallbackInfo<Value>& args) {
double loop_start_time = w->env_->performance_state()->milestones[ double loop_start_time = w->env_->performance_state()->milestones[
node::performance::NODE_PERFORMANCE_MILESTONE_LOOP_START]; node::performance::NODE_PERFORMANCE_MILESTONE_LOOP_START];
CHECK_GE(loop_start_time, 0); CHECK_GE(loop_start_time, 0);
args.GetReturnValue().Set( args.GetReturnValue().Set(loop_start_time / 1e6);
(loop_start_time - node::performance::timeOrigin) / 1e6);
} }
namespace { namespace {

View file

@ -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);
}));