Skip to content

Commit

Permalink
perf_hooks: performance milestone time origin timestamp improvement
Browse files Browse the repository at this point in the history
PR-URL: nodejs#51713
Reviewed-By: Vinícius Lourenço Claro Cardoso <contact@viniciusl.com.br>
Reviewed-By: Yagiz Nizipli <yagiz.nizipli@sentry.io>
Reviewed-By: Marco Ippolito <marcoippolito54@gmail.com>
Reviewed-By: Minwoo Jung <nodecorelab@gmail.com>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com>
  • Loading branch information
IlyasShabi authored and rdw-msft committed Mar 26, 2024
1 parent 782a7ed commit a46247d
Show file tree
Hide file tree
Showing 6 changed files with 77 additions and 27 deletions.
45 changes: 45 additions & 0 deletions benchmark/perf_hooks/time-origin.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,45 @@
'use strict';

const assert = require('assert');
const common = require('../common.js');

const bench = common.createBenchmark(main, {
n: [1e6],
method: ['timeOrigin', 'toJSON'],
});

function main({ method, n }) {
switch (method) {
case 'timeOrigin':
benchTimeOrigin(n);
break;
case 'toJSON':
benchToJSON(n);
break;
default:
throw new Error(`Unsupported method ${method}`);
}
}

function benchTimeOrigin(n) {
const arr = [];
for (let i = 0; i < n; ++i) {
arr.push(performance.timeOrigin);
}

bench.start();
for (let i = 0; i < n; i++) {
arr[i] = performance.timeOrigin;
}
bench.end(n);

assert.strictEqual(arr.length, n);
}

function benchToJSON(n) {
bench.start();
for (let i = 0; i < n; i++) {
performance.toJSON();
}
bench.end(n);
}
6 changes: 1 addition & 5 deletions lib/internal/perf/performance.js
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@ const {
defineEventHandler,
} = require('internal/event_target');

const { now } = require('internal/perf/utils');
const { now, getTimeOriginTimestamp } = require('internal/perf/utils');

const { markResourceTiming } = require('internal/perf/resource_timing');

Expand All @@ -46,10 +46,6 @@ const { inspect } = require('util');
const { validateInternalField } = require('internal/validators');
const { convertToInt } = require('internal/webidl');

const {
getTimeOriginTimestamp,
} = internalBinding('performance');

const kPerformanceBrand = Symbol('performance');

class Performance extends EventTarget {
Expand Down
6 changes: 6 additions & 0 deletions lib/internal/perf/utils.js
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@
const {
constants: {
NODE_PERFORMANCE_MILESTONE_TIME_ORIGIN,
NODE_PERFORMANCE_MILESTONE_TIME_ORIGIN_TIMESTAMP,
},
milestones,
now,
Expand All @@ -22,7 +23,12 @@ function getMilestoneTimestamp(milestoneIdx) {
return ns / 1e6 - getTimeOrigin();
}

function getTimeOriginTimestamp() {
return milestones[NODE_PERFORMANCE_MILESTONE_TIME_ORIGIN_TIMESTAMP] / 1e3;
}

module.exports = {
now,
getMilestoneTimestamp,
getTimeOriginTimestamp,
};
7 changes: 5 additions & 2 deletions src/env.cc
Original file line number Diff line number Diff line change
Expand Up @@ -880,7 +880,10 @@ Environment::Environment(IsolateData* isolate_data,
destroy_async_id_list_.reserve(512);

performance_state_ = std::make_unique<performance::PerformanceState>(
isolate, time_origin_, MAYBE_FIELD_PTR(env_info, performance_state));
isolate,
time_origin_,
time_origin_timestamp_,
MAYBE_FIELD_PTR(env_info, performance_state));

if (*TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(
TRACING_CATEGORY_NODE1(environment)) != 0) {
Expand Down Expand Up @@ -1837,7 +1840,7 @@ void Environment::DeserializeProperties(const EnvSerializeInfo* info) {
immediate_info_.Deserialize(ctx);
timeout_info_.Deserialize(ctx);
tick_info_.Deserialize(ctx);
performance_state_->Deserialize(ctx, time_origin_);
performance_state_->Deserialize(ctx, time_origin_, time_origin_timestamp_);
exit_info_.Deserialize(ctx);
stream_base_state_.Deserialize(ctx);
should_abort_on_uncaught_toggle_.Deserialize(ctx);
Expand Down
32 changes: 14 additions & 18 deletions src/node_perf.cc
Original file line number Diff line number Diff line change
Expand Up @@ -24,7 +24,6 @@ using v8::Integer;
using v8::Isolate;
using v8::Local;
using v8::MaybeLocal;
using v8::Number;
using v8::Object;
using v8::ObjectTemplate;
using v8::PropertyAttribute;
Expand All @@ -43,6 +42,7 @@ uint64_t performance_v8_start;

PerformanceState::PerformanceState(Isolate* isolate,
uint64_t time_origin,
double time_origin_timestamp,
const PerformanceState::SerializeInfo* info)
: root(isolate,
sizeof(performance_state_internal),
Expand All @@ -63,7 +63,7 @@ PerformanceState::PerformanceState(Isolate* isolate,
// For deserialized performance states, we will do the
// initialization in the deserialize callback.
ResetMilestones();
Initialize(time_origin);
Initialize(time_origin, time_origin_timestamp);
}
}

Expand All @@ -86,23 +86,27 @@ PerformanceState::SerializeInfo PerformanceState::Serialize(
return info;
}

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.
void PerformanceState::Initialize(uint64_t time_origin,
double time_origin_timestamp) {
// We are only reusing the milestone array to store the time origin
// and time origin timestamp, 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);
this->milestones[NODE_PERFORMANCE_MILESTONE_TIME_ORIGIN_TIMESTAMP] =
time_origin_timestamp;
}

void PerformanceState::Deserialize(v8::Local<v8::Context> context,
uint64_t time_origin) {
uint64_t time_origin,
double time_origin_timestamp) {
// Resets the pointers.
root.Deserialize(context);
milestones.Deserialize(context);
observers.Deserialize(context);

// Re-initialize the time origin i.e. the process start time.
Initialize(time_origin);
// Re-initialize the time origin and timestamp i.e. the process start time.
Initialize(time_origin, time_origin_timestamp);
}

std::ostream& operator<<(std::ostream& o,
Expand Down Expand Up @@ -254,7 +258,7 @@ void Notify(const FunctionCallbackInfo<Value>& args) {
void LoopIdleTime(const FunctionCallbackInfo<Value>& args) {
Environment* env = Environment::GetCurrent(args);
uint64_t idle_time = uv_metrics_idle_time(env->event_loop());
args.GetReturnValue().Set(1.0 * idle_time / 1e6);
args.GetReturnValue().Set(1.0 * idle_time / NANOS_PER_MILLIS);
}

void CreateELDHistogram(const FunctionCallbackInfo<Value>& args) {
Expand All @@ -278,12 +282,6 @@ void CreateELDHistogram(const FunctionCallbackInfo<Value>& args) {
args.GetReturnValue().Set(histogram->object());
}

void GetTimeOriginTimeStamp(const FunctionCallbackInfo<Value>& args) {
Environment* env = Environment::GetCurrent(args);
args.GetReturnValue().Set(Number::New(
args.GetIsolate(), env->time_origin_timestamp() / MICROS_PER_MILLIS));
}

void MarkBootstrapComplete(const FunctionCallbackInfo<Value>& args) {
Realm* realm = Realm::GetCurrent(args);
CHECK_EQ(realm->kind(), Realm::Kind::kPrincipal);
Expand Down Expand Up @@ -324,7 +322,6 @@ static void CreatePerIsolateProperties(IsolateData* isolate_data,
RemoveGarbageCollectionTracking);
SetMethod(isolate, target, "notify", Notify);
SetMethod(isolate, target, "loopIdleTime", LoopIdleTime);
SetMethod(isolate, target, "getTimeOriginTimestamp", GetTimeOriginTimeStamp);
SetMethod(isolate, target, "createELDHistogram", CreateELDHistogram);
SetMethod(isolate, target, "markBootstrapComplete", MarkBootstrapComplete);
SetFastMethodNoSideEffect(
Expand Down Expand Up @@ -391,7 +388,6 @@ void RegisterExternalReferences(ExternalReferenceRegistry* registry) {
registry->Register(RemoveGarbageCollectionTracking);
registry->Register(Notify);
registry->Register(LoopIdleTime);
registry->Register(GetTimeOriginTimeStamp);
registry->Register(CreateELDHistogram);
registry->Register(MarkBootstrapComplete);
registry->Register(SlowPerformanceNow);
Expand Down
8 changes: 6 additions & 2 deletions src/node_perf_common.h
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@ extern const double performance_process_start_timestamp;
extern uint64_t performance_v8_start;

#define NODE_PERFORMANCE_MILESTONES(V) \
V(TIME_ORIGIN_TIMESTAMP, "timeOriginTimestamp") \
V(TIME_ORIGIN, "timeOrigin") \
V(ENVIRONMENT, "environment") \
V(NODE_START, "nodeStart") \
Expand Down Expand Up @@ -64,10 +65,13 @@ class PerformanceState {

explicit PerformanceState(v8::Isolate* isolate,
uint64_t time_origin,
double time_origin_timestamp,
const SerializeInfo* info);
SerializeInfo Serialize(v8::Local<v8::Context> context,
v8::SnapshotCreator* creator);
void Deserialize(v8::Local<v8::Context> context, uint64_t time_origin);
void Deserialize(v8::Local<v8::Context> context,
uint64_t time_origin,
double time_origin_timestamp);
friend std::ostream& operator<<(std::ostream& o, const SerializeInfo& i);

AliasedUint8Array root;
Expand All @@ -81,7 +85,7 @@ class PerformanceState {
uint64_t ts = PERFORMANCE_NOW());

private:
void Initialize(uint64_t time_origin);
void Initialize(uint64_t time_origin, double time_origin_timestamp);
void ResetMilestones();
struct performance_state_internal {
// doubles first so that they are always sizeof(double)-aligned
Expand Down

0 comments on commit a46247d

Please sign in to comment.