Stage Sync Problem

[lianqiao]

Hi,

How can I force stage sync to download all the blocks first, then move to execution stages etc?

My current erigon do stages by small pieces, e.g. 10-20k block download, then execution etc. After all the stages, it moves back to download other 10-20k blocks, then execution etc. This is much slower than download everything first and proceed to execution stages etc.

I am running erigon locally on my macbook air, the network is slower than aws, but disk performance is much better. Since it takes a lot of computation in the stage sync, this is much fast with the same cost.

Thanks!

[AskAlexSharov]

Show some logs

[AskAlexSharov]

• if it related to slow network - I may know the reason, but need see logs first to confirm.

[lianqiao]

First, let me put the log when erigon starts, it includes version info etc.

INFO[01-07|18:22:30.613] Build info                               git_branch=stable git_tag=v2021.12.03 git_commit=fa869bf7a1bd1ae00cc5c98fab51705217bdba8d
INFO[01-07|18:22:30.613] Starting Erigon on Ethereum mainnet... 
INFO[01-07|18:22:30.614] Maximum peer count                       ETH=100 total=100
INFO[01-07|18:22:30.614] Set global gas cap                       cap=50000000
INFO[01-07|18:22:30.640] Opening Database                         label=chaindata path=/Users/lianqiao/Library/Erigon/chaindata
INFO[01-07|18:22:30.644] Initialised chain configuration          config="{ChainID: 1 Homestead: 1150000 DAO: 1920000 DAOSupport: true EIP150: 2463000 EIP155: 2675000 EIP158: 2675000 Byzantium: 4370000 Constantinople: 7280000 Petersburg: 7280000 Istanbul: 9069000, Muir Glacier: 9200000, Berlin: 12244000, London: 12965000, Arrow Glacier: 13773000, Engine: ethash}"
INFO[01-07|18:22:30.644] Disk storage enabled for ethash DAGs     dir=/Users/lianqiao/Library/Erigon/ethash-dags count=2
INFO[01-07|18:22:30.644] Initialising Ethereum protocol           network=1
INFO[01-07|18:22:30.644] Effective                                prune="--prune="
INFO[01-07|18:22:30.943] Starting private RPC server              on=127.0.0.1:9090

Some of the problematic log are following, it repeated between stage 1 and 3, downloaded 20k plus blocks, and proceed to stage 4+

INFO[01-07|12:23:14.250] [3/15 Bodies] DONE                       in=2m30.002751958s
INFO[01-07|12:23:14.260] RPC Daemon notified of new headers       from=13955090 to=13956114
INFO[01-07|12:23:14.260] [1/15 Headers] Waiting for headers...    from=13956114
INFO[01-07|12:23:44.263] [1/15 Headers] Wrote block headers       number=13956114 blk/second=0.000 alloc="294.23 MiB" sys="473.80 MiB"
INFO[01-07|12:24:14.264] [1/15 Headers] Wrote block headers       number=13956114 blk/second=0.000 alloc="294.79 MiB" sys="473.80 MiB"
INFO[01-07|12:24:16.456] [p2p] GoodPeers                          eth66=0
INFO[01-07|12:24:44.265] [1/15 Headers] Wrote block headers       number=13956114 blk/second=0.000 alloc="295.37 MiB" sys="473.80 MiB"
INFO[01-07|12:25:14.265] [1/15 Headers] Wrote block headers       number=13956114 blk/second=0.000 alloc="292.25 MiB" sys="473.80 MiB"
INFO[01-07|12:25:44.266] [1/15 Headers] Wrote block headers       number=13956114 blk/second=0.000 alloc="292.91 MiB" sys="473.80 MiB"
INFO[01-07|12:26:14.267] [1/15 Headers] Wrote block headers       number=13956114 blk/second=0.000 alloc="293.49 MiB" sys="473.80 MiB"
INFO[01-07|12:26:16.459] [p2p] GoodPeers                          eth66=1
WARN[01-07|12:26:37.305] Invalidating anchor for suspected unavailability height=13956134
INFO[01-07|12:26:44.267] [1/15 Headers] Wrote block headers       number=13956114 blk/second=0.000 alloc="294.09 MiB" sys="473.80 MiB"
INFO[01-07|12:27:14.268] [1/15 Headers] Wrote block headers       number=13956114 blk/second=0.000 alloc="292.25 MiB" sys="473.80 MiB"
INFO[01-07|12:27:42.316] [1/15 Headers] Processed                 highest inserted=13956146 age=26s
INFO[01-07|12:27:42.316] [1/15 Headers] DONE                      in=4m28.049401208s
INFO[01-07|12:27:42.338] [3/15 Bodies] Processing bodies...       from=10036881 to=13956146
INFO[01-07|12:28:12.341] [3/15 Bodies] Wrote block bodies         block_num=10036881 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="300.81 MiB" sys="473.80 MiB"
INFO[01-07|12:28:16.461] [p2p] GoodPeers                          eth66=1
INFO[01-07|12:28:42.342] [3/15 Bodies] Wrote block bodies         block_num=10036881 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="302.93 MiB" sys="473.80 MiB"
INFO[01-07|12:29:12.342] [3/15 Bodies] Wrote block bodies         block_num=10036881 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="292.36 MiB" sys="473.80 MiB"
INFO[01-07|12:29:42.343] [3/15 Bodies] Wrote block bodies         block_num=10036881 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="292.85 MiB" sys="473.80 MiB"
INFO[01-07|12:30:12.344] [3/15 Bodies] Wrote block bodies         block_num=10036881 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="293.34 MiB" sys="473.80 MiB"
INFO[01-07|12:30:12.344] [3/15 Bodies] DONE                       in=2m30.002831792s
INFO[01-07|12:30:12.353] RPC Daemon notified of new headers       from=13955122 to=13956146
INFO[01-07|12:30:12.353] [1/15 Headers] Waiting for headers...    from=13956146
INFO[01-07|12:30:16.464] [p2p] GoodPeers                          eth66=0
INFO[01-07|12:30:42.355] [1/15 Headers] Wrote block headers       number=13956146 blk/second=0.000 alloc="295.16 MiB" sys="473.80 MiB"
INFO[01-07|12:31:12.356] [1/15 Headers] Wrote block headers       number=13956146 blk/second=0.000 alloc="292.38 MiB" sys="473.80 MiB"
INFO[01-07|12:31:42.357] [1/15 Headers] Wrote block headers       number=13956146 blk/second=0.000 alloc="292.95 MiB" sys="473.80 MiB"
INFO[01-07|12:32:12.357] [1/15 Headers] Wrote block headers       number=13956146 blk/second=0.000 alloc="293.59 MiB" sys="473.80 MiB"
INFO[01-07|12:32:16.466] [p2p] GoodPeers                          eth66=1
INFO[01-07|12:32:21.694] [1/15 Headers] Processed                 highest inserted=13956171 age=50s
INFO[01-07|12:32:21.694] [1/15 Headers] DONE                      in=2m9.33875175s
INFO[01-07|12:32:21.709] [3/15 Bodies] Processing bodies...       from=10036881 to=13956171
INFO[01-07|12:32:51.712] [3/15 Bodies] Wrote block bodies         block_num=10036881 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="302.72 MiB" sys="473.80 MiB"
INFO[01-07|12:33:21.712] [3/15 Bodies] Wrote block bodies         block_num=10036881 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="292.39 MiB" sys="473.80 MiB"
INFO[01-07|12:33:51.713] [3/15 Bodies] Wrote block bodies         block_num=10036881 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="292.91 MiB" sys="473.80 MiB"
INFO[01-07|12:34:16.469] [p2p] GoodPeers                          eth66=0
INFO[01-07|12:34:21.714] [3/15 Bodies] Wrote block bodies         block_num=10036881 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="293.40 MiB" sys="473.80 MiB"
INFO[01-07|12:34:51.714] [3/15 Bodies] Wrote block bodies         block_num=10036881 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="293.88 MiB" sys="473.80 MiB"
INFO[01-07|12:34:51.715] [3/15 Bodies] DONE                       in=2m30.001902958s
INFO[01-07|12:34:51.726] RPC Daemon notified of new headers       from=13955147 to=13956171
INFO[01-07|12:34:51.726] [1/15 Headers] Waiting for headers...    from=13956171
INFO[01-07|12:35:21.729] [1/15 Headers] Wrote block headers       number=13956171 blk/second=0.000 alloc="292.35 MiB" sys="473.80 MiB"
INFO[01-07|12:35:51.730] [1/15 Headers] Wrote block headers       number=13956171 blk/second=0.000 alloc="292.99 MiB" sys="473.80 MiB"
INFO[01-07|12:36:16.471] [p2p] GoodPeers                          eth66=1
INFO[01-07|12:36:21.730] [1/15 Headers] Wrote block headers       number=13956171 blk/second=0.000 alloc="293.59 MiB" sys="473.80 MiB"
INFO[01-07|12:36:51.731] [1/15 Headers] Wrote block headers       number=13956171 blk/second=0.000 alloc="294.18 MiB" sys="473.80 MiB"
WARN[01-07|12:37:00.750] Invalidating anchor for suspected unavailability height=13956187
INFO[01-07|12:37:21.731] [1/15 Headers] Wrote block headers       number=13956171 blk/second=0.000 alloc="292.37 MiB" sys="473.80 MiB"
INFO[01-07|12:37:51.732] [1/15 Headers] Wrote block headers       number=13956171 blk/second=0.000 alloc="292.97 MiB" sys="473.80 MiB"
INFO[01-07|12:38:16.474] [p2p] GoodPeers                          eth66=1
INFO[01-07|12:38:19.091] [1/15 Headers] Processed                 highest inserted=13956200 age=34s
INFO[01-07|12:38:19.091] [1/15 Headers] DONE                      in=3m27.360266375s
INFO[01-07|12:38:19.101] [3/15 Bodies] Processing bodies...       from=10036881 to=13956200
INFO[01-07|12:38:49.104] [3/15 Bodies] Wrote block bodies         block_num=10036881 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="302.54 MiB" sys="473.80 MiB"
INFO[01-07|12:39:19.105] [3/15 Bodies] Wrote block bodies         block_num=10036881 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="292.53 MiB" sys="473.80 MiB"
INFO[01-07|12:39:49.105] [3/15 Bodies] Wrote block bodies         block_num=10036881 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="293.22 MiB" sys="473.80 MiB"
INFO[01-07|12:40:16.477] [p2p] GoodPeers                          eth66=1
INFO[01-07|12:40:19.106] [3/15 Bodies] Wrote block bodies         block_num=10036881 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="295.76 MiB" sys="473.80 MiB"
INFO[01-07|12:40:49.107] [3/15 Bodies] Wrote block bodies         block_num=10036881 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="297.90 MiB" sys="473.80 MiB"
INFO[01-07|12:40:49.107] [3/15 Bodies] DONE                       in=2m30.002879917s
INFO[01-07|12:40:49.118] RPC Daemon notified of new headers       from=13955176 to=13956200
INFO[01-07|12:40:49.118] [1/15 Headers] Waiting for headers...    from=13956200
INFO[01-07|12:41:19.119] [1/15 Headers] Wrote block headers       number=13956200 blk/second=0.000 alloc="293.55 MiB" sys="473.80 MiB"
INFO[01-07|12:41:49.120] [1/15 Headers] Wrote block headers       number=13956200 blk/second=0.000 alloc="294.13 MiB" sys="473.80 MiB"
INFO[01-07|12:42:16.479] [p2p] GoodPeers                          eth66=1
INFO[01-07|12:42:19.121] [1/15 Headers] Wrote block headers       number=13956200 blk/second=0.000 alloc="294.73 MiB" sys="473.80 MiB"
INFO[01-07|12:42:49.121] [1/15 Headers] Wrote block headers       number=13956200 blk/second=0.000 alloc="295.34 MiB" sys="473.80 MiB"
INFO[01-07|12:43:19.122] [1/15 Headers] Wrote block headers       number=13956200 blk/second=0.000 alloc="293.53 MiB" sys="473.80 MiB"
WARN[01-07|12:43:23.128] Invalidating anchor for suspected unavailability height=13956202
WARN[01-07|12:43:23.128] Invalidating anchor for suspected unavailability height=13956208
INFO[01-07|12:43:30.599] [1/15 Headers] Processed                 highest inserted=13956222 age=22s
INFO[01-07|12:43:30.599] [1/15 Headers] DONE                      in=2m41.477132959s
INFO[01-07|12:43:30.605] [3/15 Bodies] Processing bodies...       from=10036881 to=13956222
INFO[01-07|12:44:00.607] [3/15 Bodies] Wrote block bodies         block_num=10036954 delivery/sec="8.79 MiB" wasted/sec="0.00 B" alloc="728.43 MiB" sys="907.64 MiB"
INFO[01-07|12:44:16.480] [p2p] GoodPeers                          eth66=1
INFO[01-07|12:44:30.607] [3/15 Bodies] Wrote block bodies         block_num=10037100 delivery/sec="9.52 MiB" wasted/sec="0.00 B" alloc="1.05 GiB" sys="1.47 GiB"
INFO[01-07|12:45:00.620] [3/15 Bodies] Wrote block bodies         block_num=10041553 delivery/sec="9.27 MiB" wasted/sec="0.00 B" alloc="1.58 GiB" sys="1.89 GiB"
INFO[01-07|12:45:30.610] [3/15 Bodies] Wrote block bodies         block_num=10059229 delivery/sec="5.02 MiB" wasted/sec="0.00 B" alloc="1.38 GiB" sys="2.45 GiB"
INFO[01-07|12:46:00.610] [3/15 Bodies] Wrote block bodies         block_num=10059229 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="1.38 GiB" sys="2.45 GiB"
INFO[01-07|12:46:16.484] [p2p] GoodPeers                          eth66=0
INFO[01-07|12:46:30.610] [3/15 Bodies] Wrote block bodies         block_num=10059229 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="1.38 GiB" sys="2.45 GiB"
INFO[01-07|12:47:00.611] [3/15 Bodies] Wrote block bodies         block_num=10059229 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="1.38 GiB" sys="2.45 GiB"
INFO[01-07|12:47:30.610] [3/15 Bodies] Wrote block bodies         block_num=10059229 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="790.09 MiB" sys="2.45 GiB"
INFO[01-07|12:48:00.611] [3/15 Bodies] Wrote block bodies         block_num=10059229 delivery/sec="0.00 B" wasted/sec="0.00 B" alloc="790.79 MiB" sys="2.45 GiB"
INFO[01-07|12:48:11.651] [3/15 Bodies] Processed                  highest=10059229
INFO[01-07|12:48:11.651] [3/15 Bodies] DONE                       in=4m41.040603625s
INFO[01-07|12:48:11.651] [4/15 Senders] Started                   from=10036881 to=10059229
INFO[01-07|12:48:16.486] [p2p] GoodPeers                          eth66=0
INFO[01-07|12:48:41.653] [4/15 Senders] Recovery                  block_number=10051849
INFO[01-07|12:48:56.600] [5/15 Execution] Blocks execution        from=10036881 to=10059229
INFO[01-07|12:49:26.629] [5/15 Execution] Executed blocks         number=10037498 blk/s=20.547 tx/s=3244.148 Mgas/s=190.200 batch="9.24 MiB" alloc="1.35 GiB" sys="2.94 GiB"
INFO[01-07|12:49:56.604] [5/15 Execution] Executed blocks         number=10038420 blk/s=30.759 tx/s=4334.987 Mgas/s=290.897 batch="23.22 MiB" alloc="1.81 GiB" sys="2.94 GiB"
INFO[01-07|12:50:16.490] [p2p] GoodPeers                          eth66=1
INFO[01-07|12:50:26.610] [5/15 Execution] Executed blocks         number=10039476 blk/s=35.194 tx/s=4501.830 Mgas/s=329.876 batch="37.84 MiB" alloc="2.02 GiB" sys="2.94 GiB"
INFO[01-07|12:50:56.621] [5/15 Execution] Executed blocks         number=10040434 blk/s=31.922 tx/s=3918.755 Mgas/s=300.284 batch="50.60 MiB" alloc="2.67 GiB" sys="2.94 GiB"
INFO[01-07|12:51:26.605] [5/15 Execution] Executed blocks         number=10041450 blk/s=33.886 tx/s=3962.111 Mgas/s=306.437 batch="63.89 MiB" alloc="3.04 GiB" sys="3.31 GiB"
INFO[01-07|12:51:56.621] [5/15 Execution] Executed blocks         number=10042480 blk/s=34.315 tx/s=4752.122 Mgas/s=317.139 batch="77.79 MiB" alloc="3.33 GiB" sys="3.62 GiB"
INFO[01-07|12:52:16.492] [p2p] GoodPeers                          eth66=5
INFO[01-07|12:52:26.608] [5/15 Execution] Executed blocks         number=10043518 blk/s=34.616 tx/s=5488.638 Mgas/s=321.278 batch="89.19 MiB" alloc="3.45 GiB" sys="4.12 GiB"
INFO[01-07|12:52:56.620] [5/15 Execution] Executed blocks         number=10044505 blk/s=32.888 tx/s=5253.406 Mgas/s=306.800 batch="100.58 MiB" alloc="2.92 GiB" sys="4.53 GiB"
INFO[01-07|12:53:26.618] [5/15 Execution] Executed blocks         number=10045401 blk/s=29.870 tx/s=4536.413 Mgas/s=283.537 batch="110.37 MiB" alloc="3.89 GiB" sys="4.80 GiB"
INFO[01-07|12:53:56.626] [5/15 Execution] Executed blocks         number=10046284 blk/s=29.426 tx/s=3949.519 Mgas/s=274.281 batch="120.27 MiB" alloc="4.41 GiB" sys="5.09 GiB"
INFO[01-07|12:54:16.494] [p2p] GoodPeers                          eth66=5
INFO[01-07|12:54:26.631] [5/15 Execution] Executed blocks         number=10047152 blk/s=28.929 tx/s=3280.576 Mgas/s=271.672 batch="129.08 MiB" alloc="4.75 GiB" sys="5.38 GiB"
INFO[01-07|12:54:56.617] [5/15 Execution] Executed blocks         number=10048055 blk/s=30.115 tx/s=3029.679 Mgas/s=283.369 batch="141.23 MiB" alloc="4.70 GiB" sys="5.71 GiB"
INFO[01-07|12:55:26.623] [5/15 Execution] Executed blocks         number=10048850 blk/s=26.494 tx/s=3721.860 Mgas/s=247.176 batch="149.84 MiB" alloc="4.82 GiB" sys="5.98 GiB"
INFO[01-07|12:55:56.630] [5/15 Execution] Executed blocks         number=10049722 blk/s=29.061 tx/s=4098.714 Mgas/s=270.865 batch="159.97 MiB" alloc="4.83 GiB" sys="6.40 GiB"
INFO[01-07|12:56:16.497] [p2p] GoodPeers                          eth66=5
INFO[01-07|12:56:26.615] [5/15 Execution] Executed blocks         number=10050461 blk/s=24.646 tx/s=3507.378 Mgas/s=231.518 batch="168.85 MiB" alloc="4.16 GiB" sys="6.82 GiB"
INFO[01-07|12:56:56.644] [5/15 Execution] Executed blocks         number=10051296 blk/s=27.807 tx/s=4544.220 Mgas/s=255.310 batch="176.95 MiB" alloc="6.72 GiB" sys="7.22 GiB"
INFO[01-07|12:57:26.633] [5/15 Execution] Executed blocks         number=10052001 blk/s=23.509 tx/s=3562.888 Mgas/s=222.666 batch="184.50 MiB" alloc="5.90 GiB" sys="7.26 GiB"
INFO[01-07|12:57:56.651] [5/15 Execution] Executed blocks         number=10052714 blk/s=23.753 tx/s=3299.110 Mgas/s=219.830 batch="192.72 MiB" alloc="4.77 GiB" sys="7.69 GiB"
INFO[01-07|12:58:16.498] [p2p] GoodPeers                          eth66=5
INFO[01-07|12:58:26.651] [5/15 Execution] Executed blocks         number=10053394 blk/s=22.668 tx/s=2764.674 Mgas/s=211.617 batch="200.77 MiB" alloc="6.72 GiB" sys="7.69 GiB"
INFO[01-07|12:58:56.622] [5/15 Execution] Executed blocks         number=10054085 blk/s=23.056 tx/s=2510.880 Mgas/s=213.159 batch="209.58 MiB" alloc="5.19 GiB" sys="8.10 GiB"
INFO[01-07|12:59:26.623] [5/15 Execution] Executed blocks         number=10054832 blk/s=24.899 tx/s=2929.652 Mgas/s=233.629 batch="218.48 MiB" alloc="7.37 GiB" sys="8.10 GiB"
INFO[01-07|12:59:56.621] [5/15 Execution] Executed blocks         number=10055574 blk/s=24.736 tx/s=3488.558 Mgas/s=233.351 batch="226.56 MiB" alloc="6.00 GiB" sys="8.60 GiB"
INFO[01-07|13:00:16.502] [p2p] GoodPeers                          eth66=5
INFO[01-07|13:00:26.650] [5/15 Execution] Executed blocks         number=10056434 blk/s=28.640 tx/s=3385.665 Mgas/s=267.376 batch="236.04 MiB" alloc="8.43 GiB" sys="9.02 GiB"
INFO[01-07|13:00:56.631] [5/15 Execution] Executed blocks         number=10057187 blk/s=25.116 tx/s=3404.764 Mgas/s=233.058 batch="243.29 MiB" alloc="6.69 GiB" sys="9.18 GiB"
INFO[01-07|13:01:26.682] [5/15 Execution] Executed blocks         number=10057875 blk/s=22.895 tx/s=3237.741 Mgas/s=215.080 batch="250.63 MiB" alloc="8.79 GiB" sys="9.40 GiB"
INFO[01-07|13:01:56.666] [5/15 Execution] Executed blocks         number=10058411 blk/s=17.876 tx/s=2641.237 Mgas/s=168.725 batch="256.28 MiB" alloc="6.37 GiB" sys="9.76 GiB"
INFO[01-07|13:02:16.505] [p2p] GoodPeers                          eth66=5
INFO[01-07|13:02:26.628] [5/15 Execution] Executed blocks         number=10058991 blk/s=19.362 tx/s=2786.462 Mgas/s=182.527 batch="262.70 MiB" alloc="8.21 GiB" sys="9.76 GiB"
INFO[01-07|13:03:07.908] Write to db                              progress=0.3M/4.1M current table=PlainState
INFO[01-07|13:03:37.907] Write to db                              progress=0.7M/4.1M current table=PlainState
INFO[01-07|13:04:07.907] Write to db                              progress=1.1M/4.1M current table=PlainState
INFO[01-07|13:04:16.508] [p2p] GoodPeers                          eth66=5
INFO[01-07|13:04:39.169] Write to db                              progress=1.9M/4.1M current table=PlainState
INFO[01-07|13:05:09.673] Write to db                              progress=2.6M/4.1M current table=PlainState
INFO[01-07|13:05:37.911] Write to db                              progress=3.2M/4.1M current table=PlainState
INFO[01-07|13:06:07.908] Write to db                              progress=4.0M/4.1M current table=PlainState
INFO[01-07|13:06:16.508] [p2p] GoodPeers                          eth66=5
INFO[01-07|13:06:18.983] [5/15 Execution] Completed on            block=10059229
INFO[01-07|13:06:18.983] [5/15 Execution] DONE                    in=17m22.361402166s
INFO[01-07|13:06:18.984] [7/15 HashState] Promoting plain state   from=10036881 to=10059229
INFO[01-07|13:06:18.984] [7/15 HashState] Incremental promotion started from=10036881 to=10059229 codes=true csbucket=AccountChangeSet
INFO[01-07|13:06:48.992] [7/15 HashState] ETL [1/2] Extracting    from=AccountChangeSet current key=0000000000993ba9 alloc="5.3 GiB" sys="9.8 GiB"
INFO[01-07|13:07:25.514] [7/15 HashState] Incremental promotion started from=10036881 to=10059229 codes=false csbucket=AccountChangeSet
INFO[01-07|13:07:55.517] [7/15 HashState] ETL [1/2] Extracting    from=AccountChangeSet current key=0000000000994636 alloc="4.8 GiB" sys="9.9 GiB"
INFO[01-07|13:08:16.513] [p2p] GoodPeers                          eth66=5
INFO[01-07|13:08:55.367] [7/15 HashState] ETL [2/2] Loading       into=HashedAccount current key=41fe6eed... alloc="5.6 GiB" sys="10.2 GiB"
INFO[01-07|13:09:23.978] [7/15 HashState] ETL [2/2] Loading       into=HashedAccount current key=94a0f28e... alloc="5.7 GiB" sys="10.2 GiB"
INFO[01-07|13:09:53.694] [7/15 HashState] ETL [2/2] Loading       into=HashedAccount current key=eebef607... alloc="4.8 GiB" sys="10.2 GiB"
INFO[01-07|13:09:58.203] [7/15 HashState] Incremental promotion started from=10036881 to=10059229 codes=false csbucket=StorageChangeSet
INFO[01-07|13:10:16.516] [p2p] GoodPeers                          eth66=5
INFO[01-07|13:10:28.207] [7/15 HashState] ETL [1/2] Extracting    from=StorageChangeSet current key=000000000099348b5acc84a3e955bdd76467d3348077d003f00ffb970000000000000001 alloc="5.3 GiB" sys="10.2 GiB"
INFO[01-07|13:11:02.718] Flushed buffer file                      name=/Users/lianqiao/Library/Erigon/etl-temp/tg-sync-sortable-buf2119443829 alloc="7.3 GiB" sys="10.8 GiB"
INFO[01-07|13:11:02.756] [7/15 HashState] ETL [1/2] Extracting    from=StorageChangeSet current key=0000000000995948aafe28df831c2eaa28c0dab68947e30eaec765c80000000000000001 alloc="7.3 GiB" sys="10.8 GiB"
INFO[01-07|13:11:28.207] [7/15 HashState] ETL [1/2] Extracting    from=StorageChangeSet current key=0000000000996a72ba9dc7d88783a466e469ee60bf1884812f31c9c10000000000000001 alloc="7.8 GiB" sys="10.8 GiB"
INFO[01-07|13:11:52.366] Flushed buffer file                      name=/Users/lianqiao/Library/Erigon/etl-temp/tg-sync-sortable-buf3818739177 alloc="5.4 GiB" sys="10.9 GiB"
INFO[01-07|13:12:16.517] [p2p] GoodPeers                          eth66=5
INFO[01-07|13:12:25.394] [7/15 HashState] ETL [2/2] Loading       into=HashedStorage current key=46cb276c... alloc="5.8 GiB" sys="10.9 GiB"
INFO[01-07|13:12:52.802] [7/15 HashState] ETL [2/2] Loading       into=HashedStorage current key=8e910a28... alloc="6.0 GiB" sys="10.9 GiB"
INFO[01-07|13:13:22.400] [7/15 HashState] ETL [2/2] Loading       into=HashedStorage current key=d9582e1e... alloc="6.3 GiB" sys="10.9 GiB"
INFO[01-07|13:13:35.861] [7/15 HashState] etl: temp files removed total size="251.2 MB"
INFO[01-07|13:13:47.433] [7/15 HashState] DONE                    in=7m28.439051791s
INFO[01-07|13:13:47.436] [8/15 IntermediateHashes] Generating intermediate hashes from=10036881 to=10059229
INFO[01-07|13:14:16.520] [p2p] GoodPeers                          eth66=5
INFO[01-07|13:14:17.438] [8/15 IntermediateHashes] ETL [1/2] Extracting from=AccountChangeSet current key=00000000009938ca alloc="4.8 GiB" sys="10.9 GiB"
INFO[01-07|13:15:07.859] Flushed buffer file                      name=/Users/lianqiao/Library/Erigon/etl-temp/tg-sync-sortable-buf4168332959 alloc="8.5 GiB" sys="11.2 GiB"
INFO[01-07|13:15:18.183] Flushed buffer file                      name=/Users/lianqiao/Library/Erigon/etl-temp/tg-sync-sortable-buf4065218797 alloc="5.9 GiB" sys="11.2 GiB"
INFO[01-07|13:15:21.702] [8/15 IntermediateHashes] etl: temp files removed total size="232.3 MB"
INFO[01-07|13:15:51.705] [8/15 IntermediateHashes] Calculating Merkle root current key=166f167a...
INFO[01-07|13:16:16.524] [p2p] GoodPeers                          eth66=6
INFO[01-07|13:16:21.707] [8/15 IntermediateHashes] Calculating Merkle root current key=41ac1b05...
INFO[01-07|13:16:51.707] [8/15 IntermediateHashes] Calculating Merkle root current key=6d1a2561...
INFO[01-07|13:17:07.482] Flushed buffer file                      name=/Users/lianqiao/Library/Erigon/etl-temp/tg-sync-sortable-buf4137271383 alloc="9.1 GiB" sys="11.3 GiB"
INFO[01-07|13:17:21.709] [8/15 IntermediateHashes] Calculating Merkle root current key=90d7bc32...
INFO[01-07|13:17:46.673] Flushed buffer file                      name=/Users/lianqiao/Library/Erigon/etl-temp/tg-sync-sortable-buf355199105 alloc="6.1 GiB" sys="11.3 GiB"
INFO[01-07|13:17:51.913] [8/15 IntermediateHashes] Calculating Merkle root current key=b167bbdf...
INFO[01-07|13:18:16.525] [p2p] GoodPeers                          eth66=6
INFO[01-07|13:18:21.710] [8/15 IntermediateHashes] Calculating Merkle root current key=e21e7244...
INFO[01-07|13:18:44.567] Flushed buffer file                      name=/Users/lianqiao/Library/Erigon/etl-temp/tg-sync-sortable-buf3742547709 alloc="7.0 GiB" sys="11.3 GiB"
INFO[01-07|13:19:14.601] [8/15 IntermediateHashes] ETL [2/2] Loading into=TrieAccount current key=0a0f0e0d... alloc="7.7 GiB" sys="11.3 GiB"
INFO[01-07|13:19:23.875] [8/15 IntermediateHashes] etl: temp files removed total size="391.4 MB"
INFO[01-07|13:19:24.625] Flushed buffer file                      name=/Users/lianqiao/Library/Erigon/etl-temp/tg-sync-sortable-buf1729469678 alloc="5.4 GiB" sys="11.3 GiB"
INFO[01-07|13:19:54.654] [8/15 IntermediateHashes] ETL [2/2] Loading into=TrieStorage current key=9f13f882... alloc="6.1 GiB" sys="11.3 GiB"
INFO[01-07|13:20:10.046] [8/15 IntermediateHashes] etl: temp files removed total size="519.2 MB"
INFO[01-07|13:20:16.534] [p2p] GoodPeers                          eth66=6
INFO[01-07|13:20:28.681] [8/15 IntermediateHashes] DONE           in=6m41.239538s
INFO[01-07|13:21:20.177] [9/15 CallTraces] ETL [2/2] Loading      into=CallFromIndex current key=4a28e7af... alloc="4.8 GiB" sys="11.3 GiB"
INFO[01-07|13:21:43.341] [9/15 CallTraces] ETL [2/2] Loading      into=CallFromIndex current key=78c35be6... alloc="5.7 GiB" sys="11.3 GiB"
INFO[01-07|13:22:13.670] [9/15 CallTraces] ETL [2/2] Loading      into=CallFromIndex current key=cd295b22... alloc="6.9 GiB" sys="11.3 GiB"
INFO[01-07|13:22:16.532] [p2p] GoodPeers                          eth66=7
INFO[01-07|13:23:00.275] [9/15 CallTraces] ETL [2/2] Loading      into=CallToIndex current key=5593982b... alloc="4.9 GiB" sys="11.3 GiB"
INFO[01-07|13:23:30.270] [9/15 CallTraces] ETL [2/2] Loading      into=CallToIndex current key=b2567019... alloc="6.8 GiB" sys="11.3 GiB"
INFO[01-07|13:23:58.951] [9/15 CallTraces] DONE                   in=3m30.265037833s
INFO[01-07|13:24:16.534] [p2p] GoodPeers                          eth66=7
INFO[01-07|13:24:38.494] [10/15 AccountHistoryIndex] ETL [2/2] Loading into=AccountHistory current key=42978825... alloc="5.8 GiB" sys="11.3 GiB"
INFO[01-07|13:25:08.497] [10/15 AccountHistoryIndex] ETL [2/2] Loading into=AccountHistory current key=908f978b... alloc="7.7 GiB" sys="11.3 GiB"
INFO[01-07|13:25:39.341] [10/15 AccountHistoryIndex] ETL [2/2] Loading into=AccountHistory current key=e1335c8f... alloc="4.8 GiB" sys="11.4 GiB"
INFO[01-07|13:25:55.198] [10/15 AccountHistoryIndex] DONE         in=1m56.239419084s
INFO[01-07|13:26:16.535] [p2p] GoodPeers                          eth66=7
INFO[01-07|13:26:46.937] [11/15 StorageHistoryIndex] ETL [2/2] Loading into=StorageHistory current key=312a90b3... alloc="5.3 GiB" sys="11.6 GiB"
INFO[01-07|13:27:24.063] [11/15 StorageHistoryIndex] ETL [2/2] Loading into=StorageHistory current key=794e6e91... alloc="6.4 GiB" sys="11.6 GiB"
INFO[01-07|13:27:53.110] [11/15 StorageHistoryIndex] ETL [2/2] Loading into=StorageHistory current key=8a91c9a1... alloc="6.7 GiB" sys="11.6 GiB"
INFO[01-07|13:28:16.538] [p2p] GoodPeers                          eth66=7
INFO[01-07|13:28:19.672] [11/15 StorageHistoryIndex] ETL [2/2] Loading into=StorageHistory current key=8a91c9a1... alloc="7.0 GiB" sys="11.6 GiB"
INFO[01-07|13:28:48.452] [11/15 StorageHistoryIndex] ETL [2/2] Loading into=StorageHistory current key=a22c1b53... alloc="5.3 GiB" sys="11.6 GiB"
INFO[01-07|13:29:20.754] [11/15 StorageHistoryIndex] ETL [2/2] Loading into=StorageHistory current key=bd9b95c6... alloc="5.7 GiB" sys="11.6 GiB"
INFO[01-07|13:29:47.667] [11/15 StorageHistoryIndex] ETL [2/2] Loading into=StorageHistory current key=dac17f95... alloc="6.1 GiB" sys="11.6 GiB"
INFO[01-07|13:30:16.540] [p2p] GoodPeers                          eth66=7
INFO[01-07|13:30:16.941] [11/15 StorageHistoryIndex] ETL [2/2] Loading into=StorageHistory current key=f5fff180... alloc="7.3 GiB" sys="11.6 GiB"
INFO[01-07|13:30:32.423] [11/15 StorageHistoryIndex] DONE         in=4m37.216953209s
INFO[01-07|13:31:17.866] [12/15 LogIndex] ETL [2/2] Loading       into=LogTopicIndex current key=0000000000000000000000004956e8fd8bd856306f11f8768133c344351428a9ffffffff alloc="7.6 GiB" sys="11.6 GiB"
INFO[01-07|13:31:48.468] [12/15 LogIndex] ETL [2/2] Loading       into=LogTopicIndex current key=000000000000000000000000740b700c0ebbbb27fc4d0cbeb7e99d78c902f020ffffffff alloc="8.1 GiB" sys="11.6 GiB"
INFO[01-07|13:32:16.544] [p2p] GoodPeers                          eth66=7
INFO[01-07|13:32:17.866] [12/15 LogIndex] ETL [2/2] Loading       into=LogTopicIndex current key=000000000000000000000000c6cfc6a31e516d1622b80c0864b16f665712f89effffffff alloc="8.8 GiB" sys="11.6 GiB"
INFO[01-07|13:32:47.875] [12/15 LogIndex] ETL [2/2] Loading       into=LogTopicIndex current key=000000000000000000000000eee28d484628d41a82d01e21d12e2e78d69920da009958de alloc="4.9 GiB" sys="11.6 GiB"
INFO[01-07|13:33:51.821] [12/15 LogIndex] DONE                    in=3m19.393961375s
INFO[01-07|13:34:16.547] [p2p] GoodPeers                          eth66=8
INFO[01-07|13:34:48.975] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=17ad4694... alloc="7.0 GiB" sys="11.6 GiB"
INFO[01-07|13:35:19.476] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=1ee8157e... alloc="7.0 GiB" sys="11.6 GiB"
INFO[01-07|13:35:48.976] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=2df4c5d4... alloc="7.1 GiB" sys="11.6 GiB"
INFO[01-07|13:36:16.548] [p2p] GoodPeers                          eth66=8
INFO[01-07|13:36:19.909] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=3b64e759... alloc="4.9 GiB" sys="11.6 GiB"
INFO[01-07|13:36:48.973] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=4a0c7163... alloc="4.9 GiB" sys="11.6 GiB"
INFO[01-07|13:37:19.896] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=5a3f09c5... alloc="5.0 GiB" sys="11.6 GiB"
INFO[01-07|13:37:48.973] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=69d146e2... alloc="5.0 GiB" sys="11.6 GiB"
INFO[01-07|13:38:16.550] [p2p] GoodPeers                          eth66=8
INFO[01-07|13:38:19.525] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=745789dd... alloc="4.9 GiB" sys="11.6 GiB"
INFO[01-07|13:38:48.974] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=7d659112... alloc="4.9 GiB" sys="11.6 GiB"
INFO[01-07|13:39:18.975] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=88368cdc... alloc="4.9 GiB" sys="11.6 GiB"
INFO[01-07|13:39:48.977] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=9417ecec... alloc="4.9 GiB" sys="11.6 GiB"
INFO[01-07|13:40:16.555] [p2p] GoodPeers                          eth66=8
INFO[01-07|13:40:23.421] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=a1664a8f... alloc="4.9 GiB" sys="11.6 GiB"
INFO[01-07|13:40:53.541] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=aae3cf89... alloc="4.9 GiB" sys="11.6 GiB"
INFO[01-07|13:41:20.947] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=b4626b3e... alloc="4.9 GiB" sys="11.6 GiB"
INFO[01-07|13:41:48.978] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=bffd623c... alloc="5.0 GiB" sys="11.6 GiB"
INFO[01-07|13:42:16.557] [p2p] GoodPeers                          eth66=8
INFO[01-07|13:42:20.662] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=c9be98cb... alloc="4.9 GiB" sys="11.6 GiB"
INFO[01-07|13:42:48.980] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=d7760360... alloc="4.9 GiB" sys="11.6 GiB"
INFO[01-07|13:43:20.909] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=e643ca16... alloc="4.9 GiB" sys="11.6 GiB"
INFO[01-07|13:43:51.080] [13/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current key=f470a247... alloc="5.0 GiB" sys="11.6 GiB"
INFO[01-07|13:44:16.563] [p2p] GoodPeers                          eth66=8
INFO[01-07|13:44:43.104] [13/15 TxLookup] DONE                    in=10m51.268092083s

[lianqiao]

This is another example, from start to stage 5 pretty quickly.

INFO[01-07|22:20:13.448] Build info                               git_branch=stable git_tag=v2021.12.03 git_commit=fa869bf7a1bd1ae00cc5c98fab51705217bdba8d
INFO[01-07|22:20:13.448] Starting Erigon on Ethereum mainnet... 
INFO[01-07|22:20:13.449] Maximum peer count                       ETH=100 total=100
INFO[01-07|22:20:13.449] Set global gas cap                       cap=50000000
INFO[01-07|22:20:13.477] Opening Database                         label=chaindata path=/Users/lianqiao/Library/Erigon/chaindata
INFO[01-07|22:20:13.484] Initialised chain configuration          config="{ChainID: 1 Homestead: 1150000 DAO: 1920000 DAOSupport: true EIP150: 2463000 EIP155: 2675000 EIP158: 2675000 Byzantium: 4370000 Constantinople: 7280000 Petersburg: 7280000 Istanbul: 9069000, Muir Glacier: 9200000, Berlin: 12244000, London: 12965000, Arrow Glacier: 13773000, Engine: ethash}"
INFO[01-07|22:20:13.484] Disk storage enabled for ethash DAGs     dir=/Users/lianqiao/Library/Erigon/ethash-dags count=2
INFO[01-07|22:20:13.484] Initialising Ethereum protocol           network=1
INFO[01-07|22:20:13.485] Effective                                prune="--prune="
INFO[01-07|22:20:13.793] Starting private RPC server              on=127.0.0.1:9090
INFO[01-07|22:20:13.794] [1/15 Headers] Waiting for headers...    from=13958783
INFO[01-07|22:20:13.802] Started P2P networking                   version=66 self=enode://3e7b1c93b4712a7463b55c0cc83517243a0d557c5a2d6e525c0a9ac8b63c4de438461be5fc942dece86e0a03fd22ed1b8e3332f93a4e507e06db0e0e84653e19@127.0.0.1:30303 name=erigon/v2021.12.3-beta-fa869bf7/darwin-arm64/go1.17.5
INFO[01-07|22:20:24.307] [1/15 Headers] Processed                 highest inserted=13958826 age=30s
INFO[01-07|22:20:24.340] [3/15 Bodies] Processing bodies...       from=10657999 to=13958826
INFO[01-07|22:20:54.342] [3/15 Bodies] Wrote block bodies         block_num=10658052 delivery/sec="551.01 KiB" wasted/sec="0.00 B" alloc="353.96 MiB" sys="403.66 MiB"
INFO[01-07|22:21:24.343] [3/15 Bodies] Wrote block bodies         block_num=10658052 delivery/sec="344.65 KiB" wasted/sec="0.00 B" alloc="398.72 MiB" sys="450.28 MiB"
INFO[01-07|22:21:54.343] [3/15 Bodies] Wrote block bodies         block_num=10658052 delivery/sec="275.44 KiB" wasted/sec="0.00 B" alloc="437.56 MiB" sys="488.98 MiB"
INFO[01-07|22:22:13.487] [p2p] GoodPeers                          eth66=3
INFO[01-07|22:22:24.343] [3/15 Bodies] Wrote block bodies         block_num=10658052 delivery/sec="345.83 KiB" wasted/sec="0.00 B" alloc="484.00 MiB" sys="533.05 MiB"
INFO[01-07|22:22:54.344] [3/15 Bodies] Wrote block bodies         block_num=10658052 delivery/sec="482.64 KiB" wasted/sec="0.00 B" alloc="399.77 MiB" sys="541.67 MiB"
INFO[01-07|22:23:24.343] [3/15 Bodies] Wrote block bodies         block_num=10658052 delivery/sec="481.41 KiB" wasted/sec="0.00 B" alloc="462.25 MiB" sys="541.73 MiB"
INFO[01-07|22:23:24.453] [3/15 Bodies] Processed                  highest=10658052
INFO[01-07|22:23:24.453] [3/15 Bodies] DONE                       in=3m0.109967458s
INFO[01-07|22:23:24.453] [4/15 Senders] Started                   from=10657999 to=10658052
INFO[01-07|22:23:24.634] [5/15 Execution] Blocks execution        from=10299611 to=10658052
INFO[01-07|22:23:54.659] [5/15 Execution] Executed blocks         number=10300333 blk/s=24.047 tx/s=3832.040 Mgas/s=273.484 batch="13.97 MiB" alloc="530.63 MiB" sys="889.50 MiB"
INFO[01-07|22:24:13.489] [p2p] GoodPeers                          eth66=4
INFO[01-07|22:24:24.647] [5/15 Execution] Executed blocks         number=10301215 blk/s=29.413 tx/s=4675.148 Mgas/s=333.879 batch="29.32 MiB" alloc="605.02 MiB" sys="978.94 MiB"

[lianqiao]

I am checking network status, found that sometimes body download is very ineffeicient. In the following log period, nettop shows that erigon already downloaded 650MB data, but proceed only 609 blocks

INFO[01-07|22:30:45.024] [3/15 Bodies] Processing bodies...       from=10658052 to=13958869
INFO[01-07|22:31:15.026] [3/15 Bodies] Wrote block bodies         block_num=10658122 delivery/sec="4.30 MiB" wasted/sec="0.00 B" alloc="623.50 MiB" sys="685.28 MiB"
INFO[01-07|22:31:45.027] [3/15 Bodies] Wrote block bodies         block_num=10658122 delivery/sec="3.91 MiB" wasted/sec="0.00 B" alloc="850.07 MiB" sys="915.45 MiB"
INFO[01-07|22:32:14.483] [p2p] GoodPeers                          eth66=4
INFO[01-07|22:32:15.027] [3/15 Bodies] Wrote block bodies         block_num=10658122 delivery/sec="2.43 MiB" wasted/sec="0.00 B" alloc="838.71 MiB" sys="999.02 MiB"
INFO[01-07|22:32:45.026] [3/15 Bodies] Wrote block bodies         block_num=10658174 delivery/sec="3.61 MiB" wasted/sec="0.00 B" alloc="871.91 MiB" sys="1.26 GiB"
INFO[01-07|22:33:15.027] [3/15 Bodies] Wrote block bodies         block_num=10658174 delivery/sec="2.69 MiB" wasted/sec="0.00 B" alloc="1.16 GiB" sys="1.26 GiB"
INFO[01-07|22:33:45.028] [3/15 Bodies] Wrote block bodies         block_num=10658174 delivery/sec="3.31 MiB" wasted/sec="0.00 B" alloc="1.03 GiB" sys="1.63 GiB"
INFO[01-07|22:34:14.486] [p2p] GoodPeers                          eth66=4
INFO[01-07|22:34:15.029] [3/15 Bodies] Wrote block bodies         block_num=10658223 delivery/sec="3.50 MiB" wasted/sec="0.00 B" alloc="1.43 GiB" sys="1.63 GiB"
INFO[01-07|22:34:45.029] [3/15 Bodies] Wrote block bodies         block_num=10658223 delivery/sec="2.29 MiB" wasted/sec="0.00 B" alloc="1.70 GiB" sys="1.82 GiB"
INFO[01-07|22:35:15.030] [3/15 Bodies] Wrote block bodies         block_num=10658387 delivery/sec="3.15 MiB" wasted/sec="0.00 B" alloc="1.40 GiB" sys="2.09 GiB"
INFO[01-07|22:35:45.030] [3/15 Bodies] Wrote block bodies         block_num=10658387 delivery/sec="1.89 MiB" wasted/sec="0.00 B" alloc="1.62 GiB" sys="2.09 GiB"
INFO[01-07|22:36:14.484] [p2p] GoodPeers                          eth66=4
INFO[01-07|22:36:15.028] [3/15 Bodies] Wrote block bodies         block_num=10658548 delivery/sec="3.10 MiB" wasted/sec="0.00 B" alloc="1.98 GiB" sys="2.11 GiB"
INFO[01-07|22:36:45.028] [3/15 Bodies] Wrote block bodies         block_num=10658710 delivery/sec="2.15 MiB" wasted/sec="0.00 B" alloc="2.23 GiB" sys="2.38 GiB"

[AskAlexSharov]

yes, I also saw this on slow vpn DONE in=2m30.002751958s - this is some hard-coded timeout - i will increase it.
2m30s = noProgressCount * cfg.BodyDownloadTimeoutSeconds = 5 * 30