xref: /third_party/node/src/node_perf.cc (revision 1cb0ef41) 
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
14namespace node {
15namespace performance {
16
17using v8::Context;
18using v8::DontDelete;
19using v8::Function;
20using v8::FunctionCallbackInfo;
21using v8::FunctionTemplate;
22using v8::GCCallbackFlags;
23using v8::GCType;
24using v8::Int32;
25using v8::Integer;
26using v8::Isolate;
27using v8::Local;
28using v8::MaybeLocal;
29using v8::Number;
30using v8::Object;
31using v8::PropertyAttribute;
32using v8::ReadOnly;
33using v8::String;
34using 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
40const uint64_t timeOrigin = PERFORMANCE_NOW();
41// https://w3c.github.io/hr-time/#dfn-time-origin-timestamp
42const double timeOriginTimestamp = GetCurrentTimeInMicroseconds();
43uint64_t performance_v8_start;
44
45PerformanceState::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
65PerformanceState::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
73void 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
81std::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
91void 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
100void 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
108void 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
115void 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
130MaybeLocal<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
157void 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
190void 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
198static 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
210static 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
219void 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
233void 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
239void 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
260void GetTimeOrigin(const FunctionCallbackInfo<Value>& args) {
261  args.GetReturnValue().Set(Number::New(args.GetIsolate(), timeOrigin / 1e6));
262}
263
264void GetTimeOriginTimeStamp(const FunctionCallbackInfo<Value>& args) {
265  args.GetReturnValue().Set(
266      Number::New(args.GetIsolate(), timeOriginTimestamp / MICROS_PER_MILLIS));
267}
268
269void 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
275void 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
359void 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
376NODE_BINDING_CONTEXT_AWARE_INTERNAL(performance, node::performance::Initialize)
377NODE_BINDING_EXTERNAL_REFERENCE(performance,
378                                node::performance::RegisterExternalReferences)
379