程序员经验分享-hwhale

用于测量 GC 活动的 V8 垃圾收集器回调

2024-04-09

我有一个关于V8的小问题6.7.240GC 行为和AddGCPrologueCallback/AddGCEpilogueCallback回调。

问题背后的一个小故事：我们使用 V8 引擎启动自定义 JS 代码，为了限制执行时间，我们有一个watchdog（单独的线程与isolate->TerminateExecution()call）监视代码并在长时间运行时杀死它，但与 GC 活动有关。

因此，如果代码执行超时等于200ms, GC 活动需要300ms代码需要199ms我们会没事的（199ms < 200ms, 300ms不包括在内）。

另一方面，如果代码执行超时等于200ms, GC 活动需要300ms代码需要201ms这将是执行超时（201ms > 200ms, 300ms不包括在内）。

正如您所看到的，精确的 GC 测量非常重要，因为如果 GC 活动花费的时间超过回调指示的时间，则可能会导致以下情况watchdog会注意到代码运行时间太长并杀死它，但实际上 GC 活动（以及“停止世界”方法）“吃掉”时间，而没有任何迹象表明这一点。

看来这正是我们在测试和调试过程中注意到的。让我们来看看：

V8 side:

// init step
api,v8::Context::New
[api,v8::FunctionTemplate::New]

// a little bit fancy way of converting string to object
// like JSON:Parse call, but doing that using global JSON object
// no problem with that, just part of the log
api,v8::String::NewFromUtf8
api,v8::Object::Get
api,v8::String::NewFromUtf8
api,v8::Object::Get
api,v8::String::NewFromUtf8
timer-event-start,V8.GCIncrementalMarking,6406056058
timer-event-end,V8.GCIncrementalMarking,6406056581
api,v8::Function::Call

// actually function run
// script->Run(context);
timer-event-start,V8.Execute,6406057062
timer-event-start,V8.GCIncrementalMarking,6406057179
timer-event-end,V8.GCIncrementalMarking,6406059180
timer-event-start,V8.GCIncrementalMarking,6406060424
timer-event-end,V8.GCIncrementalMarking,6406062569
timer-event-start,V8.GCIncrementalMarking,6406063674
timer-event-end,V8.GCIncrementalMarking,6406065864
timer-event-start,V8.GCIncrementalMarking,6406066891
timer-event-end,V8.GCIncrementalMarking,6406068970
timer-event-start,V8.GCIncrementalMarking,6406069912
timer-event-end,V8.GCIncrementalMarking,6406070711
timer-event-start,V8.GCIncrementalMarking,6406071368
timer-event-end,V8.GCIncrementalMarking,6406073392
timer-event-start,V8.GCIncrementalMarking,6406074204
timer-event-end,V8.GCIncrementalMarking,6406076411
timer-event-start,V8.GCIncrementalMarking,6406077223
timer-event-end,V8.GCIncrementalMarking,6406079326
timer-event-start,V8.GCIncrementalMarking,6406080096
timer-event-end,V8.GCIncrementalMarking,6406082253
timer-event-start,V8.GCIncrementalMarking,6406083041
timer-event-end,V8.GCIncrementalMarking,6406085169
timer-event-start,V8.GCIncrementalMarking,6406085754
timer-event-end,V8.GCIncrementalMarking,6406087852
timer-event-start,V8.GCIncrementalMarking,6406088753
timer-event-end,V8.GCIncrementalMarking,6406090888
timer-event-start,V8.GCIncrementalMarking,6406091704
timer-event-end,V8.GCIncrementalMarking,6406093860
timer-event-start,V8.GCIncrementalMarking,6406094638
timer-event-end,V8.GCIncrementalMarking,6406096819
timer-event-start,V8.GCIncrementalMarking,6406097737
timer-event-end,V8.GCIncrementalMarking,6406099851
timer-event-start,V8.GCIncrementalMarking,6406100651
timer-event-end,V8.GCIncrementalMarking,6406102158
timer-event-start,V8.GCIncrementalMarking,6406102830
timer-event-end,V8.GCIncrementalMarking,6406102949
timer-event-start,V8.GCIncrementalMarkingFinalize,6406103476
timer-event-end,V8.GCIncrementalMarkingFinalize,6406103720
timer-event-start,V8.GCIncrementalMarking,6406103781
timer-event-end,V8.GCIncrementalMarking,6406103805
timer-event-start,V8.GCFinalizeMC,6406106106
markcompact,begin,37,733899,1573929817539
sfi-move,0x26c8c6b42258,0x39727ab446f0
sfi-move,0x26c8c6b423d0,0x39727ab44858
code-move,0x26c8c6b424a8,0x39727ab44920
code-move,0x26c8c6b42990,0x39727ab44e08
[delete,MemoryChunk,0x20803a500000]
markcompact,end,37,750515,1573929817560
timer-event-end,V8.GCFinalizeMC,6406126613
[delete,MemoryChunk,0x2fcf14300000]
timer-event-start,V8.GCIncrementalMarkingStart,
timer-event-end,V8.GCIncrementalMarkingStart,6406148920
timer-event-start,V8.GCIncrementalMarking,6406148975
timer-event-end,V8.GCIncrementalMarking,6406150059
timer-event-start,V8.GCIncrementalMarking,6406151014
timer-event-end,V8.GCIncrementalMarking,6406152657
timer-event-start,V8.GCIncrementalMarking,6406153356
timer-event-end,V8.GCIncrementalMarking,6406154995
timer-event-start,V8.GCIncrementalMarking,6406155703
timer-event-end,V8.GCIncrementalMarking,6406157341
new,MemoryChunk,0x24eee1900000,524288
timer-event-start,V8.GCIncrementalMarking,6406158486
timer-event-end,V8.GCIncrementalMarking,6406160149
new,MemoryChunk,0x7f310200000,524288
timer-event-start,V8.GCIncrementalMarking,6406161218
timer-event-end,V8.GCIncrementalMarking,6406162914
new,MemoryChunk,0x178aad500000,524288
timer-event-start,V8.GCIncrementalMarking,6406163990
timer-event-end,V8.GCIncrementalMarking,6406165681
new,MemoryChunk,0x34d7b2580000,524288
timer-event-start,V8.GCIncrementalMarking,6406166748
timer-event-end,V8.GCIncrementalMarking,6406168439
new,MemoryChunk,0x225fec080000,524288
timer-event-start,V8.GCIncrementalMarking,6406169481
timer-event-end,V8.GCIncrementalMarking,6406171229
new,MemoryChunk,0x502e7380000,524288
timer-event-start,V8.GCIncrementalMarking,6406172280
timer-event-end,V8.GCIncrementalMarking,6406174003
new,MemoryChunk,0x208b2af00000,524288
timer-event-start,V8.GCIncrementalMarking,6406175047
timer-event-end,V8.GCIncrementalMarking,6406176787
new,MemoryChunk,0x39ffd8400000,524288
timer-event-start,V8.GCIncrementalMarking,6406177851
timer-event-end,V8.GCIncrementalMarking,6406179600
new,MemoryChunk,0x10408d480000,524288
timer-event-start,V8.GCIncrementalMarking,6406180631
timer-event-end,V8.GCIncrementalMarking,6406182384
new,MemoryChunk,0x25c069e80000,524288
timer-event-start,V8.GCIncrementalMarking,6406183415
timer-event-end,V8.GCIncrementalMarking,6406185165
new,MemoryChunk,0x20cb51c80000,524288
timer-event-start,V8.GCIncrementalMarking,6406186210
timer-event-end,V8.GCIncrementalMarking,6406186919
new,MemoryChunk,0xe774a300000,524288
timer-event-start,V8.GCIncrementalMarking,6406187940
timer-event-end,V8.GCIncrementalMarking,6406188387
new,MemoryChunk,0x23a0a1180000,524288
timer-event-start,V8.GCIncrementalMarking,6406189172
timer-event-end,V8.GCIncrementalMarking,6406189924
new,MemoryChunk,0x16bb70600000,524288
timer-event-start,V8.GCIncrementalMarking,6406190724
timer-event-end,V8.GCIncrementalMarking,6406192029
new,MemoryChunk,0x18b8a0200000,524288
timer-event-start,V8.GCIncrementalMarking,6406192894
timer-event-end,V8.GCIncrementalMarking,6406194253
new,MemoryChunk,0x11c87c180000,524288
timer-event-start,V8.GCIncrementalMarking,6406195137
timer-event-end,V8.GCIncrementalMarking,6406196462
new,MemoryChunk,0x353b80280000,524288
timer-event-start,V8.GCIncrementalMarking,6406197381
timer-event-end,V8.GCIncrementalMarking,6406198513
new,MemoryChunk,0x991e5a80000,524288
timer-event-start,V8.GCIncrementalMarking,6406199347
timer-event-end,V8.GCIncrementalMarking,6406200659
new,MemoryChunk,0x77559500000,524288
timer-event-start,V8.GCIncrementalMarking,6406201554
timer-event-end,V8.GCIncrementalMarking,6406202952
new,MemoryChunk,0x51fcc580000,524288
timer-event-start,V8.GCIncrementalMarking,6406203842
timer-event-end,V8.GCIncrementalMarking,6406205229
new,MemoryChunk,0x11134ca80000,524288
timer-event-start,V8.GCIncrementalMarking,6406206124
timer-event-end,V8.GCIncrementalMarking,6406207561
new,MemoryChunk,0x17b32eb00000,524288
timer-event-start,V8.GCIncrementalMarking,6406208473
timer-event-end,V8.GCIncrementalMarking,6406209913
new,MemoryChunk,0xa7929400000,524288
timer-event-start,V8.GCIncrementalMarking,6406210795
timer-event-end,V8.GCIncrementalMarking,6406212249
new,MemoryChunk,0x1f76e7200000,524288
timer-event-start,V8.GCIncrementalMarking,6406213115
timer-event-end,V8.GCIncrementalMarking,6406214629
new,MemoryChunk,0x4bb9cd00000,524288
timer-event-start,V8.GCIncrementalMarking,6406215548
timer-event-end,V8.GCIncrementalMarking,6406216079
new,MemoryChunk,0x26fd04080000,524288
timer-event-start,V8.GCIncrementalMarking,6406216911
timer-event-end,V8.GCIncrementalMarking,6406217106
timer-event-start,V8.GCIncrementalMarkingFinalize,6406217606
timer-event-end,V8.GCIncrementalMarkingFinalize,6406217921
new,MemoryChunk,0x3e8b51000000,524288
timer-event-start,V8.GCIncrementalMarking,6406218332
timer-event-end,V8.GCIncrementalMarking,6406218348
timer-event-start,V8.GCFinalizeMC,6406218897
markcompact,begin,38,36462,1573929817653
markcompact,end,38,54306,1573929817670
timer-event-end,V8.GCFinalizeMC,6406237199
new,MemoryChunk,0x3e70a1a00000,524288
new,MemoryChunk,0x14c9e4180000,524288
new,MemoryChunk,0x335947c80000,524288
timer-event-start,V8.GCIncrementalMarkingStart,6406263779
timer-event-end,V8.GCIncrementalMarkingStart,6406264145
new,MemoryChunk,0x1bf6fd00000,524288
timer-event-start,V8.GCIncrementalMarking,6406264575
timer-event-end,V8.GCIncrementalMarking,6406266175
new,MemoryChunk,0x109d6f780000,524288
timer-event-start,V8.GCIncrementalMarking,6406267498
timer-event-end,V8.GCIncrementalMarking,6406269125
new,MemoryChunk,0xcf3b9200000,524288
timer-event-start,V8.GCIncrementalMarking,6406270226
timer-event-end,V8.GCIncrementalMarking,6406271868
new,MemoryChunk,0x33eb2c880000,524288
timer-event-start,V8.GCIncrementalMarking,6406272919
timer-event-end,V8.GCIncrementalMarking,6406274608
new,MemoryChunk,0x10c056a80000,524288
timer-event-start,V8.GCIncrementalMarking,6406275660
timer-event-end,V8.GCIncrementalMarking,6406277318
new,MemoryChunk,0x1846c1880000,524288
timer-event-start,V8.GCIncrementalMarking,6406278406
timer-event-end,V8.GCIncrementalMarking,6406280119
new,MemoryChunk,0x21eed5900000,524288
timer-event-start,V8.GCIncrementalMarking,6406281176
timer-event-end,V8.GCIncrementalMarking,6406282888
new,MemoryChunk,0x323ac6b80000,524288
timer-event-start,V8.GCIncrementalMarking,6406283954
timer-event-end,V8.GCIncrementalMarking,6406285682
new,MemoryChunk,0x3c2009d00000,524288
timer-event-start,V8.GCIncrementalMarking,6406286739
timer-event-end,V8.GCIncrementalMarking,6406288466
new,MemoryChunk,0x3d504cd00000,524288
timer-event-start,V8.GCIncrementalMarking,6406289535
timer-event-end,V8.GCIncrementalMarking,6406291291
new,MemoryChunk,0x235494980000,524288
timer-event-start,V8.GCIncrementalMarking,6406292373
timer-event-end,V8.GCIncrementalMarking,6406294127
new,MemoryChunk,0xecfc3600000,524288
timer-event-start,V8.GCIncrementalMarking,6406295191
timer-event-end,V8.GCIncrementalMarking,6406296997
new,MemoryChunk,0x1a2eae600000,524288
timer-event-start,V8.GCIncrementalMarking,6406298083
timer-event-end,V8.GCIncrementalMarking,6406299894
timer-event-end,V8.Execute,6406300603

应用端：

(1) // kGCTypeIncrementalMarking
[18:43:37.536(1573929817536752)][DEBUG]: GCPrologueCallback type: 4
[18:43:37.536(1573929817536955)][DEBUG]: GCEpilogCallback type: 4
Total: 203 micro


(2) // kGCTypeMarkSweepCompact
[18:43:37.539(1573929817539368)][DEBUG]: GCPrologueCallback type: 2
[18:43:37.559(1573929817559840)][DEBUG]: GCEpilogCallback type: 2
Total: 20472 micro


(3) // kGCTypeIncrementalMarking
[18:43:37.650(1573929817650874)][DEBUG]: GCPrologueCallback type: 4
[18:43:37.651(1573929817651154)][DEBUG]: GCEpilogCallback type: 4
Total: 280 micro


(4) // kGCTypeMarkSweepCompact
[18:43:37.652(1573929817652160)][DEBUG]: GCPrologueCallback type: 2
[18:43:37.670(1573929817670422)][DEBUG]: GCEpilogCallback type: 2
Total: 18262 micro

因此，总共 39217 微秒或 40 毫秒。

这样读取V8日志太复杂了。所以我通过测量之间的时间对其进行了一些后处​​理timer-event-start/timer-event-end events.

(V8.GCIncrementalMarking, 523)
(V8.GCIncrementalMarking, 2001)
(V8.GCIncrementalMarking, 2145)
(V8.GCIncrementalMarking, 2190)
(V8.GCIncrementalMarking, 2079)
(V8.GCIncrementalMarking, 799)
(V8.GCIncrementalMarking, 2024)
(V8.GCIncrementalMarking, 2207)
(V8.GCIncrementalMarking, 2103)
(V8.GCIncrementalMarking, 2157)
(V8.GCIncrementalMarking, 2128)
(V8.GCIncrementalMarking, 2098)
(V8.GCIncrementalMarking, 2135)
(V8.GCIncrementalMarking, 2156)
(V8.GCIncrementalMarking, 2181)
(V8.GCIncrementalMarking, 2114)
(V8.GCIncrementalMarking, 1507)
(V8.GCIncrementalMarking, 119)
(V8.GCIncrementalMarkingFinalize, 244)        (1)
(V8.GCIncrementalMarking, 24)
(V8.GCFinalizeMC, 20507)                      (2)
(V8.GCIncrementalMarkingStart, 428)
(V8.GCIncrementalMarking, 1084)
(V8.GCIncrementalMarking, 1643)
(V8.GCIncrementalMarking, 1639)
(V8.GCIncrementalMarking, 1638)
(V8.GCIncrementalMarking, 1663)
(V8.GCIncrementalMarking, 1696)
(V8.GCIncrementalMarking, 1691)
(V8.GCIncrementalMarking, 1691)
(V8.GCIncrementalMarking, 1748)
(V8.GCIncrementalMarking, 1723)
(V8.GCIncrementalMarking, 1740)
(V8.GCIncrementalMarking, 1749)
(V8.GCIncrementalMarking, 1753)
(V8.GCIncrementalMarking, 1750)
(V8.GCIncrementalMarking, 709)
(V8.GCIncrementalMarking, 447)
(V8.GCIncrementalMarking, 752)
(V8.GCIncrementalMarking, 1305)
(V8.GCIncrementalMarking, 1359)
(V8.GCIncrementalMarking, 1325)
(V8.GCIncrementalMarking, 1132)
(V8.GCIncrementalMarking, 1312)
(V8.GCIncrementalMarking, 1398)
(V8.GCIncrementalMarking, 1387)
(V8.GCIncrementalMarking, 1437)
(V8.GCIncrementalMarking, 1440)
(V8.GCIncrementalMarking, 1454)
(V8.GCIncrementalMarking, 1514)
(V8.GCIncrementalMarking, 531)
(V8.GCIncrementalMarking, 195)
(V8.GCIncrementalMarkingFinalize, 315)        (3)
(V8.GCIncrementalMarking, 16)
(V8.GCFinalizeMC, 18302)                      (4)
(V8.GCIncrementalMarkingStart, 366)
(V8.GCIncrementalMarking, 1600)
(V8.GCIncrementalMarking, 1627)
(V8.GCIncrementalMarking, 1642)
(V8.GCIncrementalMarking, 1689)
(V8.GCIncrementalMarking, 1658)
(V8.GCIncrementalMarking, 1713)
(V8.GCIncrementalMarking, 1712)
(V8.GCIncrementalMarking, 1728)
(V8.GCIncrementalMarking, 1727)
(V8.GCIncrementalMarking, 1756)
(V8.GCIncrementalMarking, 1754)
(V8.GCIncrementalMarking, 1806)
(V8.GCIncrementalMarking, 1811)
(Total, 135996)

正如你所看到的，我们只能匹配 4 个案例，但是很多GCIncrementalMarking活动未被注意到。 真实的总时间等于136ms。远远超过 40 毫秒！，我们能够在应用程序端测量。

我知道奥里诺科河和并行方法，但我不知道是否调用GCIncrementalMarking是否阻止代码执行。

我们已经多次注意到相同的情况，并且在所有情况下，代码终止的原因都是与 V8 日志文件相比，应用程序端的 GC 测量不正确。

这是故意的吗？我们不能那么信任 GC 回调吗？或者我错过了什么？ 作为临时解决方案，我们将 V8 降级为5.6.316而且效果还不错..

6.7.240有新的 GC 方法，这可能是该问题的根源吗？

PS. --single-threaded-gc for 6.7.240也没有帮助

聚苯硫醚。一些与V8和GC逻辑相关的代码：

void cnode::V8Runner::init() {    
    v8::V8::InitializeICU();

    v8::Platform *platform = v8::platform::CreateDefaultPlatform();
    v8::V8::InitializePlatform(platform);
    v8::V8::Initialize();

    auto flags = "--log --log-all --logfile=/tmp/v8.log --nolazy";
    auto isolate = cnode::V8Runner::getIsolate();

    isolate->AddGCPrologueCallback(cnode::V8Runner::_GCPrologue);
    isolate->AddGCEpilogueCallback(cnode::V8Runner::_GCEpilog);
}

void cnode::V8Runner::_GCPrologue(v8::Isolate *isolate, v8::GCType type,
                                  v8::GCCallbackFlags flags) {    
    cnode::V8Runner::_GCPrologueTimePoint = std::chrono::high_resolution_clock::now();
    cnode::V8Runner::_GCEpilogTimePoint = std::chrono::high_resolution_clock::now();

    LOG_DEBUG("GCPrologueCallback type: %d", type);
}

void cnode::V8Runner::_GCEpilog(v8::Isolate *isolate, v8::GCType type,
                                v8::GCCallbackFlags flags) {    
    cnode::V8Runner::_GCEpilogTimePoint = std::chrono::high_resolution_clock::now();

    std::chrono::milliseconds _GCPrologueTimePointMs = std::chrono::duration_cast<std::chrono::milliseconds>(
            cnode::V8Runner::_GCPrologueTimePoint.time_since_epoch());
    std::chrono::milliseconds _GCEpilogTimePointMs = std::chrono::duration_cast<std::chrono::milliseconds>(
            cnode::V8Runner::_GCEpilogTimePoint.time_since_epoch());

    const int diff = _GCEpilogTimePointMs.count() - _GCPrologueTimePointMs.count();

    cnode::V8Runner::_currentGCActionMs += diff;

    cnode::V8Runner::_GCPrologueTimePoint = std::chrono::high_resolution_clock::now();
    cnode::V8Runner::_GCEpilogTimePoint = std::chrono::high_resolution_clock::now();

    LOG_DEBUG("GCEpilogCallback type: %d", type);
}

购买力平价。 在这篇文章之后，我决定使用手动调用来重新检查这一点Isolate::LowMemoryNotification()每次代码执行后。

原始 V8 日志：

api,v8::Context::New
api,v8::FunctionTemplate::New
api,v8::ObjectTemplate::New
[api,v8::FunctionTemplate::New]
api,v8::String::NewFromUtf8
api,v8::JSON::Parse
[new,MemoryChunk,0x1940b7d00000,524288]
timer-event-start,V8.GCIncrementalMarkingStart,4351782723
timer-event-end,V8.GCIncrementalMarkingStart,4351783066
new,MemoryChunk,0x106dca200000,524288
timer-event-start,V8.GCIncrementalMarking,4351783463
timer-event-end,V8.GCIncrementalMarking,4351785131
new,MemoryChunk,0x225019c00000,524288
timer-event-start,V8.GCIncrementalMarking,4351786485
timer-event-end,V8.GCIncrementalMarking,4351788194
new,MemoryChunk,0xdfc50c80000,524288
timer-event-start,V8.GCIncrementalMarking,4351789202
timer-event-end,V8.GCIncrementalMarking,4351790879
new,MemoryChunk,0x26861a780000,524288
timer-event-start,V8.GCIncrementalMarking,4351791905
timer-event-end,V8.GCIncrementalMarking,4351793611
new,MemoryChunk,0x44086a00000,524288
timer-event-start,V8.GCIncrementalMarking,4351794615
timer-event-end,V8.GCIncrementalMarking,4351796319
new,MemoryChunk,0x4debd600000,524288
timer-event-start,V8.GCIncrementalMarking,4351797315
timer-event-end,V8.GCIncrementalMarking,4351799066
new,MemoryChunk,0x2db69c500000,524288
timer-event-start,V8.GCIncrementalMarking,4351800060
timer-event-end,V8.GCIncrementalMarking,4351801814
new,MemoryChunk,0x1f1825000000,524288
timer-event-start,V8.GCIncrementalMarking,4351802804
timer-event-end,V8.GCIncrementalMarking,4351804535
new,MemoryChunk,0x86246080000,524288
timer-event-start,V8.GCIncrementalMarking,4351805573
timer-event-end,V8.GCIncrementalMarking,4351807383
new,MemoryChunk,0xfc3bb580000,524288
timer-event-start,V8.GCIncrementalMarking,4351808377
timer-event-end,V8.GCIncrementalMarking,4351810192
new,MemoryChunk,0x10451e500000,524288
timer-event-start,V8.GCIncrementalMarking,4351811223
timer-event-end,V8.GCIncrementalMarking,4351813019
new,MemoryChunk,0x16e643c00000,524288
timer-event-start,V8.GCIncrementalMarking,4351814010
timer-event-end,V8.GCIncrementalMarking,4351815842
new,MemoryChunk,0x2a4379600000,524288
timer-event-start,V8.GCIncrementalMarking,4351816837
timer-event-end,V8.GCIncrementalMarking,4351818621
new,MemoryChunk,0x18436f400000,524288
timer-event-start,V8.GCIncrementalMarking,4351819650
timer-event-end,V8.GCIncrementalMarking,4351821491
new,MemoryChunk,0x3b377700000,524288
timer-event-start,V8.GCIncrementalMarking,4351822503
timer-event-end,V8.GCIncrementalMarking,4351824007
new,MemoryChunk,0x1f2f22600000,524288
timer-event-start,V8.GCIncrementalMarking,4351825011
timer-event-end,V8.GCIncrementalMarking,4351825827
new,MemoryChunk,0x1cd733a80000,524288
timer-event-start,V8.GCIncrementalMarking,4351826871
timer-event-end,V8.GCIncrementalMarking,4351827291
new,MemoryChunk,0x3cf039a80000,524288
timer-event-start,V8.GCIncrementalMarking,4351828058
timer-event-end,V8.GCIncrementalMarking,4351828500
new,MemoryChunk,0x31ae7100000,524288
timer-event-start,V8.GCIncrementalMarking,4351829286
timer-event-end,V8.GCIncrementalMarking,4351830586    
new,MemoryChunk,0x2265e4c00000,524288
timer-event-start,V8.GCIncrementalMarking,4351831462
timer-event-end,V8.GCIncrementalMarking,4351832806
new,MemoryChunk,0x34586ae00000,524288
timer-event-start,V8.GCIncrementalMarking,4351833700
timer-event-end,V8.GCIncrementalMarking,4351835122
new,MemoryChunk,0x21c0aa580000,524288    
timer-event-start,V8.GCIncrementalMarking,4351836000
timer-event-end,V8.GCIncrementalMarking,4351837409
new,MemoryChunk,0x2d29cda00000,524288
timer-event-start,V8.GCIncrementalMarking,4351838280
timer-event-end,V8.GCIncrementalMarking,4351839701
new,MemoryChunk,0x216cbbb80000,524288
timer-event-start,V8.GCIncrementalMarking,4351840569
timer-event-end,V8.GCIncrementalMarking,4351842015
new,MemoryChunk,0x1fb82e480000,524288
timer-event-start,V8.GCIncrementalMarking,4351842910
timer-event-end,V8.GCIncrementalMarking,4351844380
new,MemoryChunk,0x329529f00000,524288
timer-event-start,V8.GCIncrementalMarking,4351845255
timer-event-end,V8.GCIncrementalMarking,4351846654    
new,MemoryChunk,0x957ccf80000,524288
timer-event-start,V8.GCIncrementalMarking,4351847553
timer-event-end,V8.GCIncrementalMarking,4351848991
new,MemoryChunk,0x2df008e00000,524288
timer-event-start,V8.GCIncrementalMarking,4351849864
timer-event-end,V8.GCIncrementalMarking,4351851358
new,MemoryChunk,0x8be2be80000,524288
timer-event-start,V8.GCIncrementalMarking,4351852237
timer-event-end,V8.GCIncrementalMarking,4351853720
new,MemoryChunk,0x146846980000,524288
timer-event-start,V8.GCIncrementalMarking,4351854588
timer-event-end,V8.GCIncrementalMarking,4351856080
new,MemoryChunk,0x367cfe280000,524288
timer-event-start,V8.GCIncrementalMarking,4351856969
timer-event-end,V8.GCIncrementalMarking,4351858491
new,MemoryChunk,0x6ed38180000,524288
timer-event-start,V8.GCIncrementalMarking,4351859382
timer-event-end,V8.GCIncrementalMarking,4351860900
new,MemoryChunk,0xfbd5f600000,524288
timer-event-start,V8.GCIncrementalMarking,4351861805
timer-event-end,V8.GCIncrementalMarking,4351863367
new,MemoryChunk,0x1a5e01680000,524288
timer-event-start,V8.GCIncrementalMarking,4351864277
timer-event-end,V8.GCIncrementalMarking,4351865092
new,MemoryChunk,0x24120d700000,524288
timer-event-start,V8.GCIncrementalMarking,4351865984
timer-event-end,V8.GCIncrementalMarking,4351866048
new,MemoryChunk,0x125d39480000,524288
timer-event-start,V8.GCIncrementalMarking,4351866808
timer-event-end,V8.GCIncrementalMarking,4351866824
timer-event-start,V8.GCIncrementalMarkingFinalize,4351867246
timer-event-end,V8.GCIncrementalMarkingFinalize,4351867419
new,MemoryChunk,0x2f31d9400000,524288
timer-event-start,V8.GCIncrementalMarking,4351867767
timer-event-end,V8.GCIncrementalMarking,4351867774
timer-event-start,V8.GCFinalizeMC,4351869855
markcompact,begin,7143,825650,1575032707066
markcompact,end,7143,846265,1575032707086
timer-event-end,V8.GCFinalizeMC,4351890363
[new,MemoryChunk,0x19b52bb00000,524288]
timer-event-start,V8.GCLowMemoryNotification,4351984850
timer-event-start,V8.GCCompactor,4351984910
markcompact,begin,7143,949018,1575032707181
[delete,MemoryChunk,0xd202f700000]
markcompact,end,7144,188469,1575032707268
timer-event-end,V8.GCCompactor,4352073048
[delete,MemoryChunk,0x1c887fa80000]    
timer-event-start,V8.GCCompactor,4352073343
markcompact,begin,7144,192691,1575032707270
new,MemoryChunk,0x33c543500000,524288
new,MemoryChunk,0xd4241800000,524288
[sfi-move,0x8b6f5421390,0xd424181d470]
[delete,MemoryChunk,0x1455b1780000]
markcompact,end,7144,453893,1575032707371
timer-event-end,V8.GCCompactor,4352175676
delete,MemoryChunk,0x25fae9b80000
delete,MemoryChunk,0x2590e9700000
timer-event-end,V8.GCLowMemoryNotification,4352175844
api,v8::ObjectTemplate::New
api,v8::FunctionTemplate::New
api,v8::String::NewFromUtf8

应用日志：

(1) // kGCTypeIncrementalMarking
[13:05:07.063(1575032707063270)][DEBUG]: GCPrologueCallback type: 4
[13:05:07.063(1575032707063418)][DEBUG]: GCEpilogCallback type: 4
Total: 148micro

(2) // kGCTypeMarkSweepCompact
[13:05:07.065(1575032707065876)][DEBUG]: GCPrologueCallback type: 2
[13:05:07.086(1575032707086356)][DEBUG]: GCEpilogCallback type: 2
Total: 20480 micro

(3) // kGCTypeMarkSweepCompact
[13:05:07.180(1575032707180925)][DEBUG]: GCPrologueCallback type: 2
[13:05:07.269(1575032707269036)][DEBUG]: GCEpilogCallback type: 2

(4) // kGCTypeMarkSweepCompact
[13:05:07.269(1575032707269366)][DEBUG]: GCPrologueCallback type: 2
[13:05:07.371(1575032707371667)][DEBUG]: GCEpilogCallback type: 2

后处理后的V8 Log：

(V8.GCIncrementalMarkingStart, 343)          (1)?
(V8.GCIncrementalMarking, 1668)
(V8.GCIncrementalMarking, 1709)
(V8.GCIncrementalMarking, 1677)
(V8.GCIncrementalMarking, 1706)
(V8.GCIncrementalMarking, 1704)
(V8.GCIncrementalMarking, 1751)
(V8.GCIncrementalMarking, 1754)
(V8.GCIncrementalMarking, 1731)
(V8.GCIncrementalMarking, 1810)
(V8.GCIncrementalMarking, 1815)
(V8.GCIncrementalMarking, 1796)
(V8.GCIncrementalMarking, 1832)
(V8.GCIncrementalMarking, 1784)
(V8.GCIncrementalMarking, 1841)
(V8.GCIncrementalMarking, 1504)
(V8.GCIncrementalMarking, 816)
(V8.GCIncrementalMarking, 420)
(V8.GCIncrementalMarking, 442)
(V8.GCIncrementalMarking, 1300)
(V8.GCIncrementalMarking, 1344)
(V8.GCIncrementalMarking, 1422)
(V8.GCIncrementalMarking, 1409)
(V8.GCIncrementalMarking, 1421)
(V8.GCIncrementalMarking, 1446)
(V8.GCIncrementalMarking, 1470)
(V8.GCIncrementalMarking, 1399)
(V8.GCIncrementalMarking, 1438)
(V8.GCIncrementalMarking, 1494)
(V8.GCIncrementalMarking, 1483)
(V8.GCIncrementalMarking, 1492)
(V8.GCIncrementalMarking, 1522)
(V8.GCIncrementalMarking, 1518)
(V8.GCIncrementalMarking, 1562)
(V8.GCIncrementalMarking, 815)
(V8.GCIncrementalMarking, 64)
(V8.GCIncrementalMarking, 16)
(V8.GCIncrementalMarkingFinalize, 173)
(V8.GCIncrementalMarking, 7)
(V8.GCFinalizeMC, 20508)                  (2)
// call to LowMemoryNotification
(V8.GCCompactor, 88138)                   (3)
(V8.GCCompactor, 102333)                  (4)
(V8.GCLowMemoryNotification, 190994)
(Total, 452871)

当我看到这个时，我的第一个想法是 - V8.GCLowMemoryNotification (190994) 包括 V8.GCCompactor(88138) 和 V8.GCCompactor(102333)..毕竟 (88138 + 102333)

所以，大概V8.GCIncrementalMarking也被纳入V8.GCFinalizeMC。但事实证明并非如此——20508远小于数量GCIncrementalMarkings 值（50555).

这个故事最终的结果都是一样的——执行超时。代码的时间限制等于200ms.

Call to LowMemoryNotification不包括在watchdog监控。所以452871 - 190994 = 261877.

请记住，我们尊重 GC 活动，所以261877 - 20508 = 241369。仍然大于200ms。

但是，如果我们开始计算所有V8.GCIncrementalMarking活动 （50555微秒），最终结果将是241369 - 50555 = 190814. 190ms- 没有超时！

我仍然认为V8（6.7.240）在 GC 活动方面没有提供足够的准确性。


V8 开发者在这里。如果我正确理解这个问题，那么答案是：GC prologue/epilogue 回调在开始/结束时调用一个主要的 GC 周期，它由（可能是数百个）增量标记步骤和最后稍长的完成阶段组成，所有这些都与常规程序执行混合在一起。回调不会在每个增量标记步骤周围调用，也不会在次要 GC 周期（“清理”，奇怪的是，上面的各种日志中完全缺失）周围调用，并且不旨在提供精确的计时信息。对不起。

理想情况下，您不必执行任何这些操作。对于大多数程序来说，GC 所花费的时间大约占总执行时间的 1% 到 10%，因此应该没什么影响。

如果您确实坚持跟踪在主要 GC 上花费的主线程时间，那么您最好的选择可能是关闭增量标记（标志--noincremental-marking）。请注意，这将使用户体验更加不稳定（而不是数百个亚 1 毫秒的暂停，您将得到几秒长的暂停），但也许在您的场景中您并不关心。我没有关于涵盖小型 GC 的建议。

也就是说，如果您允许发表更一般性的评论，我对整体方法持怀疑态度。 GC 活动由分配触发，可以视为分配成本的一部分。如果您的目标是“公平”地对待程序（甚至可能是在竞争意义上？），那么我绝对会将 GC 时间包含在每个程序的时间预算中。 GC 并不是“突然随机地攻击表现良好的代码”——对于分配大量内存的代码来说，必须花时间进行 GC 活动；如果代码想要保持在一定的时间预算内，那么最好尝试尽可能少地分配，这只是快速/高效的一方面。

也许底层的心理模型是一种非常简单的内存管理策略，例如许多代码片段可以在没有任何 GC 活动的情况下运行，并分别分配几兆字节，然后其中一个是压垮骆驼的倒霉的最后一根稻草，跨越某个阈值，并以严重的减速运行，清理每个人都需要的垃圾还有人留下来吗？在这样的 VM 中，您的方法完全有意义，但这与 V8 的工作方式相去甚远。

此外，GC 并不是主线程的唯一中断，还有函数优化（的前台部分），它周围没有任何嵌入器控制的回调。如果您想排除所有干扰，则必须破解 V8 以创建一种方法来排除这些干扰。另一方面，我上面的论点也适用于此：优化不会随机发生，它发生在长时间运行的代码上，并且通常有利于整体性能（否则我们不会这样做），所以我认为它会是就像 GC 时间一样，将其纳入预算是公平/适当的。

本文内容由网友自发贡献，版权归原作者所有，本站不承担相应法律责任。如您发现有涉嫌抄袭侵权的内容，请联系:hwhale#tublm.com(使用前将#替换为@)

c

garbagecollection

V8

embeddedv8

用于测量 GC 活动的 V8 垃圾收集器回调 的相关文章

  • Volatile.Read 和 Volatile.Write 背后的逻辑是什么？

    来自 MSDN Volatile Read 读取字段的值 在需要它的系统上 插入一个 阻止处理器重新排序内存的内存屏障 操作如下 如果在该方法之后出现读或写 代码 处理器无法移动它before这个方法 and Volatile Write

  • 编写此代码片段的有效方法是什么？ [关闭]

    Closed 这个问题需要细节或清晰度 help closed questions 目前不接受答案 更有效和 或更短地重写此代码以节省字节并显得不那么冗长的方法 if N 2 0 N 6 N 8 N 10 N 12 N 14 N 16 N

  • 是否可以从 C++ 应用程序调用 C# 应用程序？

    我是一名编程学生 现在我已经上了两门 C 课程 这个学期我将参加我的第一门 C 课程 出于好奇 是否可以从 C 应用程序调用 C 应用程序 如果是的话 是否还可以检查运行该程序的计算机是否具有 NET框架 我只是很好奇 我想如果可能的话 这

  • 叮当错误？命名空间模板类的朋友

    以下代码在 clang 下无法编译 但在 gcc 和 VS 下可以编译 template

  • 异常堆栈跟踪不显示抛出异常的位置

    通常 当我抛出异常 捕获它并打印出堆栈跟踪时 我会看到抛出异常的调用 导致该异常的调用 导致该异常的调用that 依此类推回到整个程序的根 现在它只向我显示异常所在的调用caught 而不是它所在的地方thrown 我不明白是什么改变导致了

  • 如果 JSON.NET 中的值为 null 或空格，则防止序列化

    我有一个对象需要以这样的方式序列化 即 null 和 空白 空或只是空格 值都不会序列化 我不控制对象本身 因此无法设置属性 但我知道所有属性都是字符串 环境NullValueHandling显然 忽略 只能让我找到解决方案的一部分 它 似

  • 在 C++11 中移出 stdpriority_queue 的元素

    最小的工作示例 include

  • 在 C# 中何时使用 ArrayList 而不是 array[]？

    我经常使用一个ArrayList而不是 正常 array 当我使用时 我感觉好像我在作弊 或懒惰 ArrayList 什么时候可以使用ArrayList在数组上 数组是强类型的 并且可以很好地用作参数 如果您知道集合的长度并且它是固定的 则

  • 使用 C# 中的 Google 地图 API 和 SSIS 包获取行驶距离

    更新 找到了谷歌距离矩阵并尝试相应地修改我的代码 我在这里收到无效参数错误 return new GeoLocation dstnc uri ToString catch return new GeoLocation 0 0 https 基

  • 用于连接 DataTable 上的动态列的动态 LINQ

    我目前遇到的情况不确定如何继续 我有两个从数据库填充的数据表 我还有一个可用的列名称列表 可用于将这两个数据表连接在一起 我希望编写一组 LINQ 查询 这些查询将 显示两个数据表中的行 内部联接 用于从一个数据表更新另一个数据表 显示一个

  • Xamarin - SignalR 挂在连接上

    我正在尝试将我的 Xamarin 应用程序连接到托管在 Azure 上的 SignalR 后端 我遇到的问题是每次我在 HubConnection 上调用 StartAsync 时 它都会挂起客户端并且请求永远不会完成 我尝试通过应用程序进

  • Resharper：IEnumerable 的可能多重枚举

    我正在使用新的 Resharper 版本 6 在我的代码中的几个地方 它给一些文本加了下划线 并警告我可能存在IEnumerable 可能的多重枚举 我理解这意味着什么 并在适当的情况下采纳了建议 但在某些情况下 我不确定这实际上是一个大问

  • 如何在 C# 中获取 Json 数组？

    我有一个像这样的 Json 字符串 我想将它加载到 C 数组中 当我尝试这样做时 我收到异常 我的字符串 customerInformation customerId 123 CustomerName Age 39 Gender Male

  • 使用 OleDbCommandBuilder 时访问 SQL 语法错误

    我要在 C 中使用 OleDbDataAdapter 在 Access 数据库中插入数据 但收到错误消息INSERT INTO 命令中的语法错误 BackgroundWorker worker new BackgroundWorker Ol

  • 使用多线程进行矩阵乘法？

    我应该使用线程将两个矩阵相乘 有两件事 当我运行程序时 我不断得到 0 我还收到消息错误 对于每个错误 它在粗体行上显示 警告 从不兼容的指针类型传递 printMatrix 的参数1 我尝试打印输出 还要注意 第一个粗体块 这是我解决问题

  • ALTER TABLE ... ADD CONSTRAINT 失败时将事务回滚到保存点

    有没有办法在事务中添加检查约束and如果失败回滚到以前的保存点 而不是回滚整个事务 就我而言 当 ALTER TABLE ADD CONSTRAINT 命令失败时 事务无法回滚到保存点 尝试这样做会引发 InvalidOperationEx

  • 如何在dll级别读取app.config？ [复制]

    这个问题在这里已经有答案了 我在一个解决方案中有一个控制台应用程序项目和库项目 dll The 图书馆项目有 app config 文件 我在其中存储我在库中使用的一些键值对 控制台应用程序引用此 dll 我有另一个 app config

  • 这种尺寸对齐是如何工作的

    对于所提供的评论 我无法理解以下代码 这段代码的作用是什么 以及等效的代码是什么8 aligned segment size must be 4 aligned attr gt options ssize 3 Here ssize is o

  • 使用 C# 动态创建按钮并按预定义的顺序放置它们

    NET 4 5 C 创建 Windows 窗体 我想动态创建和添加按钮并为其分配单击事件 但希望它们以特定的方式动态放置 就像图像一样 我的问题是如何以上述方式动态放置按钮 即 4x4 格式 一行 4 个按钮 4 列 但行数不受限制 是否可

  • C++ Boost ASIO 简单的周期性定时器？

    我想要一个非常简单的周期性计时器每 50 毫秒调用我的代码 我可以创建一个始终休眠 50 毫秒的线程 但这很痛苦 我可以开始研究用于制作计时器的 Linux API 但它不可移植 I d like使用升压 我只是不确定这是否可能 boost

随机推荐

  • 如何在 NS-3/ndnSIM 中模拟过程延迟？

    我想在发送兴趣包之前在消费者节点上添加一些进程延迟 我发现 Simulator Schedule 函数可以实现这个目的 但我不确定如何使用它 因为 ndnSIM 有自己的协议流程 如果我安排一个新事件 可能会导致一些意外的结果 或者是否有其

  • Swig：将Java中的字节数组传递给C

    我正在尝试创建 Java 实现 以便使用 Swig 将 byte 传递给 C Swig include typemaps i apply char STRING int LENGTH char buff int len inline typ

  • Java EE 5 和 Hibernate

    我可以将哪个版本的 Hibernate 与 Java EE 5 一起使用 我可以使用最新版本吗 See http www hibernate org http www hibernate org 它说最新的4 1 4版本可以与Java EE

  • 带列的数据透视表 pandas 中的百分比计算

    我有一个数据集 其中包含来自不同供应商 地点 日期和产品的多个销售登记册 数据集是这样的 local categoria fabricante tipo consistencia peso pacote ordem vendas kg AR

  • Spring：用于动态查询的通用 RowMapper

    我正在使用 SpringBatch 从 Oracle 读取数据并将其写入 ElasticSearch 我的代码对于静态查询效果很好 例子 select emp id emp name from employee table我有一个 RowM

  • 存储 std::shared_ptr 的向量，其中 Foo 是模板类

    我有一个基类 我将其作为模板 因为我想改变多个函数所需的类型 但我想从这些模板化基类派生 我想存储这些类的向量 我的想法是在层次结构中的所有内容之上创建一个非模板化基类 并使用双重调度来确定类型 我这样做是 正确的方式 吗 这是该场景的代码

  • 使用 sed 从文件中删除多字节字符

    我需要从文件中删除所有多字节字符 我不知道它们是什么 所以我需要覆盖整个范围 我可以使用 grep 找到它们 如下所示 grep P x80 xFF 我的文件 尝试用 sed 做类似的事情 但删除它们 Cheers 尝试一下 LANG C

  • 用于 Objective-C 开发的 Lint 检查工具 [关闭]

    Closed 这个问题正在寻求书籍 工具 软件库等的推荐 不满足堆栈溢出指南 help closed questions 目前不接受答案 具有多个开发人员的大型项目通常会导致代码风格不一致 我正在寻找一个lint http en wikip

  • 如何识别 Visual Basic 中 MS Office 使用的显示语言（即工具栏/菜单）？

    我有一个宏 可以从 MS Excel 电子表格生成 MS Word 报告 我在报告中使用的样式在宏中以英语编码 我的一些团队将 MS Office 显示语言设置为法国 这并不奇怪 我在法国工作 因此 我的宏不起作用 因为样式标题 英文 用于

  • Python - 如果某个键不在一个列表中，则追加到另一个列表中

    这可能是一个相当简单的问题 但我还没有完全弄清楚 我有两个元组列表 List A a 0 033 b 0 030 c 0 020 d 0 010 e 0 005 List B a 0 057 b 0 065 w 0 060 x 0 040

  • 视图绑定 - 如何获取包含的布局的绑定？

    在使用视图绑定时 我遇到了一些未记录的案例 第一 如何获得包含的视图布局部分的绑定 主绑定只能看到主布局中定义的项目 第二 如何获得合并布局部分的绑定 同样 主绑定只能看到主布局中的项目 的情况下 包含通用布局 不是合并节点 我们需要为包含

  • 使用 Java 从数据库读取 UDT 的最佳方法是什么？

    我以为我了解有关 UDT 和 JDBC 的一切 直到有人SO http stackoverflow com指出了Javadoc的一些细节java sql SQLInput http download oracle com javase 6

  • 查询根目录下的文件和文件夹列表

    我想获取根目录中的文件和文件夹列表 而不必对所有文件进行排序 是否有一个查询可以做到这一点 根文件夹也可以使用名为 root 的特殊别名来寻址 因此您可以使用以下查询获取根文件夹中的所有文件和文件夹 https www googleapis

  • 如何连接到 Docker Toolbox 中托管的容器？

    我尝试在 Docker 容器中运行 ASP NET Core 1 1 Web API 但无法从浏览器或curl 为了进行故障排除 我还启动了标准 nginx 和 Apache httpd 容器 但也无法连接到这些容器 因此我相信这是 Doc

  • 连接消除在 Oracle 中不适用于子查询

    我能够让连接消除适用于简单的情况 例如一对一关系 但不适用于稍微复杂的情况 最终我想尝试锚点建模 但首先我需要找到解决这个问题的方法 我正在使用 Oracle 12c 企业版版本 12 1 0 2 0 我的测试用例的 DDL drop vi

  • 如何在android中制作自定义textview？ [关闭]

    Closed 此问题正在寻求书籍 工具 软件库等的推荐 不满足堆栈溢出指南 help closed questions 目前不接受答案 我正在开发布局 我为此布局开发了可绘制对象 但是在此视图中文本未调整 任何人告诉我有关库的信息 请提供其

  • 如何在 Mojolicious 应用程序中从命令行获取凭据？

    我正在开发一个 Mojolcious 独立应用程序 在代码中 我正在联系内部后端 用户应在其中提供一些凭据 目前我正在代码中使用凭据作为变量 它看起来有点像 password somthing 我尝试使用配置插件在那里存储凭据 但是 Moj

  • 查找 R 中 data.table 中多次出现的值对

    我有一个data table in R gt head d COUNT SAMPLE junction 1 1 R1 tup 2 1 R1 tup 3 1 R1 tai 4 1 R2 milt 5 2 R3 Bsg25D 6 1 R4 tu

  • 动态链接在应用程序关闭时不起作用，仅在后台运行时

    我一直致力于在我的应用程序中包含动态链接 我已经对其进行了设置 以便可以正确生成并正确接收链接 但它们仅在应用程序打开并在后台运行时才有效 如果应用程序完全关闭 该链接将仅打开该应用程序 即使我在 didFinishLaunchingWit

  • 用于测量 GC 活动的 V8 垃圾收集器回调

    我有一个关于V8的小问题6 7 240GC 行为和AddGCPrologueCallback AddGCEpilogueCallback回调 问题背后的一个小故事 我们使用 V8 引擎启动自定义 JS 代码 为了限制执行时间 我们有一个wa

热门标签