1 #include "node_perf.h"
2 #include "aliased_buffer.h"
3 #include "env-inl.h"
4 #include "histogram-inl.h"
5 #include "memory_tracker-inl.h"
6 #include "node_buffer.h"
7 #include "node_external_reference.h"
8 #include "node_internals.h"
9 #include "node_process-inl.h"
10 #include "util-inl.h"
11
12 #include <cinttypes>
13
14 namespace node {
15 namespace performance {
16
17 using v8::Context;
18 using v8::DontDelete;
19 using v8::Function;
20 using v8::FunctionCallbackInfo;
21 using v8::FunctionTemplate;
22 using v8::GCCallbackFlags;
23 using v8::GCType;
24 using v8::Int32;
25 using v8::Integer;
26 using v8::Isolate;
27 using v8::Local;
28 using v8::MaybeLocal;
29 using v8::Number;
30 using v8::Object;
31 using v8::PropertyAttribute;
32 using v8::ReadOnly;
33 using v8::String;
34 using v8::Value;
35
36 // Microseconds in a millisecond, as a float.
37 #define MICROS_PER_MILLIS 1e3
38
39 // https://w3c.github.io/hr-time/#dfn-time-origin
40 const uint64_t timeOrigin = PERFORMANCE_NOW();
41 // https://w3c.github.io/hr-time/#dfn-time-origin-timestamp
42 const double timeOriginTimestamp = GetCurrentTimeInMicroseconds();
43 uint64_t performance_v8_start;
44
PerformanceState(Isolate * isolate,const PerformanceState::SerializeInfo * info)45 PerformanceState::PerformanceState(Isolate* isolate,
46 const PerformanceState::SerializeInfo* info)
47 : root(isolate,
48 sizeof(performance_state_internal),
49 MAYBE_FIELD_PTR(info, root)),
50 milestones(isolate,
51 offsetof(performance_state_internal, milestones),
52 NODE_PERFORMANCE_MILESTONE_INVALID,
53 root,
54 MAYBE_FIELD_PTR(info, milestones)),
55 observers(isolate,
56 offsetof(performance_state_internal, observers),
57 NODE_PERFORMANCE_ENTRY_TYPE_INVALID,
58 root,
59 MAYBE_FIELD_PTR(info, observers)) {
60 if (info == nullptr) {
61 for (size_t i = 0; i < milestones.Length(); i++) milestones[i] = -1.;
62 }
63 }
64
Serialize(v8::Local<v8::Context> context,v8::SnapshotCreator * creator)65 PerformanceState::SerializeInfo PerformanceState::Serialize(
66 v8::Local<v8::Context> context, v8::SnapshotCreator* creator) {
67 SerializeInfo info{root.Serialize(context, creator),
68 milestones.Serialize(context, creator),
69 observers.Serialize(context, creator)};
70 return info;
71 }
72
Deserialize(v8::Local<v8::Context> context)73 void PerformanceState::Deserialize(v8::Local<v8::Context> context) {
74 root.Deserialize(context);
75 // This is just done to set up the pointers, we will actually reset
76 // all the milestones after deserialization.
77 milestones.Deserialize(context);
78 observers.Deserialize(context);
79 }
80
operator <<(std::ostream & o,const PerformanceState::SerializeInfo & i)81 std::ostream& operator<<(std::ostream& o,
82 const PerformanceState::SerializeInfo& i) {
83 o << "{\n"
84 << " " << i.root << ", // root\n"
85 << " " << i.milestones << ", // milestones\n"
86 << " " << i.observers << ", // observers\n"
87 << "}";
88 return o;
89 }
90
Mark(PerformanceMilestone milestone,uint64_t ts)91 void PerformanceState::Mark(PerformanceMilestone milestone, uint64_t ts) {
92 this->milestones[milestone] = static_cast<double>(ts);
93 TRACE_EVENT_INSTANT_WITH_TIMESTAMP0(
94 TRACING_CATEGORY_NODE1(bootstrap),
95 GetPerformanceMilestoneName(milestone),
96 TRACE_EVENT_SCOPE_THREAD, ts / 1000);
97 }
98
99 // Allows specific Node.js lifecycle milestones to be set from JavaScript
MarkMilestone(const FunctionCallbackInfo<Value> & args)100 void MarkMilestone(const FunctionCallbackInfo<Value>& args) {
101 Environment* env = Environment::GetCurrent(args);
102 PerformanceMilestone milestone =
103 static_cast<PerformanceMilestone>(args[0].As<Int32>()->Value());
104 if (milestone != NODE_PERFORMANCE_MILESTONE_INVALID)
105 env->performance_state()->Mark(milestone);
106 }
107
SetupPerformanceObservers(const FunctionCallbackInfo<Value> & args)108 void SetupPerformanceObservers(const FunctionCallbackInfo<Value>& args) {
109 Environment* env = Environment::GetCurrent(args);
110 CHECK(args[0]->IsFunction());
111 env->set_performance_entry_callback(args[0].As<Function>());
112 }
113
114 // Marks the start of a GC cycle
MarkGarbageCollectionStart(Isolate * isolate,GCType type,GCCallbackFlags flags,void * data)115 void MarkGarbageCollectionStart(
116 Isolate* isolate,
117 GCType type,
118 GCCallbackFlags flags,
119 void* data) {
120 Environment* env = static_cast<Environment*>(data);
121 // Prevent gc callback from reentering with different type
122 // See https://github.com/nodejs/node/issues/44046
123 if (env->performance_state()->current_gc_type != 0) {
124 return;
125 }
126 env->performance_state()->performance_last_gc_start_mark = PERFORMANCE_NOW();
127 env->performance_state()->current_gc_type = type;
128 }
129
GetDetails(Environment * env,const GCPerformanceEntry & entry)130 MaybeLocal<Object> GCPerformanceEntryTraits::GetDetails(
131 Environment* env,
132 const GCPerformanceEntry& entry) {
133 Local<Object> obj = Object::New(env->isolate());
134
135 if (!obj->Set(
136 env->context(),
137 env->kind_string(),
138 Integer::NewFromUnsigned(
139 env->isolate(),
140 entry.details.kind)).IsJust()) {
141 return MaybeLocal<Object>();
142 }
143
144 if (!obj->Set(
145 env->context(),
146 env->flags_string(),
147 Integer::NewFromUnsigned(
148 env->isolate(),
149 entry.details.flags)).IsJust()) {
150 return MaybeLocal<Object>();
151 }
152
153 return obj;
154 }
155
156 // Marks the end of a GC cycle
MarkGarbageCollectionEnd(Isolate * isolate,GCType type,GCCallbackFlags flags,void * data)157 void MarkGarbageCollectionEnd(
158 Isolate* isolate,
159 GCType type,
160 GCCallbackFlags flags,
161 void* data) {
162 Environment* env = static_cast<Environment*>(data);
163 PerformanceState* state = env->performance_state();
164 if (type != state->current_gc_type) {
165 return;
166 }
167 env->performance_state()->current_gc_type = 0;
168 // If no one is listening to gc performance entries, do not create them.
169 if (LIKELY(!state->observers[NODE_PERFORMANCE_ENTRY_TYPE_GC]))
170 return;
171
172 double start_time =
173 (state->performance_last_gc_start_mark - timeOrigin) / 1e6;
174 double duration =
175 (PERFORMANCE_NOW() / 1e6) - (state->performance_last_gc_start_mark / 1e6);
176
177 std::unique_ptr<GCPerformanceEntry> entry =
178 std::make_unique<GCPerformanceEntry>(
179 "gc",
180 start_time,
181 duration,
182 GCPerformanceEntry::Details(static_cast<PerformanceGCKind>(type),
183 static_cast<PerformanceGCFlags>(flags)));
184
185 env->SetImmediate([entry = std::move(entry)](Environment* env) {
186 entry->Notify(env);
187 }, CallbackFlags::kUnrefed);
188 }
189
GarbageCollectionCleanupHook(void * data)190 void GarbageCollectionCleanupHook(void* data) {
191 Environment* env = static_cast<Environment*>(data);
192 // Reset current_gc_type to 0
193 env->performance_state()->current_gc_type = 0;
194 env->isolate()->RemoveGCPrologueCallback(MarkGarbageCollectionStart, data);
195 env->isolate()->RemoveGCEpilogueCallback(MarkGarbageCollectionEnd, data);
196 }
197
InstallGarbageCollectionTracking(const FunctionCallbackInfo<Value> & args)198 static void InstallGarbageCollectionTracking(
199 const FunctionCallbackInfo<Value>& args) {
200 Environment* env = Environment::GetCurrent(args);
201 // Reset current_gc_type to 0
202 env->performance_state()->current_gc_type = 0;
203 env->isolate()->AddGCPrologueCallback(MarkGarbageCollectionStart,
204 static_cast<void*>(env));
205 env->isolate()->AddGCEpilogueCallback(MarkGarbageCollectionEnd,
206 static_cast<void*>(env));
207 env->AddCleanupHook(GarbageCollectionCleanupHook, env);
208 }
209
RemoveGarbageCollectionTracking(const FunctionCallbackInfo<Value> & args)210 static void RemoveGarbageCollectionTracking(
211 const FunctionCallbackInfo<Value> &args) {
212 Environment* env = Environment::GetCurrent(args);
213
214 env->RemoveCleanupHook(GarbageCollectionCleanupHook, env);
215 GarbageCollectionCleanupHook(env);
216 }
217
218 // Gets the name of a function
GetName(Local<Function> fn)219 inline Local<Value> GetName(Local<Function> fn) {
220 Local<Value> val = fn->GetDebugName();
221 if (val.IsEmpty() || val->IsUndefined()) {
222 Local<Value> boundFunction = fn->GetBoundFunction();
223 if (!boundFunction.IsEmpty() && !boundFunction->IsUndefined()) {
224 val = GetName(boundFunction.As<Function>());
225 }
226 }
227 return val;
228 }
229
230 // Notify a custom PerformanceEntry to observers
Notify(const FunctionCallbackInfo<Value> & args)231 void Notify(const FunctionCallbackInfo<Value>& args) {
232 Environment* env = Environment::GetCurrent(args);
233 Utf8Value type(env->isolate(), args[0]);
234 Local<Value> entry = args[1];
235 PerformanceEntryType entry_type = ToPerformanceEntryTypeEnum(*type);
236 AliasedUint32Array& observers = env->performance_state()->observers;
237 if (entry_type != NODE_PERFORMANCE_ENTRY_TYPE_INVALID &&
238 observers[entry_type]) {
239 USE(env->performance_entry_callback()->
240 Call(env->context(), Undefined(env->isolate()), 1, &entry));
241 }
242 }
243
244 // Return idle time of the event loop
LoopIdleTime(const FunctionCallbackInfo<Value> & args)245 void LoopIdleTime(const FunctionCallbackInfo<Value>& args) {
246 Environment* env = Environment::GetCurrent(args);
247 uint64_t idle_time = uv_metrics_idle_time(env->event_loop());
248 args.GetReturnValue().Set(1.0 * idle_time / 1e6);
249 }
250
CreateELDHistogram(const FunctionCallbackInfo<Value> & args)251 void CreateELDHistogram(const FunctionCallbackInfo<Value>& args) {
252 Environment* env = Environment::GetCurrent(args);
253 int64_t interval = args[0].As<Integer>()->Value();
254 CHECK_GT(interval, 0);
255 BaseObjectPtr<IntervalHistogram> histogram =
256 IntervalHistogram::Create(env, interval, [](Histogram& histogram) {
257 uint64_t delta = histogram.RecordDelta();
258 TRACE_COUNTER1(TRACING_CATEGORY_NODE2(perf, event_loop),
259 "delay", delta);
260 TRACE_COUNTER1(TRACING_CATEGORY_NODE2(perf, event_loop),
261 "min", histogram.Min());
262 TRACE_COUNTER1(TRACING_CATEGORY_NODE2(perf, event_loop),
263 "max", histogram.Max());
264 TRACE_COUNTER1(TRACING_CATEGORY_NODE2(perf, event_loop),
265 "mean", histogram.Mean());
266 TRACE_COUNTER1(TRACING_CATEGORY_NODE2(perf, event_loop),
267 "stddev", histogram.Stddev());
268 }, Histogram::Options { 1000 });
269 args.GetReturnValue().Set(histogram->object());
270 }
271
GetTimeOrigin(const FunctionCallbackInfo<Value> & args)272 void GetTimeOrigin(const FunctionCallbackInfo<Value>& args) {
273 args.GetReturnValue().Set(Number::New(args.GetIsolate(), timeOrigin / 1e6));
274 }
275
GetTimeOriginTimeStamp(const FunctionCallbackInfo<Value> & args)276 void GetTimeOriginTimeStamp(const FunctionCallbackInfo<Value>& args) {
277 args.GetReturnValue().Set(
278 Number::New(args.GetIsolate(), timeOriginTimestamp / MICROS_PER_MILLIS));
279 }
280
MarkBootstrapComplete(const FunctionCallbackInfo<Value> & args)281 void MarkBootstrapComplete(const FunctionCallbackInfo<Value>& args) {
282 Environment* env = Environment::GetCurrent(args);
283 env->performance_state()->Mark(
284 performance::NODE_PERFORMANCE_MILESTONE_BOOTSTRAP_COMPLETE);
285 }
286
Initialize(Local<Object> target,Local<Value> unused,Local<Context> context,void * priv)287 void Initialize(Local<Object> target,
288 Local<Value> unused,
289 Local<Context> context,
290 void* priv) {
291 Environment* env = Environment::GetCurrent(context);
292 Isolate* isolate = env->isolate();
293 PerformanceState* state = env->performance_state();
294
295 target->Set(context,
296 FIXED_ONE_BYTE_STRING(isolate, "observerCounts"),
297 state->observers.GetJSArray()).Check();
298 target->Set(context,
299 FIXED_ONE_BYTE_STRING(isolate, "milestones"),
300 state->milestones.GetJSArray()).Check();
301
302 Local<String> performanceEntryString =
303 FIXED_ONE_BYTE_STRING(isolate, "PerformanceEntry");
304
305 Local<FunctionTemplate> pe = FunctionTemplate::New(isolate);
306 pe->SetClassName(performanceEntryString);
307 Local<Function> fn = pe->GetFunction(context).ToLocalChecked();
308 target->Set(context, performanceEntryString, fn).Check();
309 env->set_performance_entry_template(fn);
310
311 SetMethod(context, target, "markMilestone", MarkMilestone);
312 SetMethod(context, target, "setupObservers", SetupPerformanceObservers);
313 SetMethod(context,
314 target,
315 "installGarbageCollectionTracking",
316 InstallGarbageCollectionTracking);
317 SetMethod(context,
318 target,
319 "removeGarbageCollectionTracking",
320 RemoveGarbageCollectionTracking);
321 SetMethod(context, target, "notify", Notify);
322 SetMethod(context, target, "loopIdleTime", LoopIdleTime);
323 SetMethod(context, target, "getTimeOrigin", GetTimeOrigin);
324 SetMethod(context, target, "getTimeOriginTimestamp", GetTimeOriginTimeStamp);
325 SetMethod(context, target, "createELDHistogram", CreateELDHistogram);
326 SetMethod(context, target, "markBootstrapComplete", MarkBootstrapComplete);
327
328 Local<Object> constants = Object::New(isolate);
329
330 NODE_DEFINE_CONSTANT(constants, NODE_PERFORMANCE_GC_MAJOR);
331 NODE_DEFINE_CONSTANT(constants, NODE_PERFORMANCE_GC_MINOR);
332 NODE_DEFINE_CONSTANT(constants, NODE_PERFORMANCE_GC_INCREMENTAL);
333 NODE_DEFINE_CONSTANT(constants, NODE_PERFORMANCE_GC_WEAKCB);
334
335 NODE_DEFINE_CONSTANT(
336 constants, NODE_PERFORMANCE_GC_FLAGS_NO);
337 NODE_DEFINE_CONSTANT(
338 constants, NODE_PERFORMANCE_GC_FLAGS_CONSTRUCT_RETAINED);
339 NODE_DEFINE_CONSTANT(
340 constants, NODE_PERFORMANCE_GC_FLAGS_FORCED);
341 NODE_DEFINE_CONSTANT(
342 constants, NODE_PERFORMANCE_GC_FLAGS_SYNCHRONOUS_PHANTOM_PROCESSING);
343 NODE_DEFINE_CONSTANT(
344 constants, NODE_PERFORMANCE_GC_FLAGS_ALL_AVAILABLE_GARBAGE);
345 NODE_DEFINE_CONSTANT(
346 constants, NODE_PERFORMANCE_GC_FLAGS_ALL_EXTERNAL_MEMORY);
347 NODE_DEFINE_CONSTANT(
348 constants, NODE_PERFORMANCE_GC_FLAGS_SCHEDULE_IDLE);
349
350 #define V(name, _) \
351 NODE_DEFINE_HIDDEN_CONSTANT(constants, NODE_PERFORMANCE_ENTRY_TYPE_##name);
352 NODE_PERFORMANCE_ENTRY_TYPES(V)
353 #undef V
354
355 #define V(name, _) \
356 NODE_DEFINE_HIDDEN_CONSTANT(constants, NODE_PERFORMANCE_MILESTONE_##name);
357 NODE_PERFORMANCE_MILESTONES(V)
358 #undef V
359
360 PropertyAttribute attr =
361 static_cast<PropertyAttribute>(ReadOnly | DontDelete);
362
363 target->DefineOwnProperty(context,
364 env->constants_string(),
365 constants,
366 attr).ToChecked();
367
368 HistogramBase::Initialize(env, target);
369 }
370
RegisterExternalReferences(ExternalReferenceRegistry * registry)371 void RegisterExternalReferences(ExternalReferenceRegistry* registry) {
372 registry->Register(MarkMilestone);
373 registry->Register(SetupPerformanceObservers);
374 registry->Register(InstallGarbageCollectionTracking);
375 registry->Register(RemoveGarbageCollectionTracking);
376 registry->Register(Notify);
377 registry->Register(LoopIdleTime);
378 registry->Register(GetTimeOrigin);
379 registry->Register(GetTimeOriginTimeStamp);
380 registry->Register(CreateELDHistogram);
381 registry->Register(MarkBootstrapComplete);
382 HistogramBase::RegisterExternalReferences(registry);
383 IntervalHistogram::RegisterExternalReferences(registry);
384 }
385 } // namespace performance
386 } // namespace node
387
388 NODE_BINDING_CONTEXT_AWARE_INTERNAL(performance, node::performance::Initialize)
389 NODE_BINDING_EXTERNAL_REFERENCE(performance,
390 node::performance::RegisterExternalReferences)
391