1 #include "node_perf.h"
2 #include "aliased_buffer-inl.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 // Notify a custom PerformanceEntry to observers
Notify(const FunctionCallbackInfo<Value> & args)219 void Notify(const FunctionCallbackInfo<Value>& args) {
220 Environment* env = Environment::GetCurrent(args);
221 Utf8Value type(env->isolate(), args[0]);
222 Local<Value> entry = args[1];
223 PerformanceEntryType entry_type = ToPerformanceEntryTypeEnum(*type);
224 AliasedUint32Array& observers = env->performance_state()->observers;
225 if (entry_type != NODE_PERFORMANCE_ENTRY_TYPE_INVALID &&
226 observers[entry_type]) {
227 USE(env->performance_entry_callback()->
228 Call(env->context(), Undefined(env->isolate()), 1, &entry));
229 }
230 }
231
232 // Return idle time of the event loop
LoopIdleTime(const FunctionCallbackInfo<Value> & args)233 void LoopIdleTime(const FunctionCallbackInfo<Value>& args) {
234 Environment* env = Environment::GetCurrent(args);
235 uint64_t idle_time = uv_metrics_idle_time(env->event_loop());
236 args.GetReturnValue().Set(1.0 * idle_time / 1e6);
237 }
238
CreateELDHistogram(const FunctionCallbackInfo<Value> & args)239 void CreateELDHistogram(const FunctionCallbackInfo<Value>& args) {
240 Environment* env = Environment::GetCurrent(args);
241 int64_t interval = args[0].As<Integer>()->Value();
242 CHECK_GT(interval, 0);
243 BaseObjectPtr<IntervalHistogram> histogram =
244 IntervalHistogram::Create(env, interval, [](Histogram& histogram) {
245 uint64_t delta = histogram.RecordDelta();
246 TRACE_COUNTER1(TRACING_CATEGORY_NODE2(perf, event_loop),
247 "delay", delta);
248 TRACE_COUNTER1(TRACING_CATEGORY_NODE2(perf, event_loop),
249 "min", histogram.Min());
250 TRACE_COUNTER1(TRACING_CATEGORY_NODE2(perf, event_loop),
251 "max", histogram.Max());
252 TRACE_COUNTER1(TRACING_CATEGORY_NODE2(perf, event_loop),
253 "mean", histogram.Mean());
254 TRACE_COUNTER1(TRACING_CATEGORY_NODE2(perf, event_loop),
255 "stddev", histogram.Stddev());
256 }, Histogram::Options { 1000 });
257 args.GetReturnValue().Set(histogram->object());
258 }
259
GetTimeOrigin(const FunctionCallbackInfo<Value> & args)260 void GetTimeOrigin(const FunctionCallbackInfo<Value>& args) {
261 args.GetReturnValue().Set(Number::New(args.GetIsolate(), timeOrigin / 1e6));
262 }
263
GetTimeOriginTimeStamp(const FunctionCallbackInfo<Value> & args)264 void GetTimeOriginTimeStamp(const FunctionCallbackInfo<Value>& args) {
265 args.GetReturnValue().Set(
266 Number::New(args.GetIsolate(), timeOriginTimestamp / MICROS_PER_MILLIS));
267 }
268
MarkBootstrapComplete(const FunctionCallbackInfo<Value> & args)269 void MarkBootstrapComplete(const FunctionCallbackInfo<Value>& args) {
270 Environment* env = Environment::GetCurrent(args);
271 env->performance_state()->Mark(
272 performance::NODE_PERFORMANCE_MILESTONE_BOOTSTRAP_COMPLETE);
273 }
274
Initialize(Local<Object> target,Local<Value> unused,Local<Context> context,void * priv)275 void Initialize(Local<Object> target,
276 Local<Value> unused,
277 Local<Context> context,
278 void* priv) {
279 Environment* env = Environment::GetCurrent(context);
280 Isolate* isolate = env->isolate();
281 PerformanceState* state = env->performance_state();
282
283 target->Set(context,
284 FIXED_ONE_BYTE_STRING(isolate, "observerCounts"),
285 state->observers.GetJSArray()).Check();
286 target->Set(context,
287 FIXED_ONE_BYTE_STRING(isolate, "milestones"),
288 state->milestones.GetJSArray()).Check();
289
290 Local<String> performanceEntryString =
291 FIXED_ONE_BYTE_STRING(isolate, "PerformanceEntry");
292
293 Local<FunctionTemplate> pe = FunctionTemplate::New(isolate);
294 pe->SetClassName(performanceEntryString);
295 Local<Function> fn = pe->GetFunction(context).ToLocalChecked();
296 target->Set(context, performanceEntryString, fn).Check();
297 env->set_performance_entry_template(fn);
298
299 SetMethod(context, target, "markMilestone", MarkMilestone);
300 SetMethod(context, target, "setupObservers", SetupPerformanceObservers);
301 SetMethod(context,
302 target,
303 "installGarbageCollectionTracking",
304 InstallGarbageCollectionTracking);
305 SetMethod(context,
306 target,
307 "removeGarbageCollectionTracking",
308 RemoveGarbageCollectionTracking);
309 SetMethod(context, target, "notify", Notify);
310 SetMethod(context, target, "loopIdleTime", LoopIdleTime);
311 SetMethod(context, target, "getTimeOrigin", GetTimeOrigin);
312 SetMethod(context, target, "getTimeOriginTimestamp", GetTimeOriginTimeStamp);
313 SetMethod(context, target, "createELDHistogram", CreateELDHistogram);
314 SetMethod(context, target, "markBootstrapComplete", MarkBootstrapComplete);
315
316 Local<Object> constants = Object::New(isolate);
317
318 NODE_DEFINE_CONSTANT(constants, NODE_PERFORMANCE_GC_MAJOR);
319 NODE_DEFINE_CONSTANT(constants, NODE_PERFORMANCE_GC_MINOR);
320 NODE_DEFINE_CONSTANT(constants, NODE_PERFORMANCE_GC_INCREMENTAL);
321 NODE_DEFINE_CONSTANT(constants, NODE_PERFORMANCE_GC_WEAKCB);
322
323 NODE_DEFINE_CONSTANT(
324 constants, NODE_PERFORMANCE_GC_FLAGS_NO);
325 NODE_DEFINE_CONSTANT(
326 constants, NODE_PERFORMANCE_GC_FLAGS_CONSTRUCT_RETAINED);
327 NODE_DEFINE_CONSTANT(
328 constants, NODE_PERFORMANCE_GC_FLAGS_FORCED);
329 NODE_DEFINE_CONSTANT(
330 constants, NODE_PERFORMANCE_GC_FLAGS_SYNCHRONOUS_PHANTOM_PROCESSING);
331 NODE_DEFINE_CONSTANT(
332 constants, NODE_PERFORMANCE_GC_FLAGS_ALL_AVAILABLE_GARBAGE);
333 NODE_DEFINE_CONSTANT(
334 constants, NODE_PERFORMANCE_GC_FLAGS_ALL_EXTERNAL_MEMORY);
335 NODE_DEFINE_CONSTANT(
336 constants, NODE_PERFORMANCE_GC_FLAGS_SCHEDULE_IDLE);
337
338 #define V(name, _) \
339 NODE_DEFINE_HIDDEN_CONSTANT(constants, NODE_PERFORMANCE_ENTRY_TYPE_##name);
340 NODE_PERFORMANCE_ENTRY_TYPES(V)
341 #undef V
342
343 #define V(name, _) \
344 NODE_DEFINE_HIDDEN_CONSTANT(constants, NODE_PERFORMANCE_MILESTONE_##name);
345 NODE_PERFORMANCE_MILESTONES(V)
346 #undef V
347
348 PropertyAttribute attr =
349 static_cast<PropertyAttribute>(ReadOnly | DontDelete);
350
351 target->DefineOwnProperty(context,
352 env->constants_string(),
353 constants,
354 attr).ToChecked();
355
356 HistogramBase::Initialize(env, target);
357 }
358
RegisterExternalReferences(ExternalReferenceRegistry * registry)359 void RegisterExternalReferences(ExternalReferenceRegistry* registry) {
360 registry->Register(MarkMilestone);
361 registry->Register(SetupPerformanceObservers);
362 registry->Register(InstallGarbageCollectionTracking);
363 registry->Register(RemoveGarbageCollectionTracking);
364 registry->Register(Notify);
365 registry->Register(LoopIdleTime);
366 registry->Register(GetTimeOrigin);
367 registry->Register(GetTimeOriginTimeStamp);
368 registry->Register(CreateELDHistogram);
369 registry->Register(MarkBootstrapComplete);
370 HistogramBase::RegisterExternalReferences(registry);
371 IntervalHistogram::RegisterExternalReferences(registry);
372 }
373 } // namespace performance
374 } // namespace node
375
376 NODE_BINDING_CONTEXT_AWARE_INTERNAL(performance, node::performance::Initialize)
377 NODE_BINDING_EXTERNAL_REFERENCE(performance,
378 node::performance::RegisterExternalReferences)
379