From 334936cf1da64f8edd0ad7a7db6c6ba242040ca6 Mon Sep 17 00:00:00 2001 From: theanarkh Date: Thu, 19 Jan 2023 00:29:58 +0800 Subject: [PATCH] v8: support gc profile --- doc/api/v8.md | 78 ++++++++ lib/v8.js | 54 ++++- src/node_v8.cc | 187 ++++++++++++++++++ src/node_v8.h | 28 +++ test/common/v8.js | 52 +++++ .../parallel/test-v8-take-gc-profile-abort.js | 41 ++++ ...est-v8-take-gc-profile-exit-before-stop.js | 6 + .../test-v8-take-gc-profile-in-worker.js | 25 +++ test/parallel/test-v8-take-gc-profile.js | 28 +++ 9 files changed, 497 insertions(+), 2 deletions(-) create mode 100644 test/common/v8.js create mode 100644 test/parallel/test-v8-take-gc-profile-abort.js create mode 100644 test/parallel/test-v8-take-gc-profile-exit-before-stop.js create mode 100644 test/parallel/test-v8-take-gc-profile-in-worker.js create mode 100644 test/parallel/test-v8-take-gc-profile.js diff --git a/doc/api/v8.md b/doc/api/v8.md index 7bb1a795b5a581..1b4ff8c5e594f7 100644 --- a/doc/api/v8.md +++ b/doc/api/v8.md @@ -390,6 +390,84 @@ The API is a no-op if `--heapsnapshot-near-heap-limit` is already set from the command line or the API is called more than once. `limit` must be a positive integer. See [`--heapsnapshot-near-heap-limit`][] for more information. +## `v8.collectGCProfile(options)` + + + +* `options` {Object} + * `duration` {number} how long you want to collect the data in milliseconds. + * `signal` {AbortSignal} allows aborting an in-progress collect operation + +* Returns: {Promise} + +This API collects GC data over a period of time in current thread and returns +an object when the `Promise` resolves. Each call is independent, it does not +affect each other. The content is as follows. + +```json +{ + "version": 1, + "startTime": 1674059033862, + "statistics": [ + { + "gcType": "Scavenge", + "beforeGC": { + "heapStatistics": { + "totalHeapSize": 5005312, + "totalHeapSizeExecutable": 524288, + "totalPhysicalSize": 5226496, + "totalAvailableSize": 4341325216, + "totalGlobalHandlesSize": 8192, + "usedGlobalHandlesSize": 2112, + "usedHeapSize": 4883840, + "heapSizeLimit": 4345298944, + "mallocedMemory": 254128, + "externalMemory": 225138, + "peakMallocedMemory": 181760 + }, + "heapSpaceStatistics": [ + { + "spaceName": "read_only_space", + "spaceSize": 0, + "spaceUsedSize": 0, + "spaceAvailableSize": 0, + "physicalSpaceSize": 0 + } + ] + }, + "cost": 1574.14, + "afterGC": { + "heapStatistics": { + "totalHeapSize": 6053888, + "totalHeapSizeExecutable": 524288, + "totalPhysicalSize": 5500928, + "totalAvailableSize": 4341101384, + "totalGlobalHandlesSize": 8192, + "usedGlobalHandlesSize": 2112, + "usedHeapSize": 4059096, + "heapSizeLimit": 4345298944, + "mallocedMemory": 254128, + "externalMemory": 225138, + "peakMallocedMemory": 181760 + }, + "heapSpaceStatistics": [ + { + "spaceName": "read_only_space", + "spaceSize": 0, + "spaceUsedSize": 0, + "spaceAvailableSize": 0, + "physicalSpaceSize": 0 + } + ] + } + } + ], + "endtTime": 1674059036865 +} +``` + ## Serialization API The serialization API provides means of serializing JavaScript values in a way diff --git a/lib/v8.js b/lib/v8.js index 70956192d7d34f..ffe70b7794f38e 100644 --- a/lib/v8.js +++ b/lib/v8.js @@ -33,7 +33,13 @@ const { } = primordials; const { Buffer } = require('buffer'); -const { validateString, validateUint32 } = require('internal/validators'); +const { + validateString, + validateUint32, + validateObject, + validateNumber, + validateAbortSignal, +} = require('internal/validators'); const { Serializer, Deserializer @@ -63,7 +69,10 @@ const { } = require('internal/heap_utils'); const promiseHooks = require('internal/promise_hooks'); const { getOptionValue } = require('internal/options'); - +const { setUnrefTimeout } = require('internal/timers'); +const { clearTimeout } = require('timers'); +const { AbortError } = require('internal/errors'); +const { Promise, JSONParse } = primordials; /** * Generates a snapshot of the current V8 heap * and writes it to a JSON file. @@ -397,6 +406,46 @@ function deserialize(buffer) { return der.readValue(); } +/** + * @param {{ + * duration: number, + * signal?: AbortSignal + * }} options + */ +function collectGCProfile(options) { + validateObject(options, 'options'); + validateNumber(options.duration, 'options.duration', 1); + if (options.signal) { + validateAbortSignal(options.signal, 'options.signal'); + } + return new Promise((resolve, reject) => { + let profiler; + let timer; + const onAbortListener = () => { + timer && clearTimeout(timer); + profiler && profiler.stop(); + reject(new AbortError(undefined, { cause: options.signal.reason })); + }; + if (options.signal) { + const { signal } = options; + if (signal.aborted) { + onAbortListener(); + return; + } + signal.addEventListener('abort', onAbortListener, { once: true }); + } + profiler = new binding.GCProfiler(); + profiler.start(); + timer = setUnrefTimeout(() => { + const data = profiler.stop(); + resolve(JSONParse(data)); + if (options.signal) { + options.signal.removeEventListener('abort', onAbortListener); + } + }, options.duration); + }); +} + module.exports = { cachedDataVersionTag, getHeapSnapshot, @@ -416,4 +465,5 @@ module.exports = { promiseHooks, startupSnapshot, setHeapSnapshotNearHeapLimit, + collectGCProfile, }; diff --git a/src/node_v8.cc b/src/node_v8.cc index 91a3dbb93e0155..76e13957b0d6de 100644 --- a/src/node_v8.cc +++ b/src/node_v8.cc @@ -33,6 +33,7 @@ namespace v8_utils { using v8::Array; using v8::Context; using v8::FunctionCallbackInfo; +using v8::FunctionTemplate; using v8::HandleScope; using v8::HeapCodeStatistics; using v8::HeapSpaceStatistics; @@ -210,6 +211,181 @@ void SetFlagsFromString(const FunctionCallbackInfo& args) { V8::SetFlagsFromString(*flags, static_cast(flags.length())); } +static const char* GetGCTypeName(v8::GCType gc_type) { + switch (gc_type) { + case v8::GCType::kGCTypeScavenge: + return "Scavenge"; + case v8::GCType::kGCTypeMarkSweepCompact: + return "MarkSweepCompact"; + case v8::GCType::kGCTypeIncrementalMarking: + return "IncrementalMarking"; + case v8::GCType::kGCTypeProcessWeakCallbacks: + return "ProcessWeakCallbacks"; + default: + return "Unknown"; + } +} + +static void SetHeapStatistics(JSONWriter* writer, Isolate* isolate) { + HeapStatistics heap_statistics; + isolate->GetHeapStatistics(&heap_statistics); + writer->json_objectstart("heapStatistics"); + writer->json_keyvalue("totalHeapSize", heap_statistics.total_heap_size()); + writer->json_keyvalue("totalHeapSizeExecutable", + heap_statistics.total_heap_size_executable()); + writer->json_keyvalue("totalPhysicalSize", + heap_statistics.total_physical_size()); + writer->json_keyvalue("totalAvailableSize", + heap_statistics.total_available_size()); + writer->json_keyvalue("totalGlobalHandlesSize", + heap_statistics.total_global_handles_size()); + writer->json_keyvalue("usedGlobalHandlesSize", + heap_statistics.used_global_handles_size()); + writer->json_keyvalue("usedHeapSize", heap_statistics.used_heap_size()); + writer->json_keyvalue("heapSizeLimit", heap_statistics.heap_size_limit()); + writer->json_keyvalue("mallocedMemory", heap_statistics.malloced_memory()); + writer->json_keyvalue("externalMemory", heap_statistics.external_memory()); + writer->json_keyvalue("peakMallocedMemory", + heap_statistics.peak_malloced_memory()); + writer->json_objectend(); + + int space_count = isolate->NumberOfHeapSpaces(); + writer->json_arraystart("heapSpaceStatistics"); + for (int i = 0; i < space_count; i++) { + HeapSpaceStatistics heap_space_statistics; + isolate->GetHeapSpaceStatistics(&heap_space_statistics, i); + writer->json_start(); + writer->json_keyvalue("spaceName", heap_space_statistics.space_name()); + writer->json_keyvalue("spaceSize", heap_space_statistics.space_size()); + writer->json_keyvalue("spaceUsedSize", + heap_space_statistics.space_used_size()); + writer->json_keyvalue("spaceAvailableSize", + heap_space_statistics.space_available_size()); + writer->json_keyvalue("physicalSpaceSize", + heap_space_statistics.physical_space_size()); + writer->json_end(); + } + writer->json_arrayend(); +} + +static void BeforeGCCallback(Isolate* isolate, + v8::GCType gc_type, + v8::GCCallbackFlags flags, + void* data) { + GCProfiler* profiler = static_cast(data); + if (profiler->current_gc_type != 0) { + return; + } + JSONWriter* writer = profiler->writer(); + writer->json_start(); + writer->json_keyvalue("gcType", GetGCTypeName(gc_type)); + writer->json_objectstart("beforeGC"); + SetHeapStatistics(writer, isolate); + writer->json_objectend(); + profiler->current_gc_type = gc_type; + profiler->start_time = uv_hrtime(); +} + +static void AfterGCCallback(Isolate* isolate, + v8::GCType gc_type, + v8::GCCallbackFlags flags, + void* data) { + GCProfiler* profiler = static_cast(data); + if (profiler->current_gc_type != gc_type) { + return; + } + JSONWriter* writer = profiler->writer(); + profiler->current_gc_type = 0; + writer->json_keyvalue("cost", (uv_hrtime() - profiler->start_time) / 1e3); + profiler->start_time = 0; + writer->json_objectstart("afterGC"); + SetHeapStatistics(writer, isolate); + writer->json_objectend(); + writer->json_end(); +} + +GCProfiler::GCProfiler(Environment* env, Local object) + : BaseObject(env, object), + start_time(0), + current_gc_type(0), + state(GCProfilerState::kInitialized), + writer_(out_stream_, false) { + MakeWeak(); +} + +// This function will be called when +// 1. StartGCProfile and StopGCProfile are called and +// JS land does not keep the object anymore. +// 2. StartGCProfile is called then the env exits before +// StopGCProfile is called. +GCProfiler::~GCProfiler() { + if (state != GCProfiler::GCProfilerState::kInitialized) { + env()->isolate()->RemoveGCPrologueCallback(BeforeGCCallback, this); + env()->isolate()->RemoveGCEpilogueCallback(AfterGCCallback, this); + } +} + +JSONWriter* GCProfiler::writer() { + return &writer_; +} + +std::ostringstream* GCProfiler::out_stream() { + return &out_stream_; +} + +void GCProfiler::New(const FunctionCallbackInfo& args) { + CHECK(args.IsConstructCall()); + Environment* env = Environment::GetCurrent(args); + new GCProfiler(env, args.This()); +} + +void GCProfiler::Start(const FunctionCallbackInfo& args) { + Environment* env = Environment::GetCurrent(args); + GCProfiler* profiler; + ASSIGN_OR_RETURN_UNWRAP(&profiler, args.Holder()); + if (profiler->state != GCProfiler::GCProfilerState::kInitialized) { + return; + } + profiler->writer()->json_start(); + profiler->writer()->json_keyvalue("version", 1); + + uv_timeval64_t ts; + if (uv_gettimeofday(&ts) == 0) { + profiler->writer()->json_keyvalue("startTime", + ts.tv_sec * 1000 + ts.tv_usec / 1000); + } else { + profiler->writer()->json_keyvalue("startTime", 0); + } + profiler->writer()->json_arraystart("statistics"); + env->isolate()->AddGCPrologueCallback(BeforeGCCallback, + static_cast(profiler)); + env->isolate()->AddGCEpilogueCallback(AfterGCCallback, + static_cast(profiler)); + profiler->state = GCProfiler::GCProfilerState::kStarted; +} + +void GCProfiler::Stop(const FunctionCallbackInfo& args) { + Environment* env = Environment::GetCurrent(args); + GCProfiler* profiler; + ASSIGN_OR_RETURN_UNWRAP(&profiler, args.Holder()); + if (profiler->state != GCProfiler::GCProfilerState::kStarted) { + return; + } + profiler->writer()->json_arrayend(); + uv_timeval64_t ts; + if (uv_gettimeofday(&ts) == 0) { + profiler->writer()->json_keyvalue("endTime", + ts.tv_sec * 1000 + ts.tv_usec / 1000); + } else { + profiler->writer()->json_keyvalue("endTime", 0); + } + profiler->writer()->json_end(); + profiler->state = GCProfiler::GCProfilerState::kStopped; + args.GetReturnValue().Set( + String::NewFromUtf8(env->isolate(), profiler->out_stream()->str().c_str()) + .ToLocalChecked()); +} + void Initialize(Local target, Local unused, Local context, @@ -272,6 +448,14 @@ void Initialize(Local target, // Export symbols used by v8.setFlagsFromString() SetMethod(context, target, "setFlagsFromString", SetFlagsFromString); + + // GCProfiler + Local t = + NewFunctionTemplate(env->isolate(), GCProfiler::New); + t->InstanceTemplate()->SetInternalFieldCount(BaseObject::kInternalFieldCount); + SetProtoMethod(env->isolate(), t, "start", GCProfiler::Start); + SetProtoMethod(env->isolate(), t, "stop", GCProfiler::Stop); + SetConstructorFunction(context, target, "GCProfiler", t); } void RegisterExternalReferences(ExternalReferenceRegistry* registry) { @@ -281,6 +465,9 @@ void RegisterExternalReferences(ExternalReferenceRegistry* registry) { registry->Register(UpdateHeapSpaceStatisticsBuffer); registry->Register(SetFlagsFromString); registry->Register(SetHeapSnapshotNearHeapLimit); + registry->Register(GCProfiler::New); + registry->Register(GCProfiler::Start); + registry->Register(GCProfiler::Stop); } } // namespace v8_utils diff --git a/src/node_v8.h b/src/node_v8.h index 18b3621a2a5d6a..ecab454603b36b 100644 --- a/src/node_v8.h +++ b/src/node_v8.h @@ -3,8 +3,10 @@ #if defined(NODE_WANT_INTERNALS) && NODE_WANT_INTERNALS +#include #include "aliased_buffer.h" #include "base_object.h" +#include "json_utils.h" #include "node_snapshotable.h" #include "util.h" #include "v8.h" @@ -34,6 +36,32 @@ class BindingData : public SnapshotableObject { SET_MEMORY_INFO_NAME(BindingData) }; +class GCProfiler : public BaseObject { + public: + enum class GCProfilerState { kInitialized, kStarted, kStopped }; + GCProfiler(Environment* env, v8::Local object); + inline ~GCProfiler() override; + static void New(const v8::FunctionCallbackInfo& args); + static void Start(const v8::FunctionCallbackInfo& args); + static void Stop(const v8::FunctionCallbackInfo& args); + + JSONWriter* writer(); + + std::ostringstream* out_stream(); + + SET_NO_MEMORY_INFO() + SET_MEMORY_INFO_NAME(GCProfiler) + SET_SELF_SIZE(GCProfiler) + + uint64_t start_time; + uint8_t current_gc_type; + GCProfilerState state; + + private: + std::ostringstream out_stream_; + JSONWriter writer_; +}; + } // namespace v8_utils } // namespace node diff --git a/test/common/v8.js b/test/common/v8.js new file mode 100644 index 00000000000000..1ccbb29d43a775 --- /dev/null +++ b/test/common/v8.js @@ -0,0 +1,52 @@ +'use strict'; +const assert = require('assert'); + +function checkGCProfile(data) { + assert.ok(data.version > 0); + assert.ok(data.startTime >= 0); + assert.ok(data.endTime >= 0); + assert.ok(Array.isArray(data.statistics)); + // If the array is not empty, check it + if (data.statistics.length) { + // Just check the first one + const item = data.statistics[0]; + assert.ok(typeof item.gcType === 'string'); + assert.ok(item.cost >= 0); + assert.ok(typeof item.beforeGC === 'object'); + assert.ok(typeof item.afterGC === 'object'); + // The content of beforeGC and afterGC is same, so we just check afterGC + assert.ok(typeof item.afterGC.heapStatistics === 'object'); + const heapStatisticsKeys = [ + 'externalMemory', + 'heapSizeLimit', + 'mallocedMemory', + 'peakMallocedMemory', + 'totalAvailableSize', + 'totalGlobalHandlesSize', + 'totalHeapSize', + 'totalHeapSizeExecutable', + 'totalPhysicalSize', + 'usedGlobalHandlesSize', + 'usedHeapSize', + ]; + heapStatisticsKeys.forEach((key) => { + assert.ok(item.afterGC.heapStatistics[key] >= 0); + }); + assert.ok(typeof item.afterGC.heapSpaceStatistics === 'object'); + const heapSpaceStatisticsKeys = [ + 'physicalSpaceSize', + 'spaceAvailableSize', + 'spaceName', + 'spaceSize', + 'spaceUsedSize', + ]; + heapSpaceStatisticsKeys.forEach((key) => { + const value = item.afterGC.heapSpaceStatistics[0][key]; + assert.ok(key === 'spaceName' ? typeof value === 'string' : value >= 0); + }); + } +} + +module.exports = { + checkGCProfile, +}; diff --git a/test/parallel/test-v8-take-gc-profile-abort.js b/test/parallel/test-v8-take-gc-profile-abort.js new file mode 100644 index 00000000000000..04b313dc8005ad --- /dev/null +++ b/test/parallel/test-v8-take-gc-profile-abort.js @@ -0,0 +1,41 @@ +'use strict'; +require('../common'); +const assert = require('assert'); +const { collectGCProfile } = require('v8'); + +async function run() { + { + const signal = new EventTarget(); + signal.aborted = true; + signal.reason = 'test'; + const timer = setInterval(() => {}, 10000); + try { + await collectGCProfile({ duration: 1000, signal }); + } catch (e) { + assert.ok(e.name === 'AbortError'); + } + clearInterval(timer); + } + + { + const controller = new AbortController(); + const timer = setInterval(() => {}, 10000); + setTimeout(() => { controller.abort(); }, 1000); + try { + await collectGCProfile({ duration: 3000, signal: controller.signal }); + } catch (e) { + assert.ok(e.name === 'AbortError'); + } + clearInterval(timer); + } + + { + const controller = new AbortController(); + const timer = setInterval(() => {}, 10000); + const data = await collectGCProfile({ duration: 3000, signal: controller.signal }); + assert(data); + clearInterval(timer); + } +} + +run(); diff --git a/test/parallel/test-v8-take-gc-profile-exit-before-stop.js b/test/parallel/test-v8-take-gc-profile-exit-before-stop.js new file mode 100644 index 00000000000000..22ea1cd43556ab --- /dev/null +++ b/test/parallel/test-v8-take-gc-profile-exit-before-stop.js @@ -0,0 +1,6 @@ +'use strict'; +require('../common'); +const { collectGCProfile } = require('v8'); +// Test if it makes the process crash. +collectGCProfile({ duration: 5000 }); +collectGCProfile({ duration: 5000 }); diff --git a/test/parallel/test-v8-take-gc-profile-in-worker.js b/test/parallel/test-v8-take-gc-profile-in-worker.js new file mode 100644 index 00000000000000..91e46a5bb99a81 --- /dev/null +++ b/test/parallel/test-v8-take-gc-profile-in-worker.js @@ -0,0 +1,25 @@ +// Flags: --expose-gc +'use strict'; +require('../common'); +const { collectGCProfile } = require('v8'); +const { Worker } = require('worker_threads'); +const { checkGCProfile } = require('../common/v8'); + +async function runInWorker() { + // Keep the event loop alive + const timer = setInterval(() => {}, 10000); + const data = await collectGCProfile({ duration: 5000 }); + clearInterval(timer); + checkGCProfile(data); +} + +if (process.env.isWorker) { + process.env.isWorker = 1; + new Worker(__filename); +} else { + runInWorker(); + for (let i = 0; i < 100; i++) { + new Array(100); + } + global?.gc(); +} diff --git a/test/parallel/test-v8-take-gc-profile.js b/test/parallel/test-v8-take-gc-profile.js new file mode 100644 index 00000000000000..5cdeb0ca2a3940 --- /dev/null +++ b/test/parallel/test-v8-take-gc-profile.js @@ -0,0 +1,28 @@ +// Flags: --expose-gc +'use strict'; +require('../common'); +const assert = require('assert'); +const { collectGCProfile } = require('v8'); +const { checkGCProfile } = require('../common/v8'); + +[undefined, {}].forEach((config) => { + assert.throws(() => { + collectGCProfile(config); + }, /ERR_INVALID_ARG_TYPE/); +}); + +async function run() { + // Keep the event loop alive + const timer = setInterval(() => {}, 10000); + const data = await collectGCProfile({ duration: 5000 }); + clearInterval(timer); + checkGCProfile(data); +} + +run(); + +for (let i = 0; i < 100; i++) { + new Array(100); +} + +global?.gc();