From 802f1bd040d4aea6944430a8751d31739eca4e26 Mon Sep 17 00:00:00 2001 From: Joyee Cheung Date: Fri, 21 Jul 2023 01:07:41 +0200 Subject: [PATCH] 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: https://github.com/nodejs/node/pull/48708 Refs: https://github.com/nodejs/build/issues/3043 Reviewed-By: Yagiz Nizipli --- lib/internal/perf/utils.js | 26 ++++++------ lib/internal/process/pre_execution.js | 5 --- src/env.cc | 4 +- src/node_perf.cc | 59 +++++++++++++++------------ src/node_perf_common.h | 22 ++++++---- 5 files changed, 60 insertions(+), 56 deletions(-) diff --git a/lib/internal/perf/utils.js b/lib/internal/perf/utils.js index a92e177e4246e9..a0b7955c70481c 100644 --- a/lib/internal/perf/utils.js +++ b/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, }; diff --git a/lib/internal/process/pre_execution.js b/lib/internal/process/pre_execution.js index a14a441fe3a4d9..23b51de93858c6 100644 --- a/lib/internal/process/pre_execution.js +++ b/lib/internal/process/pre_execution.js @@ -75,7 +75,6 @@ function prepareExecution(options) { // Patch the process object with legacy properties and normalizations patchProcessObject(expandArgv1); setupTraceCategoryState(); - setupPerfHooks(); setupInspectorHooks(); setupWarningHandler(); setupFetch(); @@ -433,10 +432,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 diff --git a/src/env.cc b/src/env.cc index 64b8fa6e34cc28..ab9c7aa75af488 100644 --- a/src/env.cc +++ b/src/env.cc @@ -783,7 +783,7 @@ Environment::Environment(IsolateData* isolate_data, destroy_async_id_list_.reserve(512); performance_state_ = std::make_unique( - 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); diff --git a/src/node_perf.cc b/src/node_perf.cc index 555a90b0a76091..1acaa9dfe47145 100644 --- a/src/node_perf.cc +++ b/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 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 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(time_origin); +} + +void PerformanceState::Deserialize(v8::Local 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& 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(args[0].As()->Value()); - if (milestone != NODE_PERFORMANCE_MILESTONE_INVALID) - env->performance_state()->Mark(milestone); -} - void SetupPerformanceObservers(const FunctionCallbackInfo& 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& args) { args.GetReturnValue().Set(histogram->object()); } -void GetTimeOrigin(const FunctionCallbackInfo& args) { - Environment* env = Environment::GetCurrent(args); - args.GetReturnValue().Set( - Number::New(args.GetIsolate(), env->time_origin() / NANOS_PER_MILLIS)); -} - void GetTimeOriginTimeStamp(const FunctionCallbackInfo& 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 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); diff --git a/src/node_perf_common.h b/src/node_perf_common.h index d519222616a174..dd757651c09e9f 100644 --- a/src/node_perf_common.h +++ b/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 context, v8::SnapshotCreator* creator); - void Deserialize(v8::Local context); + void Deserialize(v8::Local 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];