src: save the performance milestone time origin in the AliasedArray

Previously we cache the time origin for the milestones in the user
land, and refresh it at pre-execution. As result the time origin
gets serialized into the snapshot and is therefore not deterministic.
Now we store it in the milestone array as an internal value and
reset the milestones at serialization time instead of
deserialization time. This improves the determinism of the snapshot.

Drive-by: remove the unused MarkMilestone() binding.
PR-URL: nodejs#48708
Refs: nodejs/build#3043
Reviewed-By: Yagiz Nizipli <[email protected]>

Author: joyeecheung

lib/internal/perf/utils.js

@@ -1,33 +1,33 @@
 'use strict';
 
-const binding = internalBinding('performance');
 const {
+  constants: {
+    NODE_PERFORMANCE_MILESTONE_TIME_ORIGIN,
+  },
   milestones,
-  getTimeOrigin,
-} = binding;
+} = internalBinding('performance');
 
-// TODO(joyeecheung): we may want to warn about access to
-// this during snapshot building.
-let timeOrigin = getTimeOrigin();
+function getTimeOrigin() {
+  // Do not cache this to prevent it from being serialized into the
+  // snapshot.
+  return milestones[NODE_PERFORMANCE_MILESTONE_TIME_ORIGIN] / 1e6;
+}
 
+// Returns the time relative to the process start time in milliseconds.
 function now() {
   const hr = process.hrtime();
-  return (hr[0] * 1000 + hr[1] / 1e6) - timeOrigin;
+  return (hr[0] * 1000 + hr[1] / 1e6) - getTimeOrigin();
 }
 
+// Returns the milestone relative to the process start time in milliseconds.
 function getMilestoneTimestamp(milestoneIdx) {
   const ns = milestones[milestoneIdx];
   if (ns === -1)
     return ns;
-  return ns / 1e6 - timeOrigin;
-}
-
-function refreshTimeOrigin() {
-  timeOrigin = getTimeOrigin();
+  return ns / 1e6 - getTimeOrigin();
 }
 
 module.exports = {
   now,
   getMilestoneTimestamp,
-  refreshTimeOrigin,
 };

lib/internal/process/pre_execution.js

@@ -68,7 +68,6 @@ function prepareExecution(options) {
   // Patch the process object with legacy properties and normalizations
   patchProcessObject(expandArgv1);
   setupTraceCategoryState();
-  setupPerfHooks();
   setupInspectorHooks();
   setupWarningHandler();
   setupFetch();
@@ -424,10 +423,6 @@ function setupTraceCategoryState() {
   toggleTraceCategoryState(isTraceCategoryEnabled('node.async_hooks'));
 }
 
-function setupPerfHooks() {
-  require('internal/perf/utils').refreshTimeOrigin();
-}
-
 function setupInspectorHooks() {
   // If Debugger.setAsyncCallStackDepth is sent during bootstrap,
   // we cannot immediately call into JS to enable the hooks, which could

src/env.cc

@@ -783,7 +783,7 @@ Environment::Environment(IsolateData* isolate_data,
   destroy_async_id_list_.reserve(512);
 
   performance_state_ = std::make_unique<performance::PerformanceState>(
-      isolate, MAYBE_FIELD_PTR(env_info, performance_state));
+      isolate, time_origin_, MAYBE_FIELD_PTR(env_info, performance_state));
 
   if (*TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(
           TRACING_CATEGORY_NODE1(environment)) != 0) {
@@ -1732,7 +1732,7 @@ void Environment::DeserializeProperties(const EnvSerializeInfo* info) {
   immediate_info_.Deserialize(ctx);
   timeout_info_.Deserialize(ctx);
   tick_info_.Deserialize(ctx);
-  performance_state_->Deserialize(ctx);
+  performance_state_->Deserialize(ctx, time_origin_);
   exit_info_.Deserialize(ctx);
   stream_base_state_.Deserialize(ctx);
   should_abort_on_uncaught_toggle_.Deserialize(ctx);

src/node_perf.cc

@@ -20,7 +20,6 @@ using v8::Function;
 using v8::FunctionCallbackInfo;
 using v8::GCCallbackFlags;
 using v8::GCType;
-using v8::Int32;
 using v8::Integer;
 using v8::Isolate;
 using v8::Local;
@@ -43,6 +42,7 @@ const double performance_process_start_timestamp =
 uint64_t performance_v8_start;
 
 PerformanceState::PerformanceState(Isolate* isolate,
+                                   uint64_t time_origin,
                                    const PerformanceState::SerializeInfo* info)
     : root(isolate,
            sizeof(performance_state_internal),
@@ -58,24 +58,51 @@ PerformanceState::PerformanceState(Isolate* isolate,
                 root,
                 MAYBE_FIELD_PTR(info, observers)) {
   if (info == nullptr) {
-    for (size_t i = 0; i < milestones.Length(); i++) milestones[i] = -1.;
+    // For performance states initialized from scratch, reset
+    // all the milestones and initialize the time origin.
+    // For deserialized performance states, we will do the
+    // initialization in the deserialize callback.
+    ResetMilestones();
+    Initialize(time_origin);
+  }
+}
+
+void PerformanceState::ResetMilestones() {
+  size_t milestones_length = milestones.Length();
+  for (size_t i = 0; i < milestones_length; ++i) {
+    milestones[i] = -1;
   }
 }
 
 PerformanceState::SerializeInfo PerformanceState::Serialize(
     v8::Local<v8::Context> context, v8::SnapshotCreator* creator) {
+  // Reset all the milestones to improve determinism in the snapshot.
+  // We'll re-initialize them after deserialization.
+  ResetMilestones();
+
   SerializeInfo info{root.Serialize(context, creator),
                      milestones.Serialize(context, creator),
                      observers.Serialize(context, creator)};
   return info;
 }
 
-void PerformanceState::Deserialize(v8::Local<v8::Context> context) {
+void PerformanceState::Initialize(uint64_t time_origin) {
+  // We are only reusing the milestone array to store the time origin, so do
+  // not use the Mark() method. The time origin milestone is not exposed
+  // to user land.
+  this->milestones[NODE_PERFORMANCE_MILESTONE_TIME_ORIGIN] =
+      static_cast<double>(time_origin);
+}
+
+void PerformanceState::Deserialize(v8::Local<v8::Context> context,
+                                   uint64_t time_origin) {
+  // Resets the pointers.
   root.Deserialize(context);
-  // This is just done to set up the pointers, we will actually reset
-  // all the milestones after deserialization.
   milestones.Deserialize(context);
   observers.Deserialize(context);
+
+  // Re-initialize the time origin i.e. the process start time.
+  Initialize(time_origin);
 }
 
 std::ostream& operator<<(std::ostream& o,
@@ -96,18 +123,6 @@ void PerformanceState::Mark(PerformanceMilestone milestone, uint64_t ts) {
       TRACE_EVENT_SCOPE_THREAD, ts / 1000);
 }
 
-// Allows specific Node.js lifecycle milestones to be set from JavaScript
-void MarkMilestone(const FunctionCallbackInfo<Value>& args) {
-  Realm* realm = Realm::GetCurrent(args);
-  // TODO(legendecas): Remove this check once the sub-realms are supported.
-  CHECK_EQ(realm->kind(), Realm::Kind::kPrincipal);
-  Environment* env = realm->env();
-  PerformanceMilestone milestone =
-      static_cast<PerformanceMilestone>(args[0].As<Int32>()->Value());
-  if (milestone != NODE_PERFORMANCE_MILESTONE_INVALID)
-    env->performance_state()->Mark(milestone);
-}
-
 void SetupPerformanceObservers(const FunctionCallbackInfo<Value>& args) {
   Realm* realm = Realm::GetCurrent(args);
   // TODO(legendecas): Remove this check once the sub-realms are supported.
@@ -275,12 +290,6 @@ void CreateELDHistogram(const FunctionCallbackInfo<Value>& args) {
   args.GetReturnValue().Set(histogram->object());
 }
 
-void GetTimeOrigin(const FunctionCallbackInfo<Value>& args) {
-  Environment* env = Environment::GetCurrent(args);
-  args.GetReturnValue().Set(
-      Number::New(args.GetIsolate(), env->time_origin() / NANOS_PER_MILLIS));
-}
-
 void GetTimeOriginTimeStamp(const FunctionCallbackInfo<Value>& args) {
   Environment* env = Environment::GetCurrent(args);
   args.GetReturnValue().Set(Number::New(
@@ -300,7 +309,6 @@ static void CreatePerIsolateProperties(IsolateData* isolate_data,
 
   HistogramBase::Initialize(isolate_data, target);
 
-  SetMethod(isolate, target, "markMilestone", MarkMilestone);
   SetMethod(isolate, target, "setupObservers", SetupPerformanceObservers);
   SetMethod(isolate,
             target,
@@ -312,7 +320,6 @@ static void CreatePerIsolateProperties(IsolateData* isolate_data,
             RemoveGarbageCollectionTracking);
   SetMethod(isolate, target, "notify", Notify);
   SetMethod(isolate, target, "loopIdleTime", LoopIdleTime);
-  SetMethod(isolate, target, "getTimeOrigin", GetTimeOrigin);
   SetMethod(isolate, target, "getTimeOriginTimestamp", GetTimeOriginTimeStamp);
   SetMethod(isolate, target, "createELDHistogram", CreateELDHistogram);
   SetMethod(isolate, target, "markBootstrapComplete", MarkBootstrapComplete);
@@ -373,13 +380,11 @@ void CreatePerContextProperties(Local<Object> target,
 }
 
 void RegisterExternalReferences(ExternalReferenceRegistry* registry) {
-  registry->Register(MarkMilestone);
   registry->Register(SetupPerformanceObservers);
   registry->Register(InstallGarbageCollectionTracking);
   registry->Register(RemoveGarbageCollectionTracking);
   registry->Register(Notify);
   registry->Register(LoopIdleTime);
-  registry->Register(GetTimeOrigin);
   registry->Register(GetTimeOriginTimeStamp);
   registry->Register(CreateELDHistogram);
   registry->Register(MarkBootstrapComplete);

src/node_perf_common.h

@@ -24,15 +24,15 @@ extern const uint64_t performance_process_start;
 extern const double performance_process_start_timestamp;
 extern uint64_t performance_v8_start;
 
-#define NODE_PERFORMANCE_MILESTONES(V)                                        \
-  V(ENVIRONMENT, "environment")                                               \
-  V(NODE_START, "nodeStart")                                                  \
-  V(V8_START, "v8Start")                                                      \
-  V(LOOP_START, "loopStart")                                                  \
-  V(LOOP_EXIT, "loopExit")                                                    \
+#define NODE_PERFORMANCE_MILESTONES(V)                                         \
+  V(TIME_ORIGIN, "timeOrigin")                                                 \
+  V(ENVIRONMENT, "environment")                                                \
+  V(NODE_START, "nodeStart")                                                   \
+  V(V8_START, "v8Start")                                                       \
+  V(LOOP_START, "loopStart")                                                   \
+  V(LOOP_EXIT, "loopExit")                                                     \
   V(BOOTSTRAP_COMPLETE, "bootstrapComplete")
 
-
 #define NODE_PERFORMANCE_ENTRY_TYPES(V)                                       \
   V(GC, "gc")                                                                 \
   V(HTTP, "http")                                                             \
@@ -62,10 +62,12 @@ class PerformanceState {
     AliasedBufferIndex observers;
   };
 
-  explicit PerformanceState(v8::Isolate* isolate, const SerializeInfo* info);
+  explicit PerformanceState(v8::Isolate* isolate,
+                            uint64_t time_origin,
+                            const SerializeInfo* info);
   SerializeInfo Serialize(v8::Local<v8::Context> context,
                           v8::SnapshotCreator* creator);
-  void Deserialize(v8::Local<v8::Context> context);
+  void Deserialize(v8::Local<v8::Context> context, uint64_t time_origin);
   friend std::ostream& operator<<(std::ostream& o, const SerializeInfo& i);
 
   AliasedUint8Array root;
@@ -79,6 +81,8 @@ class PerformanceState {
             uint64_t ts = PERFORMANCE_NOW());
 
  private:
+  void Initialize(uint64_t time_origin);
+  void ResetMilestones();
   struct performance_state_internal {
     // doubles first so that they are always sizeof(double)-aligned
     double milestones[NODE_PERFORMANCE_MILESTONE_INVALID];