Skip to content

investigate flaky test/parallel/test-heapsnapshot-near-heap-limit.js #36961

Closed

Description

@RaisinTen
  • Test: test/parallel/test-heapsnapshot-near-heap-limit.js
  • Platform: test-macOS-with-quic, node-test-binary-arm-12+
  • Console Output:
=== release test-heapsnapshot-near-heap-limit ===
Path: parallel/test-heapsnapshot-near-heap-limit
Error: --- stderr ---
node:assert:119
  throw new AssertionError(obj);
  ^

AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:

0 !== 1

    at Object.<anonymous> (/Users/runner/work/node/node/test/parallel/test-heapsnapshot-near-heap-limit.js:66:10)
    at Module._compile (node:internal/modules/cjs/loader:1108:14)
    at Object.Module._extensions..js (node:internal/modules/cjs/loader:1137:10)
    at Module.load (node:internal/modules/cjs/loader:973:32)
    at Function.Module._load (node:internal/modules/cjs/loader:813:14)
    at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:76:12)
    at node:internal/main/run_main_module:17:47 {
  generatedMessage: true,
  code: 'ERR_ASSERTION',
  actual: 0,
  expected: 1,
  operator: 'strictEqual'
}
--- stdout ---
Testing limit = 0
[55440:0x7fc985e00000]      188 ms: Scavenge 3.2 (3.6) -> 2.8 (4.6) MB, 1.9 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
[55440:0x7fc985e00000]      207 ms: Scavenge 3.4 (4.6) -> 3.0 (5.4) MB, 1.9 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
[55440:0x7fc985e00000]      227 ms: Scavenge 3.7 (5.4) -> 3.3 (5.4) MB, 1.1 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
[55440:0x7fc985e00000]      245 ms: Scavenge 4.0 (5.4) -> 3.6 (7.6) MB, 1.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
[55440:0x7fc985e00000]      456 ms: Scavenge 5.2 (7.6) -> 4.3 (7.9) MB, 1.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
[55440:0x7fc985e00000]      552 ms: Scavenge 5.4 (7.9) -> 4.7 (8.9) MB, 1.8 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
[55440:0x7fc985e00000]      707 ms: Scavenge 6.4 (9.2) -> 5.5 (13.5) MB, 2.6 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
[55440:0x7fc985e00000]      942 ms: Scavenge 8.8 (13.5) -> 7.0 (14.0) MB, 1.9 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
[55440:0x7fc985e00000]     1080 ms: Scavenge 9.3 (14.0) -> 7.9 (15.5) MB, 3.2 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
[55440:0x7fc985e00000]     1297 ms: Scavenge 10.3 (15.5) -> 8.9 (24.5) MB, 3.1 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
[55440:0x7fc985e00000]     1463 ms: Scavenge 14.5 (24.5) -> 11.5 (25.5) MB, 3.2 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
[55440:0x7fc985e00000]     1489 ms: Mark-sweep 12.2 (25.5) -> 10.8 (28.5) MB, 4.2 / 0.0 ms  (+ 7.9 ms in 170 steps since start of marking, biggest step 0.4 ms, walltime since start of marking 26 ms) (average mu = 1.000, current mu = 1.000) finalize incremental marking via task GC in old space requested
[55440:0x7fc985e00000]     1875 ms: Scavenge 17.9 (28.5) -> 14.3 (28.5) MB, 3.9 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
[55440:0x7fc985e00000]     2025 ms: Scavenge 17.5 (28.5) -> 15.4 (47.0) MB, 6.9 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
[55440:0x7fc985e00000]     2059 ms: Mark-sweep 16.4 (47.0) -> 15.5 (49.2) MB, 5.2 / 0.0 ms  (+ 9.2 ms in 242 steps since start of marking, biggest step 0.5 ms, walltime since start of marking 34 ms) (average mu = 0.975, current mu = 0.975) finalize incremental marking via task GC in old space requested
[55440:0x7fc985e00000]     2673 ms: Scavenge 29.2 (49.2) -> 22.5 (49.2) MB, 3.9 / 0.0 ms  (average mu = 0.975, current mu = 0.975) task 
[55440:0x7fc985e00000]     3000 ms: Scavenge 28.8 (49.2) -> 24.6 (55.0) MB, 6.6 / 0.0 ms  (average mu = 0.975, current mu = 0.975) task 
[55440:0x7fc985e00000]     3046 ms: Mark-sweep 26.3 (55.0) -> 24.4 (58.5) MB, 5.4 / 0.0 ms  (+ 11.9 ms in 380 steps since start of marking, biggest step 0.6 ms, walltime since start of marking 46 ms) (average mu = 0.980, current mu = 0.983) finalize incremental marking via task GC in old space requested
[55440:0x7fc985e00000]     3613 ms: Scavenge 37.8 (58.6) -> 30.8 (58.6) MB, 6.7 / 0.0 ms  (average mu = 0.980, current mu = 0.983) task 
[55440:0x7fc985e00000]     3673 ms: Mark-sweep 32.8 (58.6) -> 30.7 (65.4) MB, 6.8 / 0.0 ms  (+ 13.8 ms in 474 steps since start of marking, biggest step 1.4 ms, walltime since start of marking 59 ms) (average mu = 0.974, current mu = 0.968) finalize incremental marking via task GC in old space requested
[55440:0x7fc985e00000]     4226 ms: Scavenge 44.0 (65.4) -> 36.9 (65.4) MB, 7.2 / 0.0 ms  (average mu = 0.974, current mu = 0.968) task 
[55440:0x7fc985e00000]     4310 ms: Mark-sweep 39.4 (65.4) -> 37.2 (72.6) MB, 12.9 / 0.0 ms  (+ 15.8 ms in 561 steps since start of marking, biggest step 0.7 ms, walltime since start of marking 84 ms) (average mu = 0.966, current mu = 0.956) finalize incremental marking via task GC in old space requested
[55440:0x7fc985e00000]     4898 ms: Mark-sweep 50.7 (72.9) -> 42.7 (77.0) MB, 31.8 / 0.0 ms  (average mu = 0.956, current mu = 0.946) task scavenge might not succeed
[55440:0x7fc985e00000]     5493 ms: Mark-sweep 55.4 (77.0) -> 48.0 (82.2) MB, 38.8 / 0.0 ms  (average mu = 0.946, current mu = 0.935) task scavenge might not succeed
[55440:0x7fc985e00000]     6135 ms: Mark-sweep 60.6 (82.2) -> 53.2 (87.7) MB, 45.9 / 0.0 ms  (average mu = 0.937, current mu = 0.929) task scavenge might not succeed


<--- Last few GCs --->

[55440:0x7fc985e00000]     5493 ms: Mark-sweep 55.4 (77.0) -> 48.0 (82.2) MB, 38.8 / 0.0 ms  (average mu = 0.946, current mu = 0.935) task scavenge might not succeed
[55440:0x7fc985e00000]     6135 ms: Mark-sweep 60.6 (82.2) -> 53.2 (87.7) MB, 45.9 / 0.0 ms  (average mu = 0.937, current mu = 0.929) task scavenge might not succeed


<--- JS stacktrace --->

FATAL ERROR: MarkCompactCollector: young object promotion failed Allocation failed - JavaScript heap out of memory
 1: 0x10ae70455 node::Abort() [/Users/runner/work/node/node/out/Release/node]
 2: 0x10ae705c6 node::OnFatalError(char const*, char const*) [/Users/runner/work/node/node/out/Release/node]
 3: 0x10afe1507 v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [/Users/runner/work/node/node/out/Release/node]
 4: 0x10afe14a3 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/Users/runner/work/node/node/out/Release/node]
 5: 0x10b19ff65 v8::internal::Heap::FatalProcessOutOfMemory(char const*) [/Users/runner/work/node/node/out/Release/node]
 6: 0x10b1fa21a v8::internal::EvacuateNewSpaceVisitor::Visit(v8::internal::HeapObject, int) [/Users/runner/work/node/node/out/Release/node]
 7: 0x10b1e1f5b void v8::internal::LiveObjectVisitor::VisitBlackObjectsNoFail<v8::internal::EvacuateNewSpaceVisitor, v8::internal::MajorNonAtomicMarkingState>(v8::internal::MemoryChunk*, v8::internal::MajorNonAtomicMarkingState*, v8::internal::EvacuateNewSpaceVisitor*, v8::internal::LiveObjectVisitor::IterationMode) [/Users/runner/work/node/node/out/Release/node]
 8: 0x10b1e1afc v8::internal::FullEvacuator::RawEvacuatePage(v8::internal::MemoryChunk*, long*) [/Users/runner/work/node/node/out/Release/node]
 9: 0x10b1e1806 v8::internal::Evacuator::EvacuatePage(v8::internal::MemoryChunk*) [/Users/runner/work/node/node/out/Release/node]
10: 0x10b1fecde v8::internal::PageEvacuationTask::RunInParallel(v8::internal::ItemParallelJob::Task::Runner) [/Users/runner/work/node/node/out/Release/node]
11: 0x10b1b9e82 v8::internal::ItemParallelJob::Task::RunInternal() [/Users/runner/work/node/node/out/Release/node]
12: 0x10b1ba2f8 v8::internal::ItemParallelJob::Run() [/Users/runner/work/node/node/out/Release/node]
13: 0x10b1e3a04 void v8::internal::MarkCompactCollectorBase::CreateAndExecuteEvacuationTasks<v8::internal::FullEvacuator, v8::internal::MarkCompactCollector>(v8::internal::MarkCompactCollector*, v8::internal::ItemParallelJob*, v8::internal::MigrationObserver*, long) [/Users/runner/work/node/node/out/Release/node]
14: 0x10b1e3514 v8::internal::MarkCompactCollector::EvacuatePagesInParallel() [/Users/runner/work/node/node/out/Release/node]
15: 0x10b1cf8d7 v8::internal::MarkCompactCollector::Evacuate() [/Users/runner/work/node/node/out/Release/node]
16: 0x10b1cd13a v8::internal::MarkCompactCollector::CollectGarbage() [/Users/runner/work/node/node/out/Release/node]
17: 0x10b1a066c v8::internal::Heap::MarkCompact() [/Users/runner/work/node/node/out/Release/node]
18: 0x10b19d5af v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [/Users/runner/work/node/node/out/Release/node]
19: 0x10b19b2e5 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/Users/runner/work/node/node/out/Release/node]
20: 0x10b1a4c30 v8::internal::Heap::FinalizeIncrementalMarkingIfComplete(v8::internal::GarbageCollectionReason) [/Users/runner/work/node/node/out/Release/node]
21: 0x10b1b472f v8::internal::IncrementalMarkingJob::Task::RunInternal() [/Users/runner/work/node/node/out/Release/node]
22: 0x10aedd15b node::PerIsolatePlatformData::RunForegroundTask(std::__1::unique_ptr<v8::Task, std::__1::default_delete<v8::Task> >) [/Users/runner/work/node/node/out/Release/node]
23: 0x10aedbba7 node::PerIsolatePlatformData::FlushForegroundTasksInternal() [/Users/runner/work/node/node/out/Release/node]
24: 0x10b7e1a3b uv__async_io [/Users/runner/work/node/node/out/Release/node]
25: 0x10b7f518c uv__io_poll [/Users/runner/work/node/node/out/Release/node]
26: 0x10b7e1f31 uv_run [/Users/runner/work/node/node/out/Release/node]
27: 0x10adbcd6f node::SpinEventLoop(node::Environment*) [/Users/runner/work/node/node/out/Release/node]
28: 0x10aeafda4 node::NodeMainInstance::Run(node::EnvSerializeInfo const*) [/Users/runner/work/node/node/out/Release/node]
29: 0x10ae44e24 node::Start(int, char**) [/Users/runner/work/node/node/out/Release/node]
30: 0x7fff6a743cc9 start [/usr/lib/system/libdyld.dylib]


Testing limit = 1
[55449:0x7feddde00000]      135 ms: Scavenge 3.2 (3.6) -> 2.8 (4.6) MB, 1.9 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
[55449:0x7feddde00000]      172 ms: Scavenge 3.4 (4.6) -> 3.0 (5.4) MB, 1.8 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
[55449:0x7feddde00000]      205 ms: Scavenge 3.7 (5.4) -> 3.3 (5.4) MB, 1.1 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
[55449:0x7feddde00000]      227 ms: Scavenge 4.0 (5.4) -> 3.6 (7.6) MB, 1.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
[55449:0x7feddde00000]      302 ms: Scavenge 5.2 (7.6) -> 4.3 (7.9) MB, 1.7 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
[55449:0x7feddde00000]      374 ms: Scavenge 5.4 (7.9) -> 4.7 (8.6) MB, 2.0 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
[55449:0x7feddde00000]      470 ms: Scavenge 6.4 (9.0) -> 5.5 (13.5) MB, 2.9 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
[55449:0x7feddde00000]      636 ms: Scavenge 8.8 (13.5) -> 7.0 (14.2) MB, 3.8 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
[55449:0x7feddde00000]      886 ms: Scavenge 8.6 (14.2) -> 7.6 (15.5) MB, 2.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
[55449:0x7feddde00000]     1114 ms: Scavenge 10.0 (15.5) -> 8.7 (24.0) MB, 3.4 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
[55449:0x7feddde00000]     1398 ms: Scavenge 14.2 (24.0) -> 11.1 (25.2) MB, 2.3 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
[55449:0x7feddde00000]     1433 ms: Mark-sweep 11.9 (25.2) -> 10.5 (28.0) MB, 9.3 / 0.0 ms  (+ 8.0 ms in 164 steps since start of marking, biggest step 0.4 ms, walltime since start of marking 35 ms) (average mu = 1.000, current mu = 1.000) finalize incremental marking via task GC in old space requested
[55449:0x7feddde00000]     1859 ms: Scavenge 17.5 (28.0) -> 14.0 (28.0) MB, 3.3 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
[55449:0x7feddde00000]     2104 ms: Scavenge 17.2 (28.0) -> 14.9 (46.5) MB, 5.9 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
[55449:0x7feddde00000]     2136 ms: Mark-sweep 16.0 (46.5) -> 15.1 (48.7) MB, 4.2 / 0.0 ms  (+ 9.1 ms in 236 steps since start of marking, biggest step 0.4 ms, walltime since start of marking 31 ms) (average mu = 0.981, current mu = 0.981) finalize incremental marking via task GC in old space requested
[55449:0x7feddde00000]     2847 ms: Scavenge 28.7 (48.7) -> 22.0 (48.7) MB, 3.6 / 0.0 ms  (average mu = 0.981, current mu = 0.981) task 
[55449:0x7feddde00000]     3231 ms: Scavenge 28.3 (48.7) -> 24.0 (54.2) MB, 6.4 / 0.0 ms  (average mu = 0.981, current mu = 0.981) task 
[55449:0x7feddde00000]     3277 ms: Mark-sweep 25.6 (54.2) -> 24.0 (58.0) MB, 5.5 / 0.1 ms  (+ 11.9 ms in 366 steps since start of marking, biggest step 0.6 ms, walltime since start of marking 46 ms) (average mu = 0.984, current mu = 0.985) finalize incremental marking via task GC in old space requested
[55449:0x7feddde00000]     4030 ms: Scavenge 37.4 (58.1) -> 30.7 (58.1) MB, 3.8 / 0.0 ms  (average mu = 0.984, current mu = 0.985) task 
[55449:0x7feddde00000]     4098 ms: Mark-sweep 32.7 (58.1) -> 30.3 (65.1) MB, 11.9 / 0.0 ms  (+ 12.8 ms in 460 steps since start of marking, biggest step 1.4 ms, walltime since start of marking 68 ms) (average mu = 0.977, current mu = 0.970) finalize incremental marking via task GC in old space requested
[55449:0x7feddde00000]     4915 ms: Scavenge 43.6 (65.1) -> 36.9 (65.1) MB, 4.7 / 0.0 ms  (average mu = 0.977, current mu = 0.970) task 
[55449:0x7feddde00000]     4991 ms: Mark-sweep 39.3 (65.1) -> 36.8 (71.9) MB, 8.9 / 0.0 ms  (+ 14.5 ms in 555 steps since start of marking, biggest step 0.6 ms, walltime since start of marking 77 ms) (average mu = 0.976, current mu = 0.974) finalize incremental marking via task GC in old space requested
[55449:0x7feddde00000]     5866 ms: Mark-sweep 50.1 (71.9) -> 42.3 (76.6) MB, 34.7 / 0.0 ms  (average mu = 0.968, current mu = 0.960) task scavenge might not succeed
[55449:0x7feddde00000]     7175 ms: Mark-sweep 55.1 (76.9) -> 47.6 (82.0) MB, 32.7 / 0.0 ms  (average mu = 0.972, current mu = 0.975) task scavenge might not succeed
[55449:0x7feddde00000]     8371 ms: Mark-sweep 60.2 (82.0) -> 52.8 (87.5) MB, 33.4 / 0.0 ms  (average mu = 0.972, current mu = 0.972) task scavenge might not succeed

Invoked NearHeapLimitCallback, processing=false, current_limit=52428800, initial_limit=52428800
max_young_gen_size=50331648, young_gen_size=13894336, old_gen_size=38779368, total_size=52673704
Estimated available memory=28192768, estimated overhead=50331648
Not generating snapshots because it's too risky.

<--- Last few GCs --->

[55449:0x7feddde00000]     7175 ms: Mark-sweep 55.1 (76.9) -> 47.6 (82.0) MB, 32.7 / 0.0 ms  (average mu = 0.972, current mu = 0.975) task scavenge might not succeed
[55449:0x7feddde00000]     8371 ms: Mark-sweep 60.2 (82.0) -> 52.8 (87.5) MB, 33.4 / 0.0 ms  (average mu = 0.972, current mu = 0.972) task scavenge might not succeed


<--- JS stacktrace --->

FATAL ERROR: MarkCompactCollector: young object promotion failed Allocation failed - JavaScript heap out of memory
 1: 0x101efe455 node::Abort() [/Users/runner/work/node/node/out/Release/node]
 2: 0x101efe5c6 node::OnFatalError(char const*, char const*) [/Users/runner/work/node/node/out/Release/node]
 3: 0x10206f507 v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [/Users/runner/work/node/node/out/Release/node]
 4: 0x10206f4a3 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/Users/runner/work/node/node/out/Release/node]
 5: 0x10222df65 v8::internal::Heap::FatalProcessOutOfMemory(char const*) [/Users/runner/work/node/node/out/Release/node]
 6: 0x10228821a v8::internal::EvacuateNewSpaceVisitor::Visit(v8::internal::HeapObject, int) [/Users/runner/work/node/node/out/Release/node]
 7: 0x10226ff5b void v8::internal::LiveObjectVisitor::VisitBlackObjectsNoFail<v8::internal::EvacuateNewSpaceVisitor, v8::internal::MajorNonAtomicMarkingState>(v8::internal::MemoryChunk*, v8::internal::MajorNonAtomicMarkingState*, v8::internal::EvacuateNewSpaceVisitor*, v8::internal::LiveObjectVisitor::IterationMode) [/Users/runner/work/node/node/out/Release/node]
 8: 0x10226fafc v8::internal::FullEvacuator::RawEvacuatePage(v8::internal::MemoryChunk*, long*) [/Users/runner/work/node/node/out/Release/node]
 9: 0x10226f806 v8::internal::Evacuator::EvacuatePage(v8::internal::MemoryChunk*) [/Users/runner/work/node/node/out/Release/node]
10: 0x10228ccde v8::internal::PageEvacuationTask::RunInParallel(v8::internal::ItemParallelJob::Task::Runner) [/Users/runner/work/node/node/out/Release/node]
11: 0x102247e82 v8::internal::ItemParallelJob::Task::RunInternal() [/Users/runner/work/node/node/out/Release/node]
12: 0x1022482f8 v8::internal::ItemParallelJob::Run() [/Users/runner/work/node/node/out/Release/node]
13: 0x102271a04 void v8::internal::MarkCompactCollectorBase::CreateAndExecuteEvacuationTasks<v8::internal::FullEvacuator, v8::internal::MarkCompactCollector>(v8::internal::MarkCompactCollector*, v8::internal::ItemParallelJob*, v8::internal::MigrationObserver*, long) [/Users/runner/work/node/node/out/Release/node]
14: 0x102271514 v8::internal::MarkCompactCollector::EvacuatePagesInParallel() [/Users/runner/work/node/node/out/Release/node]
15: 0x10225d8d7 v8::internal::MarkCompactCollector::Evacuate() [/Users/runner/work/node/node/out/Release/node]
16: 0x10225b13a v8::internal::MarkCompactCollector::CollectGarbage() [/Users/runner/work/node/node/out/Release/node]
17: 0x10222e66c v8::internal::Heap::MarkCompact() [/Users/runner/work/node/node/out/Release/node]
18: 0x10222b5af v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [/Users/runner/work/node/node/out/Release/node]
19: 0x1022292e5 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/Users/runner/work/node/node/out/Release/node]
20: 0x102232c30 v8::internal::Heap::FinalizeIncrementalMarkingIfComplete(v8::internal::GarbageCollectionReason) [/Users/runner/work/node/node/out/Release/node]
21: 0x10224272f v8::internal::IncrementalMarkingJob::Task::RunInternal() [/Users/runner/work/node/node/out/Release/node]
22: 0x101f6b15b node::PerIsolatePlatformData::RunForegroundTask(std::__1::unique_ptr<v8::Task, std::__1::default_delete<v8::Task> >) [/Users/runner/work/node/node/out/Release/node]
23: 0x101f69ba7 node::PerIsolatePlatformData::FlushForegroundTasksInternal() [/Users/runner/work/node/node/out/Release/node]
24: 0x10286fa3b uv__async_io [/Users/runner/work/node/node/out/Release/node]
25: 0x10288318c uv__io_poll [/Users/runner/work/node/node/out/Release/node]
26: 0x10286ff31 uv_run [/Users/runner/work/node/node/out/Release/node]
27: 0x101e4ad6f node::SpinEventLoop(node::Environment*) [/Users/runner/work/node/node/out/Release/node]
28: 0x101f3dda4 node::NodeMainInstance::Run(node::EnvSerializeInfo const*) [/Users/runner/work/node/node/out/Release/node]
29: 0x101ed2e24 node::Start(int, char**) [/Users/runner/work/node/node/out/Release/node]
30: 0x7fff6a743cc9 start [/usr/lib/system/libdyld.dylib]
Command: out/Release/node /Users/runner/work/node/node/test/parallel/test-heapsnapshot-near-heap-limit.js

===
=== 1 tests failed
===
make[1]: *** [test-ci] Error 1
make: *** [run-ci] Error 2
Error: Process completed with exit code 2.

Activity

  1. added
    flaky-testIssues and PRs involving tests that fail intermittently in CI.
    on Jan 18, 2021
  2. Trott commented on Feb 2, 2021

    @Trott
    Member

    I'm hoping #37189 will fix that ARM failure. (I'm leaving it in Draft mode until the CI returns showing the tests passing. But a pre-emptive approval would be welcome.)

  3. added a commit that references this issue on Feb 2, 2021
  4. Trott commented on Feb 20, 2021

    @Trott
    Member

    Still seeing failures on macOS in CI.

    https://ci.nodejs.org/job/node-test-commit-osx/39044/nodes=osx1015/testReport/junit/(root)/test/parallel_test_heapsnapshot_near_heap_limit/

    Details
    not ok 812 parallel/test-heapsnapshot-near-heap-limit
      ---
      duration_ms: 9.271
      severity: fail
      exitcode: 1
      stack: |-
        
        Testing limit = 0
        [6974:0x113e37000]       35 ms: Scavenge 3.2 (3.7) -> 2.7 (4.7) MB, 0.8 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6974:0x113e37000]       44 ms: Scavenge 3.4 (4.7) -> 2.8 (5.2) MB, 0.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
        [6974:0x113e37000]       55 ms: Scavenge 3.9 (5.4) -> 3.2 (5.4) MB, 0.3 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
        [6974:0x113e37000]       64 ms: Scavenge 4.0 (5.4) -> 3.4 (5.7) MB, 0.3 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
        [6974:0x113e37000]       72 ms: Scavenge 4.2 (5.7) -> 3.5 (7.7) MB, 0.4 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
        [6974:0x113e37000]       91 ms: Scavenge 5.1 (7.7) -> 3.8 (7.9) MB, 0.4 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6974:0x113e37000]      109 ms: Scavenge 5.4 (7.9) -> 4.1 (8.2) MB, 0.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6974:0x113e37000]      127 ms: Scavenge 5.6 (8.2) -> 4.3 (8.4) MB, 0.4 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6974:0x113e37000]      145 ms: Scavenge 5.9 (8.4) -> 4.6 (8.7) MB, 0.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6974:0x113e37000]      162 ms: Scavenge 6.2 (8.7) -> 4.9 (13.2) MB, 0.6 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6974:0x113e37000]      205 ms: Scavenge 8.1 (13.2) -> 5.5 (13.4) MB, 0.4 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6974:0x113e37000]      240 ms: Scavenge 8.7 (13.4) -> 6.1 (13.9) MB, 0.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6974:0x113e37000]      274 ms: Scavenge 9.2 (13.9) -> 6.6 (14.4) MB, 0.6 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6974:0x113e37000]      306 ms: Scavenge 9.8 (14.4) -> 7.2 (15.2) MB, 0.6 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6974:0x113e37000]      341 ms: Scavenge 10.4 (15.2) -> 7.8 (23.9) MB, 1.0 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6974:0x113e37000]      409 ms: Scavenge 14.1 (23.9) -> 9.0 (24.2) MB, 0.6 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6974:0x113e37000]      467 ms: Scavenge 14.5 (24.2) -> 9.9 (25.4) MB, 0.8 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6974:0x113e37000]      479 ms: Mark-sweep 11.4 (25.4) -> 9.5 (26.7) MB, 1.5 / 0.0 ms  (+ 2.3 ms in 147 steps since start of marking, biggest step 0.1 ms, walltime since start of marking 11 ms) (average mu = 1.000, current mu = 1.000) finalize incremental marking via task GC in old space requested
        [6974:0x113e37000]      549 ms: Scavenge 16.4 (26.7) -> 10.9 (26.7) MB, 0.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6974:0x113e37000]      606 ms: Scavenge 16.4 (26.7) -> 11.9 (27.9) MB, 0.9 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6974:0x113e37000]      664 ms: Scavenge 17.4 (27.9) -> 12.9 (44.9) MB, 1.3 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6974:0x113e37000]      678 ms: Mark-sweep 14.8 (44.9) -> 13.0 (46.4) MB, 1.1 / 0.0 ms  (+ 2.6 ms in 197 steps since start of marking, biggest step 0.1 ms, walltime since start of marking 14 ms) (average mu = 0.981, current mu = 0.981) finalize incremental marking via task GC in old space requested
        [6974:0x113e37000]      819 ms: Scavenge 26.2 (46.4) -> 15.8 (46.4) MB, 0.9 / 0.0 ms  (average mu = 0.981, current mu = 0.981) task 
        [6974:0x113e37000]      932 ms: Scavenge 26.3 (46.4) -> 17.8 (48.7) MB, 1.6 / 0.0 ms  (average mu = 0.981, current mu = 0.981) task 
        [6974:0x113e37000]     1044 ms: Scavenge 28.8 (48.7) -> 19.7 (50.4) MB, 1.3 / 0.0 ms  (average mu = 0.981, current mu = 0.981) task 
        [6974:0x113e37000]     1066 ms: Mark-sweep 22.6 (50.4) -> 19.7 (53.2) MB, 2.9 / 0.0 ms  (+ 3.4 ms in 298 steps since start of marking, biggest step 0.1 ms, walltime since start of marking 22 ms) (average mu = 0.983, current mu = 0.984) finalize incremental marking via task GC in old space requested
        [6974:0x113e37000]     1202 ms: Scavenge 32.8 (53.2) -> 22.4 (53.2) MB, 0.7 / 0.0 ms  (average mu = 0.983, current mu = 0.984) task 
        [6974:0x113e37000]     1226 ms: Mark-sweep 25.7 (53.2) -> 22.6 (56.4) MB, 2.9 / 0.0 ms  (+ 3.3 ms in 335 steps since start of marking, biggest step 0.2 ms, walltime since start of marking 23 ms) (average mu = 0.975, current mu = 0.962) finalize incremental marking via task GC in old space requested
        [6974:0x113e37000]     1407 ms: Scavenge 35.5 (56.4) -> 25.2 (56.4) MB, 0.8 / 0.0 ms  (average mu = 0.975, current mu = 0.962) task 
        [6974:0x113e37000]     1433 ms: Mark-sweep 28.8 (56.4) -> 25.5 (59.4) MB, 2.4 / 0.0 ms  (+ 3.5 ms in 376 steps since start of marking, biggest step 0.2 ms, walltime since start of marking 26 ms) (average mu = 0.974, current mu = 0.972) finalize incremental marking via task GC in old space requested
        [6974:0x113e37000]     1572 ms: Scavenge 38.4 (59.4) -> 28.1 (59.4) MB, 0.8 / 0.0 ms  (average mu = 0.974, current mu = 0.972) task 
        [6974:0x113e37000]     1598 ms: Mark-sweep 32.1 (59.4) -> 28.5 (62.4) MB, 1.4 / 0.0 ms  (+ 3.7 ms in 411 steps since start of marking, biggest step 0.5 ms, walltime since start of marking 26 ms) (average mu = 0.972, current mu = 0.970) finalize incremental marking via task GC in old space requested
        [6974:0x113e37000]     1738 ms: Scavenge 41.5 (62.6) -> 31.3 (62.6) MB, 0.9 / 0.0 ms  (average mu = 0.972, current mu = 0.970) task 
        [6974:0x113e37000]     1769 ms: Mark-sweep 35.9 (62.6) -> 31.7 (65.8) MB, 1.5 / 0.0 ms  (+ 4.0 ms in 472 steps since start of marking, biggest step 0.2 ms, walltime since start of marking 31 ms) (average mu = 0.970, current mu = 0.968) finalize incremental marking via task GC in old space requested
        [6974:0x113e37000]     1912 ms: Scavenge 44.5 (65.8) -> 34.2 (65.8) MB, 0.9 / 0.0 ms  (average mu = 0.970, current mu = 0.968) task 
        [6974:0x113e37000]     1946 ms: Mark-sweep 39.1 (65.8) -> 34.8 (68.8) MB, 3.1 / 0.0 ms  (+ 4.3 ms in 498 steps since start of marking, biggest step 0.5 ms, walltime since start of marking 34 ms) (average mu = 0.964, current mu = 0.959) finalize incremental marking via task GC in old space requested
        [6974:0x113e37000]     2088 ms: Mark-sweep 47.6 (68.8) -> 37.0 (70.8) MB, 8.2 / 0.0 ms  (average mu = 0.955, current mu = 0.942) task scavenge might not succeed
        [6974:0x113e37000]     2233 ms: Mark-sweep 49.7 (70.8) -> 39.3 (73.1) MB, 8.3 / 0.0 ms  (average mu = 0.949, current mu = 0.943) task scavenge might not succeed
        [6974:0x113e37000]     2375 ms: Mark-sweep 51.9 (73.1) -> 41.5 (75.6) MB, 8.3 / 0.0 ms  (average mu = 0.945, current mu = 0.941) task scavenge might not succeed
        [6974:0x113e37000]     2518 ms: Mark-sweep 54.4 (75.9) -> 43.8 (77.9) MB, 8.9 / 0.0 ms  (average mu = 0.942, current mu = 0.938) task scavenge might not succeed
        [6974:0x113e37000]     2663 ms: Mark-sweep 56.5 (77.9) -> 46.1 (79.9) MB, 10.3 / 0.0 ms  (average mu = 0.935, current mu = 0.929) task scavenge might not succeed
        [6974:0x113e37000]     2810 ms: Mark-sweep 58.7 (79.9) -> 48.3 (82.4) MB, 9.7 / 0.0 ms  (average mu = 0.935, current mu = 0.934) task scavenge might not succeed
        [6974:0x113e37000]     2955 ms: Mark-sweep 61.0 (82.4) -> 50.6 (84.7) MB, 10.4 / 0.0 ms  (average mu = 0.931, current mu = 0.928) task scavenge might not succeed
        
        
        <--- Last few GCs --->
        
        [6974:0x113e37000]     2663 ms: Mark-sweep 56.5 (77.9) -> 46.1 (79.9) MB, 10.3 / 0.0 ms  (average mu = 0.935, current mu = 0.929) task scavenge might not succeed
        [6974:0x113e37000]     2810 ms: Mark-sweep 58.7 (79.9) -> 48.3 (82.4) MB, 9.7 / 0.0 ms  (average mu = 0.935, current mu = 0.934) task scavenge might not succeed
        [6974:0x113e37000]     2955 ms: Mark-sweep 61.0 (82.4) -> 50.6 (84.7) MB, 10.4 / 0.0 ms  (average mu = 0.931, current mu = 0.928) task scavenge might not succeed
        
        
        <--- JS stacktrace --->
        
        FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory
         1: 0x1107ae555 node::Abort() (.cold.1) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         2: 0x10f4dfe09 node::Abort() [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         3: 0x10f4dff6f node::OnFatalError(char const*, char const*) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         4: 0x10f65af47 v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         5: 0x10f65aee3 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         6: 0x10f823685 v8::internal::Heap::FatalProcessOutOfMemory(char const*) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         7: 0x10f821460 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         8: 0x10f8ac57f v8::internal::ScavengeJob::Task::RunInternal() [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         9: 0x10f54e45b node::PerIsolatePlatformData::RunForegroundTask(std::__1::unique_ptr<v8::Task, std::__1::default_delete<v8::Task> >) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        10: 0x10f54cef7 node::PerIsolatePlatformData::FlushForegroundTasksInternal() [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        11: 0x10fe850bb uv__async_io [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        12: 0x10fe98f6c uv__io_poll [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        13: 0x10fe85641 uv_run [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        14: 0x10f41de8f node::SpinEventLoop(node::Environment*) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        15: 0x10f5207e4 node::NodeMainInstance::Run(node::EnvSerializeInfo const*) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        16: 0x10f4aead4 node::Start(int, char**) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        17: 0x7fff70d37cc9 start [/usr/lib/system/libdyld.dylib]
        18: 0x5 
        
        
        Testing limit = 1
        [6977:0x11151b000]       31 ms: Scavenge 3.2 (3.7) -> 2.7 (4.7) MB, 0.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6977:0x11151b000]       40 ms: Scavenge 3.4 (4.7) -> 2.8 (5.2) MB, 0.4 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
        [6977:0x11151b000]       51 ms: Scavenge 3.9 (5.4) -> 3.2 (5.4) MB, 0.3 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
        [6977:0x11151b000]       61 ms: Scavenge 4.0 (5.4) -> 3.3 (5.7) MB, 0.3 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
        [6977:0x11151b000]       70 ms: Scavenge 4.1 (5.7) -> 3.5 (7.7) MB, 0.3 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6977:0x11151b000]       88 ms: Scavenge 5.0 (7.7) -> 3.8 (7.9) MB, 0.3 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6977:0x11151b000]      106 ms: Scavenge 5.4 (7.9) -> 4.1 (8.2) MB, 0.4 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6977:0x11151b000]      124 ms: Scavenge 5.6 (8.2) -> 4.3 (8.4) MB, 0.4 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6977:0x11151b000]      142 ms: Scavenge 5.9 (8.4) -> 4.6 (8.7) MB, 0.4 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6977:0x11151b000]      159 ms: Scavenge 6.2 (8.7) -> 4.9 (12.9) MB, 0.6 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6977:0x11151b000]      197 ms: Scavenge 8.0 (12.9) -> 5.5 (13.2) MB, 0.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6977:0x11151b000]      233 ms: Scavenge 8.6 (13.2) -> 6.0 (13.9) MB, 0.6 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6977:0x11151b000]      267 ms: Scavenge 9.2 (13.9) -> 6.6 (14.7) MB, 0.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6977:0x11151b000]      300 ms: Scavenge 9.8 (14.7) -> 7.2 (15.2) MB, 0.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6977:0x11151b000]      335 ms: Scavenge 10.4 (15.2) -> 7.7 (23.7) MB, 0.7 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6977:0x11151b000]      405 ms: Scavenge 14.1 (23.7) -> 9.0 (24.4) MB, 0.6 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6977:0x11151b000]      469 ms: Scavenge 14.5 (24.4) -> 9.9 (25.4) MB, 1.0 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6977:0x11151b000]      480 ms: Mark-sweep 11.4 (25.4) -> 9.5 (26.7) MB, 1.0 / 0.0 ms  (+ 2.4 ms in 148 steps since start of marking, biggest step 0.1 ms, walltime since start of marking 11 ms) (average mu = 1.000, current mu = 1.000) finalize incremental marking via task GC in old space requested
        [6977:0x11151b000]      554 ms: Scavenge 16.5 (26.7) -> 10.9 (26.7) MB, 0.6 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6977:0x11151b000]      615 ms: Scavenge 16.5 (26.7) -> 11.9 (28.2) MB, 1.1 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6977:0x11151b000]      675 ms: Scavenge 17.5 (28.2) -> 12.9 (44.9) MB, 1.4 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6977:0x11151b000]      689 ms: Mark-sweep 14.8 (44.9) -> 13.0 (46.4) MB, 1.0 / 0.0 ms  (+ 2.6 ms in 197 steps since start of marking, biggest step 0.2 ms, walltime since start of marking 14 ms) (average mu = 0.983, current mu = 0.983) finalize incremental marking via task GC in old space requested
        [6977:0x11151b000]      831 ms: Scavenge 26.2 (46.4) -> 15.7 (46.4) MB, 0.7 / 0.0 ms  (average mu = 0.983, current mu = 0.983) task 
        [6977:0x11151b000]      946 ms: Scavenge 26.3 (46.4) -> 17.7 (48.7) MB, 1.4 / 0.0 ms  (average mu = 0.983, current mu = 0.983) task 
        [6977:0x11151b000]     1064 ms: Scavenge 28.8 (48.7) -> 19.7 (50.4) MB, 1.2 / 0.0 ms  (average mu = 0.983, current mu = 0.983) task 
        [6977:0x11151b000]     1086 ms: Mark-sweep 22.6 (50.4) -> 19.7 (53.2) MB, 1.7 / 0.0 ms  (+ 3.5 ms in 298 steps since start of marking, biggest step 0.2 ms, walltime since start of marking 22 ms) (average mu = 0.986, current mu = 0.987) finalize incremental marking via task GC in old space requested
        [6977:0x11151b000]     1225 ms: Scavenge 32.8 (53.2) -> 22.4 (53.2) MB, 0.7 / 0.0 ms  (average mu = 0.986, current mu = 0.987) task 
        [6977:0x11151b000]     1248 ms: Mark-sweep 25.7 (53.2) -> 22.6 (56.4) MB, 2.2 / 0.0 ms  (+ 3.3 ms in 334 steps since start of marking, biggest step 0.2 ms, walltime since start of marking 22 ms) (average mu = 0.979, current mu = 0.966) finalize incremental marking via task GC in old space requested
        [6977:0x11151b000]     1387 ms: Scavenge 35.6 (56.4) -> 25.2 (56.4) MB, 0.8 / 0.0 ms  (average mu = 0.979, current mu = 0.966) task 
        [6977:0x11151b000]     1412 ms: Mark-sweep 28.9 (56.4) -> 25.6 (59.4) MB, 2.3 / 0.0 ms  (+ 3.4 ms in 376 steps since start of marking, biggest step 0.2 ms, walltime since start of marking 25 ms) (average mu = 0.973, current mu = 0.965) finalize incremental marking via task GC in old space requested
        [6977:0x11151b000]     1549 ms: Scavenge 38.5 (59.4) -> 28.2 (59.4) MB, 0.7 / 0.0 ms  (average mu = 0.973, current mu = 0.965) task 
        [6977:0x11151b000]     1577 ms: Mark-sweep 32.2 (59.4) -> 28.6 (63.2) MB, 2.4 / 0.0 ms  (+ 3.7 ms in 411 steps since start of marking, biggest step 0.2 ms, walltime since start of marking 27 ms) (average mu = 0.969, current mu = 0.964) finalize incremental marking via task GC in old space requested
        [6977:0x11151b000]     1714 ms: Scavenge 41.6 (63.3) -> 31.3 (63.3) MB, 0.9 / 0.0 ms  (average mu = 0.969, current mu = 0.964) task 
        [6977:0x11151b000]     1746 ms: Mark-sweep 35.9 (63.3) -> 31.7 (66.6) MB, 1.9 / 0.0 ms  (+ 4.0 ms in 473 steps since start of marking, biggest step 0.2 ms, walltime since start of marking 32 ms) (average mu = 0.967, current mu = 0.965) finalize incremental marking via task GC in old space requested
        [6977:0x11151b000]     1882 ms: Scavenge 44.6 (66.6) -> 34.3 (66.6) MB, 0.9 / 0.0 ms  (average mu = 0.967, current mu = 0.965) task 
        [6977:0x11151b000]     1917 ms: Mark-sweep 39.2 (66.6) -> 34.9 (70.1) MB, 2.2 / 0.0 ms  (+ 4.4 ms in 502 steps since start of marking, biggest step 0.2 ms, walltime since start of marking 35 ms) (average mu = 0.965, current mu = 0.962) finalize incremental marking via task GC in old space requested
        [6977:0x11151b000]     2062 ms: Mark-sweep 47.6 (70.1) -> 37.0 (72.3) MB, 7.2 / 0.0 ms  (average mu = 0.958, current mu = 0.950) task scavenge might not succeed
        [6977:0x11151b000]     2210 ms: Mark-sweep 49.7 (72.3) -> 39.3 (74.6) MB, 7.1 / 0.0 ms  (average mu = 0.955, current mu = 0.952) task scavenge might not succeed
        [6977:0x11151b000]     2353 ms: Mark-sweep 51.9 (74.6) -> 41.5 (77.1) MB, 8.5 / 0.0 ms  (average mu = 0.948, current mu = 0.941) task scavenge might not succeed
        [6977:0x11151b000]     2498 ms: Mark-sweep 54.4 (77.4) -> 43.8 (79.2) MB, 9.4 / 0.0 ms  (average mu = 0.942, current mu = 0.935) task scavenge might not succeed
        [6977:0x11151b000]     2642 ms: Mark-sweep 56.5 (79.2) -> 46.1 (81.7) MB, 9.3 / 0.0 ms  (average mu = 0.939, current mu = 0.935) task scavenge might not succeed
        [6977:0x11151b000]     2787 ms: Mark-sweep 58.7 (81.7) -> 48.3 (83.9) MB, 9.5 / 0.0 ms  (average mu = 0.936, current mu = 0.934) task scavenge might not succeed
        [6977:0x11151b000]     2797 ms: Mark-sweep (reduce) 48.3 (83.9) -> 48.3 (52.9) MB, 9.4 / 0.0 ms  (average mu = 0.880, current mu = 0.076) heap profiler GC in old space requested
        
        Invoked NearHeapLimitCallback, processing=false, current_limit=52428800, initial_limit=52428800
        max_young_gen_size=50331648, young_gen_size=0, old_gen_size=50843104, total_size=50843104
        Estimated available memory=105586688, estimated overhead=50331648
        Start generating Heap.20210217.000611.6977.0.001.heapsnapshot...
        
        <--- Last few GCs --->
        
        [6977:0x11151b000]     2642 ms: Mark-sweep 56.5 (79.2) -> 46.1 (81.7) MB, 9.3 / 0.0 ms  (average mu = 0.939, current mu = 0.935) task scavenge might not succeed
        [6977:0x11151b000]     2787 ms: Mark-sweep 58.7 (81.7) -> 48.3 (83.9) MB, 9.5 / 0.0 ms  (average mu = 0.936, current mu = 0.934) task scavenge might not succeed
        [6977:0x11151b000]     2797 ms: Mark-sweep (reduce) 48.3 (83.9) -> 48.3 (52.9) MB, 9.4 / 0.0 ms  (average mu = 0.880, current mu = 0.076) heap profiler GC in old space requested
        
        
        <--- JS stacktrace --->
        
        FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory
         1: 0x10de92555 node::Abort() (.cold.1) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         2: 0x10cbc3e09 node::Abort() [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         3: 0x10cbc3f6f node::OnFatalError(char const*, char const*) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         4: 0x10cd3ef47 v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         5: 0x10cd3eee3 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         6: 0x10cf07685 v8::internal::Heap::FatalProcessOutOfMemory(char const*) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         7: 0x10cf05460 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         8: 0x10cf05542 v8::internal::Heap::CollectAllAvailableGarbage(v8::internal::GarbageCollectionReason) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         9: 0x10d1f9b7e v8::internal::HeapSnapshotGenerator::GenerateSnapshot() [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        10: 0x10d1ee3ab v8::internal::HeapProfiler::TakeSnapshot(v8::ActivityControl*, v8::HeapProfiler::ObjectNameResolver*, bool) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        11: 0x10cb76722 node::heap::WriteSnapshot(v8::Isolate*, char const*) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        12: 0x10cb6518e node::Environment::NearHeapLimitCallback(void*, unsigned long, unsigned long) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        13: 0x10cf0604a v8::internal::Heap::InvokeNearHeapLimitCallback() [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        14: 0x10cf053b9 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        15: 0x10cf9057f v8::internal::ScavengeJob::Task::RunInternal() [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        16: 0x10cc3245b node::PerIsolatePlatformData::RunForegroundTask(std::__1::unique_ptr<v8::Task, std::__1::default_delete<v8::Task> >) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        17: 0x10cc30ef7 node::PerIsolatePlatformData::FlushForegroundTasksInternal() [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        18: 0x10d5690bb uv__async_io [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        19: 0x10d57cf6c uv__io_poll [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        20: 0x10d569641 uv_run [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        21: 0x10cb01e8f node::SpinEventLoop(node::Environment*) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        22: 0x10cc047e4 node::NodeMainInstance::Run(node::EnvSerializeInfo const*) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        23: 0x10cb92ad4 node::Start(int, char**) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        24: 0x7fff70d37cc9 start [/usr/lib/system/libdyld.dylib]
        25: 0x5 
        
        
        Testing limit = 3
        [6980:0x11242f000]       32 ms: Scavenge 3.2 (3.7) -> 2.7 (4.7) MB, 0.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6980:0x11242f000]       41 ms: Scavenge 3.4 (4.7) -> 2.8 (5.2) MB, 0.4 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
        [6980:0x11242f000]       52 ms: Scavenge 3.9 (5.4) -> 3.2 (5.4) MB, 0.2 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
        [6980:0x11242f000]       62 ms: Scavenge 4.0 (5.4) -> 3.4 (5.7) MB, 0.3 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
        [6980:0x11242f000]       71 ms: Scavenge 4.2 (5.7) -> 3.5 (7.7) MB, 0.3 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure 
        [6980:0x11242f000]       89 ms: Scavenge 5.1 (7.7) -> 3.8 (7.9) MB, 0.3 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6980:0x11242f000]      108 ms: Scavenge 5.4 (7.9) -> 4.1 (8.2) MB, 0.4 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6980:0x11242f000]      126 ms: Scavenge 5.6 (8.2) -> 4.3 (8.4) MB, 0.4 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6980:0x11242f000]      143 ms: Scavenge 5.9 (8.4) -> 4.6 (8.7) MB, 0.4 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6980:0x11242f000]      161 ms: Scavenge 6.2 (8.7) -> 4.9 (12.9) MB, 0.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6980:0x11242f000]      201 ms: Scavenge 8.1 (12.9) -> 5.5 (13.2) MB, 0.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6980:0x11242f000]      235 ms: Scavenge 8.6 (13.2) -> 6.1 (13.9) MB, 0.6 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6980:0x11242f000]      266 ms: Scavenge 9.2 (13.9) -> 6.6 (14.4) MB, 0.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6980:0x11242f000]      297 ms: Scavenge 9.8 (14.4) -> 7.2 (14.9) MB, 0.6 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6980:0x11242f000]      327 ms: Scavenge 10.3 (14.9) -> 7.7 (23.7) MB, 0.8 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6980:0x11242f000]      386 ms: Scavenge 14.1 (23.7) -> 9.0 (24.2) MB, 0.9 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6980:0x11242f000]      456 ms: Scavenge 14.5 (24.2) -> 10.0 (25.4) MB, 0.9 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6980:0x11242f000]      468 ms: Mark-sweep 11.4 (25.4) -> 9.5 (26.7) MB, 1.7 / 0.0 ms  (+ 2.5 ms in 147 steps since start of marking, biggest step 0.1 ms, walltime since start of marking 12 ms) (average mu = 1.000, current mu = 1.000) finalize incremental marking via task GC in old space requested
        [6980:0x11242f000]      556 ms: Scavenge 16.4 (26.7) -> 10.9 (26.7) MB, 0.8 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6980:0x11242f000]      628 ms: Scavenge 16.4 (26.7) -> 11.9 (27.9) MB, 1.1 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6980:0x11242f000]      702 ms: Scavenge 17.4 (27.9) -> 12.9 (44.7) MB, 1.6 / 0.0 ms  (average mu = 1.000, current mu = 1.000) task 
        [6980:0x11242f000]      717 ms: Mark-sweep 14.8 (44.7) -> 13.0 (46.4) MB, 1.3 / 0.0 ms  (+ 2.6 ms in 199 steps since start of marking, biggest step 0.1 ms, walltime since start of marking 15 ms) (average mu = 0.985, current mu = 0.985) finalize incremental marking via task GC in old space requested
        [6980:0x11242f000]      878 ms: Scavenge 26.2 (46.4) -> 15.8 (46.4) MB, 0.8 / 0.0 ms  (average mu = 0.985, current mu = 0.985) task 
        [6980:0x11242f000]     1000 ms: Scavenge 26.3 (46.4) -> 17.7 (48.4) MB, 2.3 / 0.0 ms  (average mu = 0.985, current mu = 0.985) task 
        [6980:0x11242f000]     1120 ms: Scavenge 28.8 (48.4) -> 19.7 (50.4) MB, 1.4 / 0.0 ms  (average mu = 0.985, current mu = 0.985) task 
        [6980:0x11242f000]     1144 ms: Mark-sweep 22.6 (50.4) -> 19.7 (53.4) MB, 2.4 / 0.0 ms  (+ 3.3 ms in 294 steps since start of marking, biggest step 0.2 ms, walltime since start of marking 25 ms) (average mu = 0.986, current mu = 0.987) finalize incremental marking via task GC in old space requested
        [6980:0x11242f000]     1295 ms: Scavenge 32.8 (53.4) -> 22.4 (53.4) MB, 0.9 / 0.0 ms  (average mu = 0.986, current mu = 0.987) task 
        [6980:0x11242f000]     1318 ms: Mark-sweep 25.7 (53.4) -> 22.6 (56.4) MB, 2.5 / 0.0 ms  (+ 3.3 ms in 334 steps since start of marking, biggest step 0.1 ms, walltime since start of marking 24 ms) (average mu = 0.980, current mu = 0.967) finalize incremental marking via task GC in old space requested
        [6980:0x11242f000]     1494 ms: Scavenge 35.6 (56.4) -> 25.2 (56.4) MB, 0.9 / 0.0 ms  (average mu = 0.980, current mu = 0.967) task 
        [6980:0x11242f000]     1521 ms: Mark-sweep 28.8 (56.4) -> 25.6 (59.4) MB, 3.6 / 0.0 ms  (+ 3.8 ms in 369 steps since start of marking, biggest step 0.2 ms, walltime since start of marking 27 ms) (average mu = 0.973, current mu = 0.964) finalize incremental marking via task GC in old space requested
        [6980:0x11242f000]     1693 ms: Scavenge 38.5 (59.4) -> 28.1 (59.4) MB, 0.8 / 0.0 ms  (average mu = 0.973, current mu = 0.964) task 
        [6980:0x11242f000]     1722 ms: Mark-sweep 32.2 (59.4) -> 28.6 (62.9) MB, 2.7 / 0.0 ms  (+ 3.8 ms in 414 steps since start of marking, biggest step 0.2 ms, walltime since start of marking 29 ms) (average mu = 0.970, current mu = 0.968) finalize incremental marking via task GC in old space requested
        [6980:0x11242f000]     1895 ms: Scavenge 41.6 (63.1) -> 31.3 (63.1) MB, 1.0 / 0.0 ms  (average mu = 0.970, current mu = 0.968) task 
        [6980:0x11242f000]     1933 ms: Mark-sweep 35.8 (63.1) -> 31.7 (66.3) MB, 3.5 / 0.0 ms  (+ 4.4 ms in 462 steps since start of marking, biggest step 0.2 ms, walltime since start of marking 38 ms) (average mu = 0.967, current mu = 0.963) finalize incremental marking via task GC in old space requested
        [6980:0x11242f000]     2104 ms: Scavenge 44.5 (66.3) -> 34.3 (66.3) MB, 1.0 / 0.0 ms  (average mu = 0.967, current mu = 0.963) task 
        [6980:0x11242f000]     2145 ms: Mark-sweep 39.1 (66.3) -> 34.8 (69.8) MB, 7.7 / 0.0 ms  (+ 4.6 ms in 498 steps since start of marking, biggest step 0.3 ms, walltime since start of marking 41 ms) (average mu = 0.954, current mu = 0.942) finalize incremental marking via task GC in old space requested
        [6980:0x11242f000]     2319 ms: Mark-sweep 47.6 (69.8) -> 37.0 (72.3) MB, 8.8 / 0.0 ms  (average mu = 0.952, current mu = 0.949) task scavenge might not succeed
        [6980:0x11242f000]     2496 ms: Mark-sweep 49.6 (72.3) -> 39.2 (74.6) MB, 8.7 / 0.0 ms  (average mu = 0.951, current mu = 0.951) task scavenge might not succeed
        [6980:0x11242f000]     2658 ms: Mark-sweep 51.9 (74.6) -> 41.5 (76.8) MB, 8.8 / 0.0 ms  (average mu = 0.949, current mu = 0.945) task scavenge might not succeed
        [6980:0x11242f000]     2823 ms: Mark-sweep 54.4 (77.1) -> 43.8 (79.2) MB, 9.6 / 0.0 ms  (average mu = 0.945, current mu = 0.942) task scavenge might not succeed
        [6980:0x11242f000]     3016 ms: Mark-sweep 56.5 (79.2) -> 46.1 (81.4) MB, 9.2 / 0.0 ms  (average mu = 0.949, current mu = 0.952) task scavenge might not succeed
        [6980:0x11242f000]     3180 ms: Mark-sweep 58.7 (81.4) -> 48.3 (83.7) MB, 9.7 / 0.0 ms  (average mu = 0.945, current mu = 0.941) task scavenge might not succeed
        
        Invoked NearHeapLimitCallback, processing=false, current_limit=52428800, initial_limit=52428800
        max_young_gen_size=50331648, young_gen_size=0, old_gen_size=50806304, total_size=50806304
        Estimated available memory=36347904, estimated overhead=50331648
        Not generating snapshots because it's too risky.
        
        <--- Last few GCs --->
        
        [6980:0x11242f000]     2823 ms: Mark-sweep 54.4 (77.1) -> 43.8 (79.2) MB, 9.6 / 0.0 ms  (average mu = 0.945, current mu = 0.942) task scavenge might not succeed
        [6980:0x11242f000]     3016 ms: Mark-sweep 56.5 (79.2) -> 46.1 (81.4) MB, 9.2 / 0.0 ms  (average mu = 0.949, current mu = 0.952) task scavenge might not succeed
        [6980:0x11242f000]     3180 ms: Mark-sweep 58.7 (81.4) -> 48.3 (83.7) MB, 9.7 / 0.0 ms  (average mu = 0.945, current mu = 0.941) task scavenge might not succeed
        
        
        <--- JS stacktrace --->
        
        FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory
         1: 0x10eda6555 node::Abort() (.cold.1) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         2: 0x10dad7e09 node::Abort() [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         3: 0x10dad7f6f node::OnFatalError(char const*, char const*) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         4: 0x10dc52f47 v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         5: 0x10dc52ee3 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         6: 0x10de1b685 v8::internal::Heap::FatalProcessOutOfMemory(char const*) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         7: 0x10de19460 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         8: 0x10dea457f v8::internal::ScavengeJob::Task::RunInternal() [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
         9: 0x10db4645b node::PerIsolatePlatformData::RunForegroundTask(std::__1::unique_ptr<v8::Task, std::__1::default_delete<v8::Task> >) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        10: 0x10db44ef7 node::PerIsolatePlatformData::FlushForegroundTasksInternal() [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        11: 0x10e47d0bb uv__async_io [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        12: 0x10e490f6c uv__io_poll [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        13: 0x10e47d641 uv_run [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        14: 0x10da15e8f node::SpinEventLoop(node::Environment*) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        15: 0x10db187e4 node::NodeMainInstance::Run(node::EnvSerializeInfo const*) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        16: 0x10daa6ad4 node::Start(int, char**) [/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/out/Release/node]
        17: 0x7fff70d37cc9 start [/usr/lib/system/libdyld.dylib]
        18: 0x5 
        
        node:assert:402
            throw err;
            ^
        
        AssertionError [ERR_ASSERTION]: The expression evaluated to a falsy value:
        
          assert(list.length > 0 && list.length <= 3)
        
            at Object.<anonymous> (/Users/iojs/build/workspace/node-test-commit-osx/nodes/osx1015/test/parallel/test-heapsnapshot-near-heap-limit.js:87:3)
            at Module._compile (node:internal/modules/cjs/loader:1094:14)
            at Object.Module._extensions..js (node:internal/modules/cjs/loader:1123:10)
            at Module.load (node:internal/modules/cjs/loader:974:32)
            at Function.Module._load (node:internal/modules/cjs/loader:815:14)
            at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:76:12)
            at node:internal/main/run_main_module:17:47 {
          generatedMessage: true,
          code: 'ERR_ASSERTION',
          actual: false,
          expected: true,
          operator: '=='
        }
      ...
    
  5. Trott commented on Feb 20, 2021

    @Trott
    Member

    In theory, the test is too strict in that Node.js will try to generate a heap snapshot but there's no guarantee.

    On that last test case, where it writes up to 3, I never see it writing more than one locally.

  6. Trott commented on Feb 20, 2021

    @Trott
    Member
  7. Trott commented on Feb 20, 2021

    @Trott
    Member

    ARM failure with which this was originally opened has been worked around but the "macOS often writes 0 snapshots" issue has not.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    flaky-testIssues and PRs involving tests that fail intermittently in CI.

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions