Gobble dies during GC

[IvanSanchez]

I was tempted to title this "out-of-memory kill", but it's V8's garbage collector who's killing my build.

Unfortunately I cannot share the conditions in which this is reproducible. It involves a (propietary) project which runs a rollupjs transform on top of mapbox-gl-js, in "watch" mode.

The first few times I run my pipeline, it works nicely...

build invalidated (). restarting                                                                                                                           
node_modules/whatwg-fetch/fetch.js (460:40) The 'this' keyword is equivalent to 'undefined' at the top level of an ES module, and has been rewritten           
gobble: 02-rollup done in 4573ms                                                                                                                               
gobble: 03-sassAll done in 4ms                                                                                                                                 
gobble: 04-replace done in 7ms                                                                                                                                 
gobble: 05-merge done in 5ms                                                                                                                                   
gobble: 06-concat done in 52ms                                                                                                                                 
gobble: 01-leafdoc done in 63ms                                                                                                                               
gobble: 11-merge done in 7ms                                                                                                                                   
gobble: build completed in 4735ms

Saving my files triggers a rebuild. Doing this an arbitrary amount of times while browsing the built project kills gobble sooner or later.

The stack traces don't tell me anything, really:

build invalidated (). restarting                                                                                                                           
gobble: 



build invalidated (). restarting                                                                                                                           
node_modules/whatwg-fetch/fetch.js (460:40) The 'this' keyword is equivalent to 'undefined' at the top level of an ES module, and has been rewritten           
node_modules/whatwg-fetch/fetch.js (460:40) The 'this' keyword is equivalent to 'undefined' at the top level of an ES module, and has been rewritten           
node_modules/whatwg-fetch/fetch.js (460:40) The 'this' keyword is equivalent to 'undefined' at the top level of an ES module, and has been rewritten           
node_modules/whatwg-fetch/fetch.js (460:40) The 'this' keyword is equivalent to 'undefined' at the top level of an ES module, and has been rewritten           
node_modules/whatwg-fetch/fetch.js (460:40) The 'this' keyword is equivalent to 'undefined' at the top level of an ES module, and has been rewritten           
∙∙∙∙∙◦∙ 02-rollup running...                                                                                                                                   
<--- Last few GCs --->

  324559 ms: Mark-sweep 1304.6 (1413.6) -> 1304.7 (1423.6) MB, 727.7 / 0.0 ms [allocation failure] [GC in old space requested].
  325291 ms: Mark-sweep 1304.7 (1423.6) -> 1304.6 (1423.6) MB, 732.2 / 0.0 ms [allocation failure] [GC in old space requested].
  326044 ms: Mark-sweep 1304.6 (1423.6) -> 1313.7 (1413.6) MB, 752.7 / 0.0 ms [last resort gc].
  326800 ms: Mark-sweep 1313.7 (1413.6) -> 1322.3 (1413.6) MB, 755.8 / 0.0 ms [last resort gc].


<--- JS stacktrace --->

==== JS stack trace =========================================

    2: arguments adaptor frame: 3->1
Security context: 0x36edf67cfb51 <JS Object>
    3: map [native array.js:~994] [pc=0x1e9500399e92] (this=0x30ec25a576a1 <JS Array[40573]>,bq=0x22db45a8ee01 <JS Function (SharedFunctionInfo 0x3f179323e131)>,br=0x36edf6704381 <undefined>)
    4: arguments adaptor frame: 1->2
    5: encode(aka encode) [/ivan/devel/**redacted**/node_modules/gobble-rollup/node_modules/rollup/dist/rollup.js:~341] [p...

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory
 1: node::Abort() [gobble]
 2: 0xd6fb6c [gobble]
 3: v8::Utils::ReportApiFailure(char const*, char const*) [gobble]
 4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [gobble]
 5: v8::internal::Factory::NewFixedArray(int, v8::internal::PretenureFlag) [gobble]
 6: v8::internal::TypeFeedbackVector::New(v8::internal::Isolate*, v8::internal::Handle<v8::internal::TypeFeedbackMetadata>) [gobble]
 7: 0x88c4b0 [gobble]
 8: 0x88c6e5 [gobble]
 9: 0x88dbd8 [gobble]
10: 0x88dcdf [gobble]
11: 0x8961b1 [gobble]
12: v8::internal::Compiler::Compile(v8::internal::Handle<v8::internal::JSFunction>, v8::internal::Compiler::ClearExceptionFlag) [gobble]
13: v8::internal::Runtime_CompileLazy(int, v8::internal::Object**, v8::internal::Isolate*) [gobble]
14: 0x1e94ff8092a7
Aborted
error Command failed with exit code 134.

---

build invalidated (). restarting                                                                                                                           

<--- Last few GCs --->

  199511 ms: Mark-sweep 1299.1 (1408.8) -> 1299.1 (1414.8) MB, 692.7 / 0.0 ms [allocation failure] [GC in old space requested].
  200205 ms: Mark-sweep 1299.1 (1414.8) -> 1299.1 (1414.8) MB, 693.5 / 0.0 ms [allocation failure] [GC in old space requested].
  200917 ms: Mark-sweep 1299.1 (1414.8) -> 1309.3 (1408.8) MB, 712.0 / 0.0 ms [last resort gc].
  201632 ms: Mark-sweep 1309.3 (1408.8) -> 1319.5 (1408.8) MB, 715.1 / 0.0 ms [last resort gc].


<--- JS stacktrace --->

==== JS stack trace =========================================

Security context: 0x39375d6cfb51 <JS Object>
    1: /* anonymous */(aka /* anonymous */) [/home/ivan/devel/**redacted**/node_modules/gobble-rollup/node_modules/rollup/dist/rollup.js:~8897] [pc=0x2efaea47863] (this=0x39375d604381 <undefined>,line=0x37c3199ae8b9 <JS Array[12]>)
    2: arguments adaptor frame: 3->1
    3: map [native array.js:~994] [pc=0x2efae7d1832] (this=0x3483785a6779 <JS Array[40573]>,bq=0x198328e274e1 <JS Function (...

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory
 1: node::Abort() [gobble]
 2: 0xd6fb6c [gobble]
 3: v8::Utils::ReportApiFailure(char const*, char const*) [gobble]
 4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [gobble]
 5: v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationSpace) [gobble]
 6: v8::internal::Runtime_AllocateInTargetSpace(int, v8::internal::Object**, v8::internal::Isolate*) [gobble]
 7: 0x2efad3079a7
Aborted
error Command failed with exit code 134.

Judging by the stack traces, the problem is in the memory allocation of some Gobble code.

I also have experienced Gobble not dying gracefully when interrupted by Ctrl+C because there was an open socket to a browser. I'm gonna make a wild guess and say that Gobble is keeping in memory more copies of the files than it should.

So the question is: How can I debug this further?

[fskreuz]

My 2c, try running Gobble with either node-inspector or with node using the --inspect. I believe the dev tools still has the profiler.

[evs-chris]

My experience with this was that it was caused by rollup. Dropping gobble-rollup in favor of basically inlining it in the gobblefile to get the most recent flavor of gobble stopped the OOMs for me.

[IvanSanchez]

@evs-chris Care to elaborate?

[IvanSanchez]

Thanks to @fskreuz 's suggestion, I can see that most of the memory (> 50%) is being taken up by magic-string and its sourcemapLocations.

But, unlike devtools in the browser, there are no good facilities for a memory allocation timeline, or filtering out circular references, so I can't be completely sure. Also taking a (big) heap snapshot fails :-/

It might be worth it to try and take heap snapshots with smaller projects, and see if the sourcemap chains grow up in memory consumption over time.

[evs-chris]

Ractive's build used to die about every 8th rebuild before we added changed the bundle step to basically what I linked. @fskreuz cleaned up the build quite a bit beyond that, but that along with pulling the latest version of rollup (at the time) seemed to fix the OOMs.