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 <yagiz@nizipli.com>
This commit is contained in:
Joyee Cheung 2023-07-21 01:07:41 +02:00 committed by GitHub
parent ac34e7561a
commit 4ee4718857
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
5 changed files with 63 additions and 59 deletions

View File

@ -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 now() {
const hr = process.hrtime();
return (hr[0] * 1000 + hr[1] / 1e6) - timeOrigin;
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) - 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,
};

View File

@ -67,7 +67,6 @@ function prepareExecution(options) {
// Patch the process object with legacy properties and normalizations
patchProcessObject(expandArgv1);
setupTraceCategoryState();
setupPerfHooks();
setupInspectorHooks();
setupWarningHandler();
setupFetch();
@ -423,10 +422,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

View File

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

View File

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

View File

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