Skip to content

Commit

Permalink
src: save the performance milestone time origin in the AliasedArray
Browse files Browse the repository at this point in the history 
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: #48708
Refs: nodejs/build#3043
Reviewed-By: Yagiz Nizipli <yagiz@nizipli.com>
  • Loading branch information
@joyeecheung @RafaelGSS
joyeecheung authored and RafaelGSS committed Aug 15, 2023
1 parent 5dec186 commit ed23426
Show file tree
Hide file tree
Showing 5 changed files with 60 additions and 56 deletions.
26 changes: 13 additions & 13 deletions lib/internal/perf/utils.js
View file
Original file line number Diff line number Diff line change
@@ -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,
};
5 changes: 0 additions & 5 deletions lib/internal/process/pre_execution.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -68,7 +68,6 @@ function prepareExecution(options) {
// Patch the process object with legacy properties and normalizations
patchProcessObject(expandArgv1);
setupTraceCategoryState();
setupPerfHooks();
setupInspectorHooks();
setupWarningHandler();
setupFetch();
Expand Down Expand Up @@ -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
Expand Down
4 changes: 2 additions & 2 deletions src/env.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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) {
Expand Down Expand Up @@ -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);
Expand Down
59 changes: 32 additions & 27 deletions src/node_perf.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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),
Expand All @@ -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,
Expand All @@ -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.
Expand Down Expand Up @@ -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(
Expand All @@ -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,
Expand All @@ -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);
Expand Down Expand Up @@ -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);
Expand Down
22 changes: 13 additions & 9 deletions src/node_perf_common.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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") \
Expand Down Expand Up @@ -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;
Expand All @@ -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];
Expand Down

0 comments on commit ed23426

Please sign in to comment.