diff options
author | James M Snell <jasnell@gmail.com> | 2017-08-08 01:53:24 +0300 |
---|---|---|
committer | James M Snell <jasnell@gmail.com> | 2017-08-24 02:00:09 +0300 |
commit | 67269fd7f33279699b1ae71225f3d738518c844c (patch) | |
tree | 22f6a615c02ccb93c69355d101db87f36f08cf06 /src/node_perf.cc | |
parent | e007f66ae211192f385dc253bfa19a84e7fc649a (diff) |
perf_hooks: implementation of the perf timing API
An initial implementation of the Performance Timing API for Node.js.
This is the same Performance Timing API implemented by modern browsers
with a number of Node.js specific properties. The User Timing mark()
and measure() APIs are implemented, garbage collection timing, and
node startup milestone timing.
```js
const { performance } = require('perf_hooks');
performance.mark('A');
setTimeout(() => {
performance.mark('B');
performance.measure('A to B', 'A', 'B');
const entry = performance.getEntriesByName('A to B', 'measure')[0];
console.log(entry.duration);
}, 10000);
```
The implementation is at the native layer and makes use of uv_hrtime().
This should enable *eventual* integration with things like Tracing
and Inspection.
The implementation is extensible and should allow us to add new
performance entry types as we go (e.g. for measuring i/o perf,
etc).
Documentation and a test are provided.
PR-URL: https://github.com/nodejs/node/pull/14680
Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
Diffstat (limited to 'src/node_perf.cc')
-rw-r--r-- | src/node_perf.cc | 389 |
1 files changed, 389 insertions, 0 deletions
diff --git a/src/node_perf.cc b/src/node_perf.cc new file mode 100644 index 00000000000..2398bb9b8fd --- /dev/null +++ b/src/node_perf.cc @@ -0,0 +1,389 @@ +#include "node.h" +#include "v8.h" +#include "env.h" +#include "env-inl.h" +#include "node_perf.h" +#include "uv.h" + +#include <vector> + +namespace node { +namespace performance { + +using v8::Array; +using v8::ArrayBuffer; +using v8::Context; +using v8::Function; +using v8::FunctionCallbackInfo; +using v8::FunctionTemplate; +using v8::HandleScope; +using v8::Integer; +using v8::Isolate; +using v8::Local; +using v8::Name; +using v8::Object; +using v8::ObjectTemplate; +using v8::PropertyCallbackInfo; +using v8::String; +using v8::Value; + +const uint64_t timeOrigin = PERFORMANCE_NOW(); +uint64_t performance_node_start; +uint64_t performance_v8_start; + +uint64_t performance_last_gc_start_mark_ = 0; +v8::GCType performance_last_gc_type_ = v8::GCType::kGCTypeAll; + +void PerformanceEntry::New(const FunctionCallbackInfo<Value>& args) { + Environment* env = Environment::GetCurrent(args); + Isolate* isolate = env->isolate(); + Utf8Value name(isolate, args[0]); + Utf8Value type(isolate, args[1]); + uint64_t now = PERFORMANCE_NOW(); + new PerformanceEntry(env, args.This(), *name, *type, now, now); +} + +void PerformanceEntry::NotifyObservers(Environment* env, + PerformanceEntry* entry) { + uint32_t* observers = env->performance_state()->observers; + PerformanceEntryType type = ToPerformanceEntryTypeEnum(entry->type().c_str()); + if (observers == nullptr || + type == NODE_PERFORMANCE_ENTRY_TYPE_INVALID || + !observers[type]) { + return; + } + Local<Context> context = env->context(); + Isolate* isolate = env->isolate(); + Local<Value> argv = entry->object(); + env->performance_entry_callback()->Call(context, + v8::Undefined(isolate), + 1, &argv); +} + +void Mark(const FunctionCallbackInfo<Value>& args) { + Environment* env = Environment::GetCurrent(args); + Local<Context> context = env->context(); + Isolate* isolate = env->isolate(); + Utf8Value name(isolate, args[0]); + uint64_t now = PERFORMANCE_NOW(); + auto marks = env->performance_marks(); + (*marks)[*name] = now; + + // TODO(jasnell): Once Tracing API is fully implemented, this should + // record a trace event also. + + Local<Function> fn = env->performance_entry_template(); + Local<Object> obj = fn->NewInstance(context).ToLocalChecked(); + new PerformanceEntry(env, obj, *name, "mark", now, now); + args.GetReturnValue().Set(obj); +} + +inline uint64_t GetPerformanceMark(Environment* env, std::string name) { + auto marks = env->performance_marks(); + auto res = marks->find(name); + return res != marks->end() ? res->second : 0; +} + +void Measure(const FunctionCallbackInfo<Value>& args) { + Environment* env = Environment::GetCurrent(args); + Local<Context> context = env->context(); + Isolate* isolate = env->isolate(); + Utf8Value name(isolate, args[0]); + Utf8Value startMark(isolate, args[1]); + Utf8Value endMark(isolate, args[2]); + + double* milestones = env->performance_state()->milestones; + + uint64_t startTimestamp = timeOrigin; + uint64_t start = GetPerformanceMark(env, *startMark); + if (start != 0) { + startTimestamp = start; + } else { + PerformanceMilestone milestone = ToPerformanceMilestoneEnum(*startMark); + if (milestone != NODE_PERFORMANCE_MILESTONE_INVALID) + startTimestamp = milestones[milestone]; + } + + uint64_t endTimestamp = GetPerformanceMark(env, *endMark); + if (endTimestamp == 0) { + PerformanceMilestone milestone = ToPerformanceMilestoneEnum(*endMark); + if (milestone != NODE_PERFORMANCE_MILESTONE_INVALID) + endTimestamp = milestones[milestone]; + } + + if (endTimestamp < startTimestamp) + endTimestamp = startTimestamp; + + // TODO(jasnell): Once Tracing API is fully implemented, this should + // record a trace event also. + + Local<Function> fn = env->performance_entry_template(); + Local<Object> obj = fn->NewInstance(context).ToLocalChecked(); + new PerformanceEntry(env, obj, *name, "measure", + startTimestamp, endTimestamp); + args.GetReturnValue().Set(obj); +} + +void GetPerformanceEntryName(const Local<String> prop, + const PropertyCallbackInfo<Value>& info) { + Isolate* isolate = info.GetIsolate(); + PerformanceEntry* entry; + ASSIGN_OR_RETURN_UNWRAP(&entry, info.Holder()); + info.GetReturnValue().Set( + String::NewFromUtf8(isolate, entry->name().c_str(), String::kNormalString)); +} + +void GetPerformanceEntryType(const Local<String> prop, + const PropertyCallbackInfo<Value>& info) { + Isolate* isolate = info.GetIsolate(); + PerformanceEntry* entry; + ASSIGN_OR_RETURN_UNWRAP(&entry, info.Holder()); + info.GetReturnValue().Set( + String::NewFromUtf8(isolate, entry->type().c_str(), String::kNormalString)); +} + +void GetPerformanceEntryStartTime(const Local<String> prop, + const PropertyCallbackInfo<Value>& info) { + PerformanceEntry* entry; + ASSIGN_OR_RETURN_UNWRAP(&entry, info.Holder()); + info.GetReturnValue().Set(entry->startTime()); +} + +void GetPerformanceEntryDuration(const Local<String> prop, + const PropertyCallbackInfo<Value>& info) { + PerformanceEntry* entry; + ASSIGN_OR_RETURN_UNWRAP(&entry, info.Holder()); + info.GetReturnValue().Set(entry->duration()); +} + +void MarkMilestone(const FunctionCallbackInfo<Value>& args) { + Environment* env = Environment::GetCurrent(args); + Local<Context> context = env->context(); + double* milestones = env->performance_state()->milestones; + PerformanceMilestone milestone = + static_cast<PerformanceMilestone>( + args[0]->Int32Value(context).ToChecked()); + if (milestone != NODE_PERFORMANCE_MILESTONE_INVALID) { + milestones[milestone] = PERFORMANCE_NOW(); + } +} + +void SetupPerformanceObservers(const FunctionCallbackInfo<Value>& args) { + Environment* env = Environment::GetCurrent(args); + CHECK(args[0]->IsFunction()); + env->set_performance_entry_callback(args[0].As<Function>()); +} + +inline void PerformanceGCCallback(uv_async_t* handle) { + PerformanceEntry::Data* data = + static_cast<PerformanceEntry::Data*>(handle->data); + Isolate* isolate = Isolate::GetCurrent(); + HandleScope scope(isolate); + Environment* env = Environment::GetCurrent(isolate); + Local<Context> context = env->context(); + Local<Function> fn; + Local<Object> obj; + PerformanceGCKind kind = static_cast<PerformanceGCKind>(data->data()); + + uint32_t* observers = env->performance_state()->observers; + if (!observers[NODE_PERFORMANCE_ENTRY_TYPE_GC]) { + goto cleanup; + } + + fn = env->performance_entry_template(); + obj = fn->NewInstance(context).ToLocalChecked(); + obj->Set(context, + FIXED_ONE_BYTE_STRING(isolate, "kind"), + Integer::New(isolate, kind)).FromJust(); + new PerformanceEntry(env, obj, data); + + cleanup: + delete data; + auto closeCB = [](uv_handle_t* handle) { delete handle; }; + uv_close(reinterpret_cast<uv_handle_t*>(handle), closeCB); +} + +inline void MarkGarbageCollectionStart(Isolate* isolate, + v8::GCType type, + v8::GCCallbackFlags flags) { + performance_last_gc_start_mark_ = PERFORMANCE_NOW(); + performance_last_gc_type_ = type; +} + +inline void MarkGarbageCollectionEnd(Isolate* isolate, + v8::GCType type, + v8::GCCallbackFlags flags) { + uv_async_t *async = new uv_async_t; + async->data = + new PerformanceEntry::Data("gc", "gc", + performance_last_gc_start_mark_, + PERFORMANCE_NOW(), type); + uv_async_init(uv_default_loop(), async, PerformanceGCCallback); + uv_async_send(async); +} + +inline void SetupGarbageCollectionTracking(Isolate* isolate) { + isolate->AddGCPrologueCallback(MarkGarbageCollectionStart); + isolate->AddGCPrologueCallback(MarkGarbageCollectionEnd); +} + +inline Local<Value> GetName(Local<Function> fn) { + Local<Value> val = fn->GetDebugName(); + if (val.IsEmpty() || val->IsUndefined()) { + Local<Value> boundFunction = fn->GetBoundFunction(); + if (!boundFunction.IsEmpty() && !boundFunction->IsUndefined()) { + val = GetName(boundFunction.As<Function>()); + } + } + return val; +} + +void TimerFunctionCall(const FunctionCallbackInfo<Value>& args) { + Isolate* isolate = args.GetIsolate(); + HandleScope scope(isolate); + Environment* env = Environment::GetCurrent(isolate); + Local<Context> context = env->context(); + Local<Function> fn = args.Data().As<Function>(); + size_t count = args.Length(); + size_t idx; + std::vector<Local<Value>> call_args; + for (size_t i = 0; i < count; ++i) { + call_args.push_back(args[i]); + } + + Utf8Value name(isolate, GetName(fn)); + + uint64_t start; + uint64_t end; + v8::TryCatch try_catch(isolate); + if (args.IsConstructCall()) { + start = PERFORMANCE_NOW(); + v8::MaybeLocal<Object> ret = fn->NewInstance(context, + call_args.size(), + call_args.data()); + end = PERFORMANCE_NOW(); + if (ret.IsEmpty()) { + try_catch.ReThrow(); + return; + } + args.GetReturnValue().Set(ret.ToLocalChecked()); + } else { + start = PERFORMANCE_NOW(); + v8::MaybeLocal<Value> ret = fn->Call(context, + args.This(), + call_args.size(), + call_args.data()); + end = PERFORMANCE_NOW(); + if (ret.IsEmpty()) { + try_catch.ReThrow(); + return; + } + args.GetReturnValue().Set(ret.ToLocalChecked()); + } + + + uint32_t* observers = env->performance_state()->observers; + if (!observers[NODE_PERFORMANCE_ENTRY_TYPE_FUNCTION]) + return; + + Local<Function> ctor = env->performance_entry_template(); + v8::MaybeLocal<Object> instance = ctor->NewInstance(context); + Local<Object> obj = instance.ToLocalChecked(); + for (idx = 0; idx < count; idx++) { + obj->Set(context, idx, args[idx]); + } + new PerformanceEntry(env, obj, *name, "function", start, end); +} + +void Timerify(const FunctionCallbackInfo<Value>& args) { + Environment* env = Environment::GetCurrent(args); + Local<Context> context = env->context(); + CHECK(args[0]->IsFunction()); + CHECK(args[1]->IsNumber()); + Local<Function> fn = args[0].As<Function>(); + int length = args[1]->IntegerValue(context).ToChecked(); + Local<Function> wrap = + Function::New(context, TimerFunctionCall, fn, length).ToLocalChecked(); + args.GetReturnValue().Set(wrap); +} + +void Init(Local<Object> target, + Local<Value> unused, + Local<Context> context) { + Environment* env = Environment::GetCurrent(context); + Isolate* isolate = env->isolate(); + performance_state* state = env->performance_state(); + auto state_ab = ArrayBuffer::New(isolate, state, sizeof(*state)); + + #define SET_STATE_TYPEDARRAY(name, type, field) \ + target->Set(context, \ + FIXED_ONE_BYTE_STRING(isolate, (name)), \ + type::New(state_ab, \ + offsetof(performance_state, field), \ + arraysize(state->field))) \ + .FromJust() + SET_STATE_TYPEDARRAY("observerCounts", v8::Uint32Array, observers); + SET_STATE_TYPEDARRAY("milestones", v8::Float64Array, milestones); + #undef SET_STATE_TYPEDARRAY + + Local<String> performanceEntryString = + FIXED_ONE_BYTE_STRING(isolate, "PerformanceEntry"); + + Local<FunctionTemplate> pe = env->NewFunctionTemplate(PerformanceEntry::New); + pe->InstanceTemplate()->SetInternalFieldCount(1); + pe->SetClassName(performanceEntryString); + Local<ObjectTemplate> ot = pe->InstanceTemplate(); + ot->SetAccessor(env->name_string(), GetPerformanceEntryName); + ot->SetAccessor(FIXED_ONE_BYTE_STRING(isolate, "entryType"), + GetPerformanceEntryType); + ot->SetAccessor(FIXED_ONE_BYTE_STRING(isolate, "startTime"), + GetPerformanceEntryStartTime); + ot->SetAccessor(FIXED_ONE_BYTE_STRING(isolate, "duration"), + GetPerformanceEntryDuration); + Local<Function> fn = pe->GetFunction(); + target->Set(performanceEntryString, fn); + env->set_performance_entry_template(fn); + + env->SetMethod(target, "mark", Mark); + env->SetMethod(target, "measure", Measure); + env->SetMethod(target, "markMilestone", MarkMilestone); + env->SetMethod(target, "setupObservers", SetupPerformanceObservers); + env->SetMethod(target, "timerify", Timerify); + + Local<Object> constants = Object::New(isolate); + + NODE_DEFINE_CONSTANT(constants, NODE_PERFORMANCE_GC_MAJOR); + NODE_DEFINE_CONSTANT(constants, NODE_PERFORMANCE_GC_MINOR); + NODE_DEFINE_CONSTANT(constants, NODE_PERFORMANCE_GC_INCREMENTAL); + NODE_DEFINE_CONSTANT(constants, NODE_PERFORMANCE_GC_WEAKCB); + +#define V(name, _) \ + NODE_DEFINE_HIDDEN_CONSTANT(constants, NODE_PERFORMANCE_ENTRY_TYPE_##name); + NODE_PERFORMANCE_ENTRY_TYPES(V) +#undef V + +#define V(name, _) \ + NODE_DEFINE_HIDDEN_CONSTANT(constants, NODE_PERFORMANCE_MILESTONE_##name); + NODE_PERFORMANCE_MILESTONES(V) +#undef V + + v8::PropertyAttribute attr = + static_cast<v8::PropertyAttribute>(v8::ReadOnly | v8::DontDelete); + + target->DefineOwnProperty(context, + FIXED_ONE_BYTE_STRING(isolate, "timeOrigin"), + v8::Number::New(isolate, timeOrigin / 1e6), + attr); + + target->DefineOwnProperty(context, + env->constants_string(), + constants, + attr); + + SetupGarbageCollectionTracking(isolate); +} + +} // namespace performance +} // namespace node + +NODE_MODULE_CONTEXT_AWARE_BUILTIN(performance, node::performance::Init) |