Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

perf_hooks: performance milestone time origin timestamp improvement #51713

Merged
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
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