Fatal heap exhaustion when syncing from scratch with v7.11.2

[morninglite]

I'm using [email protected], with a clean/unmodified build from the included Dockerfile, so there is no preexisting database which means syncing from scratch.

(The host is Debian stretch running Docker 19.03.2)

The process runs for about 40 minutes before crashing due to GC failure:

2019-10-01T04:01:52.590445304Z Starting websocket server on port 9001
2019-10-01T04:01:53.301360123Z Getting Augur logs from block 5926223 to block 8654243
2019-10-01T04:01:53.897426051Z got 40 logs in blocks { fromBlock: 5926223, toBlock: 5926882 }
...
2019-10-01T04:43:29.332164352Z new block: 6266555, 1536009635 (Mon Sep 03 2018 21:20:35 GMT+0000 (Coordinated Universal Time))
2019-10-01T04:43:29.337147927Z Processing 1 logs
2019-10-01T04:43:29.340857012Z Fetched 20 / 104 block details (current: 7185528)
2019-10-01T04:43:31.761970334Z 
2019-10-01T04:43:31.762013519Z <--- Last few GCs --->
2019-10-01T04:43:31.762019513Z 
2019-10-01T04:43:31.762023500Z [17:0x3aba070]  2505025 ms: Mark-sweep 1309.5 (1456.0) -> 1304.8 (1456.0) MB, 670.7 / 0.1 ms  (average mu = 0.184, current mu = 0.160) allocation failure GC in old space requested
2019-10-01T04:43:31.762039822Z [17:0x3aba070]  2506047 ms: Mark-sweep 1304.8 (1456.0) -> 1304.8 (1456.0) MB, 937.1 / 0.0 ms  (average mu = 0.132, current mu = 0.084) allocation failure GC in old space requested
2019-10-01T04:43:31.762044997Z 
2019-10-01T04:43:31.762048109Z 
2019-10-01T04:43:31.762051603Z <--- JS stacktrace --->
2019-10-01T04:43:31.762055047Z 
2019-10-01T04:43:31.762058064Z ==== JS stack trace =========================================
2019-10-01T04:43:31.762061308Z 
2019-10-01T04:43:31.762064722Z     0: ExitFrame [pc: 0x1162133dbe1d]
2019-10-01T04:43:31.762067941Z Security context: 0x383b63b1e6e9 <JSObject>
2019-10-01T04:43:31.762071262Z     1: memoized [0x2ee0140aa771] [/app/node_modules/ethrpc/node_modules/lodash/lodash.js:~10543] [pc=0x116214ffa4d3](this=0x3cd13ab1ad81 <JSGlobal Object>)
2019-10-01T04:43:31.762074769Z     2: arguments adaptor frame: 1->0
2019-10-01T04:43:31.762077709Z     3: set [0x22597cb5fe9] [/app/node_modules/ethrpc/src/internal-state.js:~10] [pc=0x11621549ef59](this=0x26e85ece0819 <Object map = 0xc13c4320131>,path=0x22383dbe515...
2019-10-01T04:43:31.762081238Z 
2019-10-01T04:43:31.762103357Z FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
2019-10-01T04:43:31.764633762Z  1: 0x8dc510 node::Abort() [node]

Once restarted, it continues for another hour or so before failing again:

2019-10-01T17:53:20.521642441Z Starting websocket server on port 9001
2019-10-01T17:53:21.218128228Z Getting Augur logs from block 6267299 to block 8657923
2019-10-01T17:53:21.714132653Z got 44 logs in blocks { fromBlock: 6267299, toBlock: 6267522 }
...
2019-10-01T18:52:47.478776598Z new block: 7139237, 1548681772 (Mon Jan 28 2019 13:22:52 GMT+0000 (Coordinated Universal Time))
2019-10-01T18:52:47.493751382Z Processing 8 logs
2019-10-01T18:52:47.740001187Z Fetched 10 / 54 block details (current: 8085617)
2019-10-01T18:52:48.041011012Z Fetched 20 / 54 block details (current: 8085818)
2019-10-01T18:52:48.198266146Z Fetched 30 / 54 block details (current: 8085877)
2019-10-01T18:52:49.512460955Z FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
2019-10-01T18:52:49.512463457Z 
2019-10-01T18:52:49.512511979Z <--- Last few GCs --->
2019-10-01T18:52:49.512516925Z 
2019-10-01T18:52:49.512521017Z [17:0x367f070]  3567773 ms: Mark-sweep 1326.1 (1453.7) -> 1310.4 (1454.2) MB, 673.6 / 0.3 ms  (average mu = 0.386, current mu = 0.427) allocation failure scavenge might not succeed
2019-10-01T18:52:49.512525954Z [17:0x367f070]  3568782 ms: Mark-sweep 1326.3 (1454.2) -> 1310.5 (1454.7) MB, 673.6 / 0.3 ms  (average mu = 0.363, current mu = 0.333) allocation failure scavenge might not succeed
2019-10-01T18:52:49.512530300Z 
2019-10-01T18:52:49.512533598Z 
2019-10-01T18:52:49.512536952Z <--- JS stacktrace --->
2019-10-01T18:52:49.512540684Z 
2019-10-01T18:52:49.512544710Z ==== JS stack trace =========================================
2019-10-01T18:52:49.512548280Z 
2019-10-01T18:52:49.512551349Z     0: ExitFrame [pc: 0xf2a22e861e1]
2019-10-01T18:52:49.512554948Z Security context: 0x32671cb9e6e9 <JSObject>
2019-10-01T18:52:49.512558511Z     1: stringSlice(aka stringSlice) [0x2f654ea05a9] [buffer.js:~589] [pc=0xf2a22f90dc1](this=0x0c6c5aa026f1 <undefined>,buf=0x08f219682c29 <Uint8Array map = 0x392b20253771>,encoding=0x0c6c5aa026f1 <undefined>,start=0,end=524140)
2019-10-01T18:52:49.512562664Z     2: toString [0x118e28c1e5d9] [buffer.js:~643] [pc=0xf2a23d49012](this=0x08f219682c29 <Uint8Array map = 0x392b20253771>,encoding=...
2019-10-01T18:52:49.512566680Z 
2019-10-01T18:52:49.512848863Z  1: 0x8dc510 node::Abort() [node]

That seems to suggest a memory leak -- if all the memory was actually needed to proceed, it should die pretty soon after restart, not after processing several more months of blocks.

Additionally, the apparent 1.5GB used at crash time is far less than the available memory on the machine:

              total        used        free      shared  buff/cache   available
Mem:            31G         13G        6.9G        1.5G         11G         16G
Swap:           31G        2.0G         30G

So, if this isn't a memory leak, or at least not one that can be easily fixed, then it seems that the provided Dockerfile should adjust the maximum size of the JS heap to some value that works.