From 02632b42cf2bda3a42cd500187a609fde6d94ad1 Mon Sep 17 00:00:00 2001 From: theanarkh Date: Wed, 25 Jan 2023 20:02:09 +0800 Subject: [PATCH] v8: support gc profile PR-URL: https://github.com/nodejs/node/pull/46255 Reviewed-By: Anna Henningsen Reviewed-By: Rafael Gonzaga Reviewed-By: Franziska Hinkelmann --- doc/api/v8.md | 106 ++++++++++ lib/v8.js | 22 +- src/node_v8.cc | 190 ++++++++++++++++++ src/node_v8.h | 28 +++ test/common/v8.js | 70 +++++++ ...-v8-collect-gc-profile-exit-before-stop.js | 17 ++ .../test-v8-collect-gc-profile-in-worker.js | 16 ++ test/parallel/test-v8-collect-gc-profile.js | 12 ++ 8 files changed, 460 insertions(+), 1 deletion(-) create mode 100644 test/common/v8.js create mode 100644 test/parallel/test-v8-collect-gc-profile-exit-before-stop.js create mode 100644 test/parallel/test-v8-collect-gc-profile-in-worker.js create mode 100644 test/parallel/test-v8-collect-gc-profile.js diff --git a/doc/api/v8.md b/doc/api/v8.md index 9621a9b7621509..3076a199540f13 100644 --- a/doc/api/v8.md +++ b/doc/api/v8.md @@ -1021,6 +1021,112 @@ added: v18.6.0 Returns true if the Node.js instance is run to build a snapshot. +## Class: `v8.GCProfiler` + + + +This API collects GC data in current thread. + +### `new v8.GCProfiler()` + + + +Create a new instance of the `v8.GCProfiler` class. + +### `profiler.start()` + + + +Start collecting GC data. + +### `profiler.stop()` + + + +Stop collecting GC data and return a object.The content of object +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 + } + ] + } + } + ], + "endTime": 1674059036865 +} +``` + +Here's an example. + +```js +const { GCProfiler } = require('v8'); +const profiler = new GCProfiler(); +profiler.start(); +setTimeout(() => { + console.log(profiler.stop()); +}, 1000); +``` + [HTML structured clone algorithm]: https://developer.mozilla.org/en-US/docs/Web/API/Web_Workers_API/Structured_clone_algorithm [Hook Callbacks]: #hook-callbacks [V8]: https://developers.google.com/v8/ diff --git a/lib/v8.js b/lib/v8.js index 479e8b13efc96d..bfca704f5e32cc 100644 --- a/lib/v8.js +++ b/lib/v8.js @@ -60,7 +60,7 @@ const { const { HeapSnapshotStream } = require('internal/heap_utils'); const promiseHooks = require('internal/promise_hooks'); const { getOptionValue } = require('internal/options'); - +const { JSONParse } = primordials; /** * Generates a snapshot of the current V8 heap * and writes it to a JSON file. @@ -384,6 +384,25 @@ function deserialize(buffer) { return der.readValue(); } +class GCProfiler { + #profiler = null; + + start() { + if (!this.#profiler) { + this.#profiler = new binding.GCProfiler(); + this.#profiler.start(); + } + } + + stop() { + if (this.#profiler) { + const data = this.#profiler.stop(); + this.#profiler = null; + return JSONParse(data); + } + } +} + module.exports = { cachedDataVersionTag, getHeapSnapshot, @@ -403,4 +422,5 @@ module.exports = { promiseHooks, startupSnapshot, setHeapSnapshotNearHeapLimit, + GCProfiler, }; diff --git a/src/node_v8.cc b/src/node_v8.cc index 91a3dbb93e0155..890f59eea673c5 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,184 @@ 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; + auto string = profiler->out_stream()->str(); + args.GetReturnValue().Set(String::NewFromUtf8(env->isolate(), + string.data(), + v8::NewStringType::kNormal, + string.size()) + .ToLocalChecked()); +} + void Initialize(Local target, Local unused, Local context, @@ -272,6 +451,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 +468,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..9c247bde50eb8c --- /dev/null +++ b/test/common/v8.js @@ -0,0 +1,70 @@ +'use strict'; +const assert = require('assert'); +const { GCProfiler } = require('v8'); + +function collectGCProfile({ duration }) { + return new Promise((resolve) => { + const profiler = new GCProfiler(); + profiler.start(); + setTimeout(() => { + resolve(profiler.stop()); + }, duration); + }); +} + +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); + }); + } +} + +async function testGCProfiler() { + const data = await collectGCProfile({ duration: 5000 }); + checkGCProfile(data); +} + +module.exports = { + collectGCProfile, + checkGCProfile, + testGCProfiler, +}; diff --git a/test/parallel/test-v8-collect-gc-profile-exit-before-stop.js b/test/parallel/test-v8-collect-gc-profile-exit-before-stop.js new file mode 100644 index 00000000000000..4ef44001236209 --- /dev/null +++ b/test/parallel/test-v8-collect-gc-profile-exit-before-stop.js @@ -0,0 +1,17 @@ +'use strict'; +require('../common'); +const { GCProfiler } = require('v8'); + +// Test if it makes the process crash. +{ + const profiler = new GCProfiler(); + profiler.start(); + profiler.stop(); + profiler.start(); + profiler.stop(); +} +{ + const profiler = new GCProfiler(); + profiler.start(); + profiler.stop(); +} diff --git a/test/parallel/test-v8-collect-gc-profile-in-worker.js b/test/parallel/test-v8-collect-gc-profile-in-worker.js new file mode 100644 index 00000000000000..49762c50fb1c73 --- /dev/null +++ b/test/parallel/test-v8-collect-gc-profile-in-worker.js @@ -0,0 +1,16 @@ +// Flags: --expose-gc +'use strict'; +require('../common'); +const { Worker } = require('worker_threads'); +const { testGCProfiler } = require('../common/v8'); + +if (process.env.isWorker) { + process.env.isWorker = 1; + new Worker(__filename); +} else { + testGCProfiler(); + for (let i = 0; i < 100; i++) { + new Array(100); + } + global?.gc(); +} diff --git a/test/parallel/test-v8-collect-gc-profile.js b/test/parallel/test-v8-collect-gc-profile.js new file mode 100644 index 00000000000000..70a8a0d842ef9e --- /dev/null +++ b/test/parallel/test-v8-collect-gc-profile.js @@ -0,0 +1,12 @@ +// Flags: --expose-gc +'use strict'; +require('../common'); +const { testGCProfiler } = require('../common/v8'); + +testGCProfiler(); + +for (let i = 0; i < 100; i++) { + new Array(100); +} + +global?.gc();