Prysm: Memory consumption during initial sync

[farazdagi]

• this is a meta issue to track memory optimization PRs, which will improve memory consumption during initial sync
• we need to find an upper bound of minimum memory required to sync (making sure that such a bound exists and memory doesn't grow unconstrained) note: at the moment it seems docker image with 8GiB of memory is necessary to sync
• then gradually decrease memory consumption via several optimization PRs
• related issue #4970
• start from https://github.com/prysmaticlabs/prysm/pull/5245 PR

[nisdas]

@Magicking hey could you give more details on the setup you are using to run the node ? I can't reproduce the memory usage increasing to 6.8gb of resident memory. It has stayed from 1gb - 2.5gb .

[metanull-operator]

I had an OOM crash this morning for the first time in months on one of my two beacon chains.

Running beacon with the following command:
beacon-chain --datadir=/home/eth2/prysm --min-sync-peers=7 --p2p-max-peers=50 --monitoring-port 8080 --p2p-tcp-port 13000 --p2p-udp-port 12000 --rpc-port 4000 --p2p-host-ip=XXX.XXX.XXX.XXX --http-web3provider http://192.168.XXX.XXX:8545 --web3provider ws://192.168.XXX.XXX:8546 --peer /ip4/192.168.XXX.XXX/tcp/13001/p2p/16Uiu2HAm19mzAn8MQrKWb3nr4U6XKyYZ5RVvP4WPv723EedDWsY8

Beacon was synced the night prior to the crash, and had 50 peers up until the point of crash. Grafana chart shows memory usage slowly increasing over the prior 5 days up until crash.

Logs show:

May  1 06:02:39 beacon01 beacon-chain[12379]: time="2020-05-01 06:02:39" level=info msg="Executing state transition on block" prefix=blockchain root=0xd469773a... slot=97213
May  1 06:02:43 beacon01 beacon-chain[12379]: time="2020-05-01 06:02:43" level=info msg="Finished applying state transition" attestations=23 attesterSlashings=0 deposits=0 prefix=blockchain proposerSlashings=0 slot=97213 voluntaryExits=0
May  1 06:02:53 beacon01 beacon-chain[12379]: time="2020-05-01 06:02:53" level=info msg="Executing state transition on block" prefix=blockchain root=0x9a4b108b... slot=97214
May  1 06:02:53 beacon01 beacon-chain[12379]: time="2020-05-01 06:02:53" level=info msg="Finished applying state transition" attestations=11 attesterSlashings=0 deposits=0 prefix=blockchain proposerSlashings=0 slot=97214 voluntaryExits=0
May  1 06:03:04 beacon01 beacon-chain[12379]: time="2020-05-01 06:03:04" level=info msg="Executing state transition on block" prefix=blockchain root=0xad04c09a... slot=97215
May  1 06:03:47 beacon01 beacon-chain[12379]: fatal error: runtime: out of memory
May  1 06:04:05 beacon01 beacon-chain[12379]: runtime stack:
May  1 06:04:19 beacon01 beacon-chain[12379]: runtime.throw(0x1738bcf, 0x16)
May  1 06:04:45 beacon01 beacon-chain[12379]: #011GOROOT/src/runtime/panic.go:1112 +0x72
May  1 06:05:03 beacon01 beacon-chain[12379]: runtime.sysMap(0xc490000000, 0x4000000, 0x27af3f8)
May  1 06:05:18 beacon01 beacon-chain[12379]: #011GOROOT/src/runtime/mem_linux.go:169 +0xc5
May  1 06:05:19 beacon01 beacon-chain[12379]: runtime.(*mheap).sysAlloc(0x27967a0, 0x400000, 0x27967a8, 0x1ea)
May  1 06:05:29 beacon01 beacon-chain[12379]: #011GOROOT/src/runtime/malloc.go:715 +0x1cd
May  1 06:05:49 beacon01 beacon-chain[12379]: runtime.(*mheap).grow(0x27967a0, 0x1ea, 0x0)
May  1 06:06:35 beacon01 beacon-chain[12379]: #011GOROOT/src/runtime/mheap.go:1286 +0x11c
May  1 06:06:42 beacon01 beacon-chain[12379]: runtime.(*mheap).allocSpan(0x27967a0, 0x1ea, 0x7f6faae60100, 0x27af408, 0x436e66)
May  1 06:06:43 beacon01 beacon-chain[12379]: #011GOROOT/src/runtime/mheap.go:1124 +0x6a0
May  1 06:06:48 beacon01 beacon-chain[12379]: runtime.(*mheap).alloc.func1()
May  1 06:06:51 beacon01 beacon-chain[12379]: #011GOROOT/src/runtime/mheap.go:871 +0x64
May  1 06:06:52 beacon01 beacon-chain[12379]: runtime.(*mheap).alloc(0x27967a0, 0x1ea, 0x7f6faae60101, 0x7f6f1a33a818)
May  1 06:07:02 beacon01 beacon-chain[12379]: #011GOROOT/src/runtime/mheap.go:865 +0x81
May  1 06:07:02 beacon01 beacon-chain[12379]: runtime.largeAlloc(0x3d3c60, 0x480101, 0x7f6f1a33a818)
May  1 06:07:14 beacon01 beacon-chain[12379]: #011GOROOT/src/runtime/malloc.go:1152 +0x92
May  1 06:07:36 beacon01 beacon-chain[12379]: runtime.mallocgc.func1()
May  1 06:07:56 beacon01 beacon-chain[12379]: #011GOROOT/src/runtime/malloc.go:1047 +0x46
May  1 06:08:18 beacon01 beacon-chain[12379]: runtime.systemstack(0x0)
May  1 06:08:29 beacon01 beacon-chain[12379]: #011GOROOT/src/runtime/asm_amd64.s:370 +0x66
May  1 06:08:38 beacon01 beacon-chain[12379]: runtime.mstart()
May  1 06:08:51 beacon01 beacon-chain[12379]: #011GOROOT/src/runtime/proc.go:1041
May  1 06:08:56 beacon01 beacon-chain[12379]: goroutine 156870908 [running]:
May  1 06:09:06 beacon01 beacon-chain[12379]: runtime.systemstack_switch()
May  1 06:09:24 beacon01 beacon-chain[12379]: #011GOROOT/src/runtime/asm_amd64.s:330 fp=0xc018307560 sp=0xc018307558 pc=0x486db0
May  1 06:09:39 beacon01 beacon-chain[12379]: runtime.mallocgc(0x3d3c60, 0x1492ee0, 0x23cdb201, 0x10fe26d75b1c1e8)
May  1 06:09:51 beacon01 beacon-chain[12379]: #011GOROOT/src/runtime/malloc.go:1046 +0x895 fp=0xc018307600 sp=0xc018307560 pc=0x42df45
May  1 06:10:05 beacon01 beacon-chain[12379]: runtime.makeslice(0x1492ee0, 0x7a78c, 0x7a78c, 0xc012a1fb48)
May  1 06:10:15 beacon01 beacon-chain[12379]: #011GOROOT/src/runtime/slice.go:49 +0x6c fp=0xc018307630 sp=0xc018307600 pc=0x46df2c
May  1 06:10:17 beacon01 beacon-chain[12379]: github.com/prysmaticlabs/prysm/beacon-chain/state.(*BeaconState).Copy(0xc01a9c4e00, 0x0)
May  1 06:10:17 beacon01 beacon-chain[12379]: #011beacon-chain/state/state_trie.go:126 +0x88a fp=0xc018307948 sp=0xc018307630 pc=0xb41a6a
May  1 06:10:34 beacon01 beacon-chain[12379]: github.com/prysmaticlabs/prysm/beacon-chain/blockchain.(*Service).headState(0xc00000c3c0, 0x0)
May  1 06:11:04 beacon01 beacon-chain[12379]: #011beacon-chain/blockchain/head.go:202 +0x82 fp=0xc018307988 sp=0xc018307948 pc=0x116a192
May  1 06:12:13 beacon01 beacon-chain[12379]: github.com/prysmaticlabs/prysm/beacon-chain/blockchain.(*Service).HeadState(0xc00000c3c0, 0x1af31c0, 0xc01d49e120, 0x0, 0x0, 0x0)

[metanull-operator]

I should add this commit I was using: 33774721bb585d4fca85343fbd9592274f246274

My system has 16GB RAM.

[terencechain]

Can confirm. Syncing 2/3 of the way through, and the memory is at 4.2GB

[metanull-operator]

Update after upgrading to v1.0.0-alpha.6, memory consumption looks more reasonably now, but I will continue to monitor.

Edit: You can see prior memory problem in the middle, then last restart after upgrade to alpha.6.

[rkapka]

I just wanted to confirm the issue. I tried to sync the blockchain on Windows 10 and the process has consumed over 5GB of ram at around 50000 blocks. I used the --enable-state-ref-copy flag. Without the flag it got to 4.5GB at around 30000 blocks.

EDIT:
I was able to successfully sync on Windows Server 2019 with 16GB of RAM. Memory usage peaked at almost 9846MB at one point (probably somewhere around block 100,000). The CPU usage was in the 70-75 percent range most of the time (Intel(R) Xeon(R) E5-2673 @ 2.30GHz). After completing the initial sync the CPU usage dropped to around 60% and the memory usage stayed at the peak level - 9864MB.

[rauljordan]

Initial sync is currently significantly stable. We can close unless these suspicions arise again from user reports.