From 2b5c23c3bb22b0102062fa174915553c3c1e25b2 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 | 77 ++++++++ lib/v8.js | 31 ++- src/node_v8.cc | 179 ++++++++++++++++++ src/node_v8.h | 39 ++++ test/common/v8.js | 52 +++++ ...est-v8-take-gc-profile-exit-before-stop.js | 11 ++ .../test-v8-take-gc-profile-in-worker.js | 31 +++ test/parallel/test-v8-take-gc-profile.js | 35 ++++ 8 files changed, 453 insertions(+), 2 deletions(-) create mode 100644 test/common/v8.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..7170a9cb16c1db 100644 --- a/doc/api/v8.md +++ b/doc/api/v8.md @@ -390,6 +390,83 @@ 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.takeGCProfile(options)` + + + +* `options` {Object} + * `filename` {string} Node.js will write data to `filename`. + * `duration` {number} how long you want to collect the gc data. + +* Returns: {Promise} + +This API collects gc data over a period of time and write it to the `filename`. +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..ffedac44ef455f 100644 --- a/lib/v8.js +++ b/lib/v8.js @@ -33,7 +33,7 @@ const { } = primordials; const { Buffer } = require('buffer'); -const { validateString, validateUint32 } = require('internal/validators'); +const { validateString, validateUint32, validateObject, validateNumber } = require('internal/validators'); const { Serializer, Deserializer @@ -63,7 +63,8 @@ const { } = require('internal/heap_utils'); const promiseHooks = require('internal/promise_hooks'); const { getOptionValue } = require('internal/options'); - +const { setUnrefTimeout } = require('internal/timers'); +const { Promise } = primordials; /** * Generates a snapshot of the current V8 heap * and writes it to a JSON file. @@ -397,6 +398,31 @@ function deserialize(buffer) { return der.readValue(); } +/** + * @param {{ + * filename: string, + * duration: number, + * }} [options] + */ +function takeGCProfile(options) { + validateObject(options, 'options'); + validateString(options.filename, 'options.filename'); + validateNumber(options.duration, 'options.duration', 1); + return new Promise((resolve, reject) => { + const profiler = new binding.GCProfiler(); + try { + profiler.startGCProfile(options.filename); + } catch (e) { + reject(e); + return; + } + setUnrefTimeout(() => { + profiler.stopGCProfile(); + resolve(); + }, options.duration); + }); +} + module.exports = { cachedDataVersionTag, getHeapSnapshot, @@ -416,4 +442,5 @@ module.exports = { promiseHooks, startupSnapshot, setHeapSnapshotNearHeapLimit, + takeGCProfile, }; diff --git a/src/node_v8.cc b/src/node_v8.cc index 91a3dbb93e0155..7619bf77d3d0c7 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,173 @@ 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 "UnKnow"; + } +} + +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; + } + profiler->set_current_gc_type(gc_type); + profiler->set_start_time(uv_hrtime()); + JSONWriter* writer = profiler->writer(); + writer->json_start(); + writer->json_keyvalue("gcType", GetGCTypeName(gc_type)); + writer->json_objectstart("beforeGC"); + SetHeapStatistics(writer, isolate); + writer->json_objectend(); +} + +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->set_current_gc_type(0); + u_int64_t start_time = profiler->start_time(); + profiler->set_start_time(0); + writer->json_keyvalue("cost", (uv_hrtime() - start_time) / 1e3); + writer->json_objectstart("afterGC"); + SetHeapStatistics(writer, isolate); + writer->json_objectend(); + writer->json_end(); +} + +GCProfiler::GCProfiler(Environment* env, Local object) + : BaseObject(env, object), writer_(outfile_, false) { + MakeWeak(); +} + +// This function will be called when +// 1. StartGCProfile and StopGCProfile are called and +// JS land do not keep the object any more. +// 2. StartGCProfile is called then the env exits before +// StopGCProfile is called. +GCProfiler::~GCProfiler() { + if (state_ != GCProfilerState::kInitialized) { + env()->isolate()->RemoveGCPrologueCallback(BeforeGCCallback, this); + env()->isolate()->RemoveGCEpilogueCallback(AfterGCCallback, this); + } +} + +void GCProfiler::New(const FunctionCallbackInfo& args) { + CHECK(args.IsConstructCall()); + Environment* env = Environment::GetCurrent(args); + new GCProfiler(env, args.This()); +} + +void GCProfiler::StartGCProfile(const FunctionCallbackInfo& args) { + GCProfiler* profiler; + ASSIGN_OR_RETURN_UNWRAP(&profiler, args.Holder()); + if (profiler->state() != GCProfilerState::kInitialized) { + return; + } + Environment* env = Environment::GetCurrent(args); + Isolate* isolate = args.GetIsolate(); + node::Utf8Value filename(env->isolate(), args[0]); + profiler->outfile()->open(*filename, std::ios::out | std::ios::binary); + if (!profiler->outfile()->is_open()) { + env->ThrowError("failed to open file"); + 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"); + isolate->AddGCPrologueCallback(BeforeGCCallback, + static_cast(profiler)); + isolate->AddGCEpilogueCallback(AfterGCCallback, static_cast(profiler)); + profiler->set_state(GCProfilerState::kStarted); +} + +void GCProfiler::StopGCProfile(const FunctionCallbackInfo& args) { + GCProfiler* profiler; + ASSIGN_OR_RETURN_UNWRAP(&profiler, args.Holder()); + if (profiler->state() != GCProfilerState::kStarted) { + return; + } + profiler->writer()->json_arrayend(); + uv_timeval64_t ts; + if (uv_gettimeofday(&ts) == 0) { + profiler->writer()->json_keyvalue("endtTime", + ts.tv_sec * 1000 + ts.tv_usec / 1000); + } else { + profiler->writer()->json_keyvalue("endtTime", 0); + } + profiler->writer()->json_end(); + profiler->outfile()->close(); + profiler->set_state(GCProfilerState::kStopped); +} + void Initialize(Local target, Local unused, Local context, @@ -272,6 +440,15 @@ 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, "startGCProfile", GCProfiler::StartGCProfile); + SetProtoMethod(env->isolate(), t, "stopGCProfile", GCProfiler::StopGCProfile); + SetConstructorFunction(context, target, "GCProfiler", t); } void RegisterExternalReferences(ExternalReferenceRegistry* registry) { @@ -281,6 +458,8 @@ void RegisterExternalReferences(ExternalReferenceRegistry* registry) { registry->Register(UpdateHeapSpaceStatisticsBuffer); registry->Register(SetFlagsFromString); registry->Register(SetHeapSnapshotNearHeapLimit); + registry->Register(GCProfiler::StartGCProfile); + registry->Register(GCProfiler::StopGCProfile); } } // namespace v8_utils diff --git a/src/node_v8.h b/src/node_v8.h index 18b3621a2a5d6a..50fa164d4f02af 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,43 @@ 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 StartGCProfile(const v8::FunctionCallbackInfo& args); + static void StopGCProfile(const v8::FunctionCallbackInfo& args); + + GCProfilerState state() { return state_; } + + void set_state(GCProfilerState state) { state_ = state; } + + u_int64_t start_time() { return start_time_; } + + void set_start_time(u_int64_t time) { start_time_ = time; } + + u_int8_t current_gc_type() { return current_gc_type_; } + + void set_current_gc_type(u_int8_t type) { current_gc_type_ = type; } + + JSONWriter* writer() { return &writer_; } + + std::ofstream* outfile() { return &outfile_; } + + SET_NO_MEMORY_INFO() + SET_MEMORY_INFO_NAME(GCProfiler) + SET_SELF_SIZE(GCProfiler) + + private: + u_int64_t start_time_ = 0; + u_int8_t current_gc_type_ = 0; + std::ofstream outfile_; + JSONWriter writer_; + GCProfilerState state_ = GCProfilerState::kInitialized; +}; + } // namespace v8_utils } // namespace node diff --git a/test/common/v8.js b/test/common/v8.js new file mode 100644 index 00000000000000..fe0ef3878db042 --- /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.endtTime >= 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-exit-before-stop.js b/test/parallel/test-v8-take-gc-profile-exit-before-stop.js new file mode 100644 index 00000000000000..da78df9ca0c5ec --- /dev/null +++ b/test/parallel/test-v8-take-gc-profile-exit-before-stop.js @@ -0,0 +1,11 @@ +'use strict'; +require('../common'); +const path = require('path'); +const { takeGCProfile } = require('v8'); +const tmpdir = require('../common/tmpdir'); + +tmpdir.refresh(); + +const filename = path.join(tmpdir.path, 'gc.json'); + +takeGCProfile({ filename, 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..53228c6a4c4b4a --- /dev/null +++ b/test/parallel/test-v8-take-gc-profile-in-worker.js @@ -0,0 +1,31 @@ +// Flags: --expose-gc +'use strict'; +require('../common'); +const path = require('path'); +const { takeGCProfile } = require('v8'); +const { Worker } = require('worker_threads'); +const tmpdir = require('../common/tmpdir'); +const { checkGCProfile } = require('../common/v8'); + +tmpdir.refresh(); +const filename = path.join(tmpdir.path, 'gc.json'); + +async function runInWorker() { + // Keep the event loop alive + const timer = setInterval(() => {}, 10000); + await takeGCProfile({ filename, duration: 5000 }); + clearInterval(timer); + const data = require(filename); + 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 && 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..ed85a891d77375 --- /dev/null +++ b/test/parallel/test-v8-take-gc-profile.js @@ -0,0 +1,35 @@ +// Flags: --expose-gc +'use strict'; +require('../common'); +const assert = require('assert'); +const path = require('path'); +const { takeGCProfile } = require('v8'); +const { checkGCProfile } = require('../common/v8'); +const tmpdir = require('../common/tmpdir'); + +tmpdir.refresh(); + +const filename = path.join(tmpdir.path, 'gc.json'); + +[undefined, { duration: 1000 }, { filename }].forEach((config) => { + assert.throws(() => { + takeGCProfile(config); + }, /ERR_INVALID_ARG_TYPE/); +}); + +async function run() { + // Keep the event loop alive + const timer = setInterval(() => {}, 10000); + await takeGCProfile({ filename, duration: 5000 }); + clearInterval(timer); + const data = require(filename); + checkGCProfile(data); +} + +run(); + +for (let i = 0; i < 100; i++) { + new Array(100); +} + +global.gc && global.gc();