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];