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>
joyeecheung · Oct 14, 2022 · 99e2a11 · 99e2a11
1 parent c13a4bc
commit 99e2a11
Show file tree

Hide file tree

Showing 10 changed files with 99 additions and 56 deletions.
diff --git a/lib/internal/perf/event_loop_utilization.js b/lib/internal/perf/event_loop_utilization.js
@@ -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 };
   }
 
@@ -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,
+};
diff --git a/lib/internal/perf/performance.js b/lib/internal/perf/performance.js
@@ -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');

diff --git a/lib/internal/worker.js b/lib/internal/worker.js
@@ -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 {
@@ -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 = {

diff --git a/src/env.cc b/src/env.cc
@@ -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
@@ -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);
 

diff --git a/src/env.h b/src/env.h
@@ -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;
@@ -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;

diff --git a/src/node_http2.cc b/src/node_http2.cc
@@ -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_);
 
@@ -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_);
 

diff --git a/src/node_perf.cc b/src/node_perf.cc
@@ -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,
@@ -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>(
@@ -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) {

diff --git a/src/node_perf.h b/src/node_perf.h
@@ -21,8 +21,6 @@ class ExternalReferenceRegistry;
 
 namespace performance {
 
-extern const uint64_t timeOrigin;
-
 inline const char* GetPerformanceMilestoneName(
     PerformanceMilestone milestone) {
   switch (milestone) {

diff --git a/src/node_worker.cc b/src/node_worker.cc
@@ -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 {

diff --git a/test/parallel/test-perf-hooks-worker-timeorigin.js b/test/parallel/test-perf-hooks-worker-timeorigin.js
@@ -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);
+}));