search

erigontech / erigon

Ethereum implementation on the efficiency frontier https://erigon.gitbook.io
GNU Lesser General Public License v3.0
3.11k stars 1.09k forks source link

Stuck at block height 17999999 #8796

Closed caedmo closed 6 months ago

caedmo commented 10 months ago

Hi all

I'm wondering if I'm stuck, given a reused Beacon chain (previously running with Geth), against a fresh Erigon full sync? Appreciate any help/suggestions!

Notes

Versions

Execution chain: Erigon 2.53.4-c4843268 Beacon chain: Nimbus v23.10.0-8b07f4 Go: go1.20.10 linux/amd64 OS: Fedora 36, Intel XEON

CPU

$ lscpu 
Architecture:            x86_64
  CPU op-mode(s):        32-bit, 64-bit
  Address sizes:         46 bits physical, 48 bits virtual
  Byte Order:            Little Endian
CPU(s):                  24
  On-line CPU(s) list:   0-23
Vendor ID:               GenuineIntel
  Model name:            Intel(R) Xeon(R) CPU E5-2670 v3 @ 2.30GHz
    CPU family:          6
    Model:               63
    Thread(s) per core:  2
    Core(s) per socket:  12
    Socket(s):           1
    Stepping:            2
    CPU(s) scaling MHz:  40%
    CPU max MHz:         3100.0000
    CPU min MHz:         1200.0000
    BogoMIPS:            4597.36
    Flags:               fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid dca 
                         sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm cpuid_fault epb invpcid_single pti intel_ppin ssbd ibrs ibpb stibp tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid cqm xsaveopt cqm_llc cqm_occup_llc dtherm ida arat pln pts md_clear flus                         h_l1d
Virtualization features: 
  Virtualization:        VT-x

Erigon configuration

erigon \
        --chain="mainnet" \
        --datadir="/storage/ethereum/erigon/data" \
        --snapshots="true" \
        --authrpc.jwtsecret="/var/ethereum/jwtsecret" \
        --torrent.download.rate="150mb" --torrent.upload.rate="15mb" \
        --http="true" --http.api="web3,net,eth" --http.addr="192.168.2.3" --http.vhosts="*" \
        --ws="true" \
        --ws.compression="false" \
#        --ws.api="web3,net,eth" \
#        --ws.addr="192.168.2.3" \
        --graphql="true" \
        --private.api.addr="192.168.2.3:9191" \
        --authrpc.addr="127.0.0.1" --authrpc.port="8551" --authrpc.vhosts="127.0.0.1"

Output

Nov 20 09:50:23 anon-r2 systemd[1]: Started erigon.service - Erigon Client - Mainnet full.
Nov 20 09:50:23 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:23.837] logging to file system                   log dir=/storage/ethereum/erigon/data/logs file prefix=erigon log level=info json=false
Nov 20 09:50:23 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:23.837] Build info                               git_branch=HEAD git_tag=v2.53.4 git_commit=c4843268b788c0899cdad12d220fea4396afbb56
Nov 20 09:50:23 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:23.838] Starting Erigon on Ethereum mainnet...
Nov 20 09:50:23 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:23.839] Maximum peer count                       ETH=100 total=100
Nov 20 09:50:23 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:23.839] starting HTTP APIs                       APIs=web3,net,eth
Nov 20 09:50:23 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:23.840] torrent verbosity                        level=WRN
Nov 20 09:50:25 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:25.944] Set global gas cap                       cap=50000000
Nov 20 09:50:26 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:26.042] [Downloader] Runnning with               ipv6-enabled=true ipv4-enabled=true download.rate=150mb upload.rate=15mb
Nov 20 09:50:26 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:26.042] Opening Database                         label=chaindata path=/storage/ethereum/erigon/data/chaindata
Nov 20 09:50:26 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:26.046] [db] chaindata                           sizeLimit=3TB pageSize=8192
Nov 20 09:50:26 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:26.047] Initialised chain configuration          config="{ChainID: 1, Homestead: 1150000, DAO: 1920000, Tangerine Whistle: 2463000, Spurious Dragon: 2675000, Byzantium: 4370000, Constantinople: 7280000, Petersburg: 7280000, Istanbul: 9069000, Muir Glacier: 9200000, Berlin: 12244000, London: 12965000, Arrow Glacier: 13773000, Gray Glacier: 15050000, Terminal Total Difficulty: 58750000000000000000000, Merge Netsplit: <nil>, Shanghai: 1681338455, Cancun: <nil>, Prague: <nil>, Engine: ethash}" genesis=0xd4e56740f876aef8c010b86a40d5f56745a118d0906a34e69aec8c0db1cb8fa3
Nov 20 09:50:51 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:51.800] Initialising Ethereum protocol           network=1
Nov 20 09:50:51 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:51.800] Disk storage enabled for ethash DAGs     dir=/storage/ethereum/erigon/data/ethash-dags count=2
Nov 20 09:50:51 anon-r2 erigon[2745314]: 17999999
Nov 20 09:50:53 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:53.795] Starting private RPC server              on=192.168.2.3:9191
Nov 20 09:50:53 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:53.795] new subscription to logs established
Nov 20 09:50:53 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:53.795] rpc filters: subscribing to Erigon events
Nov 20 09:50:53 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:53.795] New txs subscriber joined
Nov 20 09:50:53 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:53.796] new subscription to newHeaders established
Nov 20 09:50:53 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:53.796] HTTP endpoint opened                     url=192.168.2.3:8545 ws=true ws.compression=false grpc=false
Nov 20 09:50:53 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:53.796] Reading JWT secret                       path=/var/ethereum/jwtsecret
Nov 20 09:50:53 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:53.798] HTTP endpoint opened for Engine API      url=127.0.0.1:8551 ws=true ws.compression=false
Nov 20 09:50:53 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:53.809] [1/12 Snapshots] Fetching torrent files metadata
Nov 20 09:50:53 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:53.813] [txpool] Started
Nov 20 09:50:53 anon-r2 erigon[2745314]: [WARN] [11-20|09:50:53.814] NAT ExternalIP resolution has failed, try to pass a different --nat option err="no UPnP or NAT-PMP router discovered"
Nov 20 09:50:53 anon-r2 erigon[2745314]: [WARN] [11-20|09:50:53.816] NAT ExternalIP resolution has failed, try to pass a different --nat option err="no UPnP or NAT-PMP router discovered"
Nov 20 09:50:53 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:53.818] Started P2P networking                   version=67 self=enode://[REDACTED]@127.0.0.1:30304 name=erigon/v2.53.4-c4843268/linux-amd64/go1.20.10
Nov 20 09:50:53 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:53.820] Started P2P networking                   version=68 self=enode://[REDACTED]@127.0.0.1:30303 name=erigon/v2.53.4-c4843268/linux-amd64/go1.20.10
Nov 20 09:50:56 anon-r2 erigon[2745314]: [INFO] [11-20|09:50:56.981] [snapshots] Blocks Stat                  blocks=18000k indices=18000k alloc=3.4GB sys=4.4GB
Nov 20 09:53:51 anon-r2 erigon[2745314]: [INFO] [11-20|09:53:51.788] [p2p] GoodPeers
Nov 20 09:53:53 anon-r2 erigon[2745314]: [INFO] [11-20|09:53:53.796] [txpool] stat                            pending=0 baseFee=0 queued=0 alloc=2.1GB sys=4.4GB

Eventually building over time, to output the same following lines;

Nov 20 05:47:29 anon-r2 erigon[2375722]: [INFO] [11-20|05:47:29.039] [txpool] stat                            pending=10000 baseFee=0 queued=30000 alloc=2.2GB sys=4.5GB
Nov 20 05:50:09 anon-r2 erigon[2375722]: [INFO] [11-20|05:50:09.745] [p2p] GoodPeers
Nov 20 05:50:29 anon-r2 erigon[2375722]: [INFO] [11-20|05:50:29.038] [txpool] stat                            pending=10000 baseFee=0 queued=30000 alloc=2.2GB sys=4.5GB
Nov 20 05:53:09 anon-r2 erigon[2375722]: [INFO] [11-20|05:53:09.745] [p2p] GoodPeers

Thanks for your help!

antonok-edm commented 7 months ago

I restarted syncing from 0 due to a disk failure; now facing the same issue here (stuck at 18299999).

caedmo commented 7 months ago

Erigon reached tip, then threw an error on insertion

Feb 03 11:36:22 anon-r2 erigon[2250351]: [WARN] [02-03|11:36:22.320] [EngineBlockDownloader] Could not insert headers and bodies err="ethereumExecutionModule.InsertBlocks: could not insert: WriteRawTransactions: txId=2153968712, baseTxId=2153968712, label: chaindata, bucket: BlockTransaction, mdbx_cursor_put: MDBX_EKEYMISMATCH: The given key value is mismatched to the current cursor position"

Has now restarted sync from 18299999

Also had another OOM a couple hours ago - nothing specific in the logs as to why, and it seems the node continued that time round, instead of restarting sync from snapshot tip

Feb 03 11:36:08 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:08.232] [EngineBlockDownloader] Downloading block bodies block_num=19146830 delivery/sec=6.9MB wasted/sec=1.3MB remaining=393 delivered=179304 cache=39.9MB alloc=5.9GB sys=9.3GB
Feb 03 11:36:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:13.152] [NewPayload] Handling new payload        height=19147573 hash=0x1583e47659d4868855a6b956cecb8d4e56f739223768257e3413ce8584106449
Feb 03 11:36:21 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:21.887] [EngineBlockDownloader] Processed        highest=19147224
Feb 03 11:36:21 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:21.890] Beginning downloaded blocks insertion
Feb 03 11:36:22 anon-r2 erigon[2250351]: [WARN] [02-03|11:36:22.320] [EngineBlockDownloader] Could not insert headers and bodies err="ethereumExecutionModule.InsertBlocks: could not insert: WriteRawTransactions: txId=2153968712, baseTxId=2153968712, label: chaindata, bucket: BlockTransaction, mdbx_cursor_put: MDBX_EKEYMISMATCH: The given key value is mismatched to the current cursor position"
Feb 03 11:36:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:22.883] P2P                                      app=caplin peers=6
Feb 03 11:36:24 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:24.902] [NewPayload] Handling new payload        height=19147574 hash=0x4e98257dfc7a466d22f889306e9a6f32f675ec5736c486b8b4d20d9a8ffced55
Feb 03 11:36:24 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:24.903] [EngineBlockDownloader] Downloading PoS headers... height=unknown hash=0x1583e47659d4868855a6b956cecb8d4e56f739223768257e3413ce8584106449 requestId=0
Feb 03 11:36:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8272014 blockNumber=19075577 blk/sec=6.4 mbps/sec=1.3418 peers=4 snapshots=0 reconnected=false
Feb 03 11:36:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:59.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8271256 blockNumber=19074827 blk/sec=25.3 mbps/sec=5.3596 peers=6 snapshots=0 reconnected=false
Feb 03 11:37:01 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:01.910] [p2p] GoodPeers                          eth68=17 eth67=28
Feb 03 11:37:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:13.402] [downloader] Downloaded PoS Headers      now=19141429 blk/sec=140.800
Feb 03 11:37:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:22.885] P2P                                      app=caplin peers=7
Feb 03 11:37:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8270382 blockNumber=19073965 blk/sec=29.1 mbps/sec=5.3092 peers=6 snapshots=0 reconnected=false
Feb 03 11:37:38 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:38.696] [txpool] stat                            pending=1297 baseFee=0 queued=30000 alloc=6.0GB sys=9.3GB
Feb 03 11:37:43 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:43.109] [downloader] Downloaded PoS Headers      now=19136821 blk/sec=153.600
Feb 03 11:37:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:59.175] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8269998 blockNumber=19073581 blk/sec=12.8 mbps/sec=2.6003 peers=3 snapshots=0 reconnected=false
Feb 03 11:38:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:38:13.425] [downloader] Downloaded PoS Headers      now=19131253 blk/sec=185.600
Feb 03 11:38:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:38:22.882] P2P                                      app=caplin peers=4
Feb 03 11:38:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:38:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8269774 blockNumber=19073360 blk/sec=7.5 mbps/sec=1.6564 peers=11 snapshots=0 reconnected=false
Feb 03 11:38:43 anon-r2 erigon[2250351]: [INFO] [02-03|11:38:43.423] [downloader] Downloaded PoS Headers      now=19124917 blk/sec=211.200
Feb 03 11:38:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:38:59.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8269582 blockNumber=19073169 blk/sec=6.4 mbps/sec=1.3525 peers=3 snapshots=0 reconnected=false
Feb 03 11:39:12 anon-r2 erigon[2250351]: [INFO] [02-03|11:39:12.990] [downloader] Downloaded PoS Headers      now=19116853 blk/sec=268.800
Feb 03 11:39:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:39:22.882] P2P                                      app=caplin peers=4
Feb 03 11:39:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:39:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8269326 blockNumber=19072915 blk/sec=8.5 mbps/sec=1.8904 peers=8 snapshots=0 reconnected=false
Feb 03 11:39:43 anon-r2 erigon[2250351]: [INFO] [02-03|11:39:43.116] [downloader] Downloaded PoS Headers      now=19108789 blk/sec=268.800
Feb 03 11:39:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:39:59.175] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8269198 blockNumber=19072788 blk/sec=4.3 mbps/sec=0.8474 peers=9 snapshots=0 reconnected=false
Feb 03 11:40:01 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:01.909] [p2p] GoodPeers                          eth68=17 eth67=27 eth66=2
Feb 03 11:40:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:13.339] [downloader] Downloaded PoS Headers      now=19098805 blk/sec=332.800
Feb 03 11:40:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:22.883] P2P                                      app=caplin peers=9
Feb 03 11:40:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8268398 blockNumber=19072000 blk/sec=26.7 mbps/sec=5.2127 peers=9 snapshots=0 reconnected=false
Feb 03 11:40:38 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:38.698] [txpool] stat                            pending=1335 baseFee=0 queued=30000 alloc=5.4GB sys=9.3GB
Feb 03 11:40:42 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:42.990] [downloader] Downloaded PoS Headers      now=19086325 blk/sec=416.000
Feb 03 11:40:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:59.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8267598 blockNumber=19071211 blk/sec=26.7 mbps/sec=4.4458 peers=9 snapshots=0 reconnected=false
Feb 03 11:41:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:41:13.124] [downloader] Downloaded PoS Headers      now=19070581 blk/sec=524.800
Feb 03 11:41:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:41:22.882] P2P                                      app=caplin peers=9
Feb 03 11:41:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:41:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8266670 blockNumber=19070293 blk/sec=30.9 mbps/sec=6.0149 peers=9 snapshots=0 reconnected=false
Feb 03 11:41:43 anon-r2 erigon[2250351]: [INFO] [02-03|11:41:43.167] [downloader] Downloaded PoS Headers      now=19047349 blk/sec=774.400
Feb 03 11:41:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:41:59.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8266030 blockNumber=19069660 blk/sec=21.3 mbps/sec=4.3020 peers=5 snapshots=0 reconnected=false
Feb 03 11:42:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:42:13.066] [downloader] Downloaded PoS Headers      now=19021429 blk/sec=864.000
Feb 03 11:42:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:42:22.882] P2P                                      app=caplin peers=4
Feb 03 11:42:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:42:29.175] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8265350 blockNumber=19068983 blk/sec=22.7 mbps/sec=4.5990 peers=12 snapshots=0 reconnected=false
Feb 03 11:42:43 anon-r2 erigon[2250351]: [INFO] [02-03|11:42:43.022] [downloader] Downloaded PoS Headers      now=18983413 blk/sec=1267.200
Feb 03 11:42:58 anon-r2 erigon[2250351]: [INFO] [02-03|11:42:58.798] [EngineBlockDownloader] Processing bodies... from=18967799 to=19147573
Feb 03 11:42:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:42:59.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8264750 blockNumber=19068387 blk/sec=20.0 mbps/sec=4.2126 peers=6 snapshots=0 reconnected=false
Feb 03 11:43:00 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:00.537] [NewPayload] Handling new payload        height=19147607 hash=0x4b68b9eb0159b75396b21c58cc30baeea088794fdd53822737b131c116e532a8
Feb 03 11:43:01 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:01.909] [p2p] GoodPeers                          eth68=18 eth67=27 eth66=1
Feb 03 11:43:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:13.013] [NewPayload] Handling new payload        height=19147608 hash=0x9a067e4382f1682a5b5df55dfdc6f15b96418dc1de69a636baee27aeb982b72c
Feb 03 11:43:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:22.883] P2P                                      app=caplin peers=5
Feb 03 11:43:24 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:24.625] [NewPayload] Handling new payload        height=19147609 hash=0x04b8c817f373f76e4642499e64fd51b10fc481e0f037c39e711204cf2f079370
Feb 03 11:43:28 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:28.800] [EngineBlockDownloader] Downloading block bodies block_num=18968346 delivery/sec=4.3MB wasted/sec=1.0MB remaining=179226 delivered=784 cache=38.2MB alloc=6.8GB sys=9.6GB
Feb 03 11:43:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8264289 blockNumber=19067938 blk/sec=15.4 mbps/sec=3.1864 peers=6 snapshots=0 reconnected=false
Feb 03 11:43:36 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:36.481] [NewPayload] Handling new payload        height=19147610 hash=0x71d848a468e01731ab1e386231d22573b1ee792719463ad631854a198dd74fae
caedmo commented 7 months ago

Moved to 2.57.3-705814b1 - syncing from 18299999 - will update

Giulio2002 commented 7 months ago

Erigon reached tip, then threw an error on insertion

Feb 03 11:36:22 anon-r2 erigon[2250351]: [WARN] [02-03|11:36:22.320] [EngineBlockDownloader] Could not insert headers and bodies err="ethereumExecutionModule.InsertBlocks: could not insert: WriteRawTransactions: txId=2153968712, baseTxId=2153968712, label: chaindata, bucket: BlockTransaction, mdbx_cursor_put: MDBX_EKEYMISMATCH: The given key value is mismatched to the current cursor position"

Has now restarted sync from 18299999

Also had another OOM a couple hours ago - nothing specific in the logs as to why, and it seems the node continued that time round, instead of restarting sync from snapshot tip

Feb 03 11:36:08 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:08.232] [EngineBlockDownloader] Downloading block bodies block_num=19146830 delivery/sec=6.9MB wasted/sec=1.3MB remaining=393 delivered=179304 cache=39.9MB alloc=5.9GB sys=9.3GB
Feb 03 11:36:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:13.152] [NewPayload] Handling new payload        height=19147573 hash=0x1583e47659d4868855a6b956cecb8d4e56f739223768257e3413ce8584106449
Feb 03 11:36:21 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:21.887] [EngineBlockDownloader] Processed        highest=19147224
Feb 03 11:36:21 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:21.890] Beginning downloaded blocks insertion
Feb 03 11:36:22 anon-r2 erigon[2250351]: [WARN] [02-03|11:36:22.320] [EngineBlockDownloader] Could not insert headers and bodies err="ethereumExecutionModule.InsertBlocks: could not insert: WriteRawTransactions: txId=2153968712, baseTxId=2153968712, label: chaindata, bucket: BlockTransaction, mdbx_cursor_put: MDBX_EKEYMISMATCH: The given key value is mismatched to the current cursor position"
Feb 03 11:36:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:22.883] P2P                                      app=caplin peers=6
Feb 03 11:36:24 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:24.902] [NewPayload] Handling new payload        height=19147574 hash=0x4e98257dfc7a466d22f889306e9a6f32f675ec5736c486b8b4d20d9a8ffced55
Feb 03 11:36:24 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:24.903] [EngineBlockDownloader] Downloading PoS headers... height=unknown hash=0x1583e47659d4868855a6b956cecb8d4e56f739223768257e3413ce8584106449 requestId=0
Feb 03 11:36:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8272014 blockNumber=19075577 blk/sec=6.4 mbps/sec=1.3418 peers=4 snapshots=0 reconnected=false
Feb 03 11:36:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:59.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8271256 blockNumber=19074827 blk/sec=25.3 mbps/sec=5.3596 peers=6 snapshots=0 reconnected=false
Feb 03 11:37:01 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:01.910] [p2p] GoodPeers                          eth68=17 eth67=28
Feb 03 11:37:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:13.402] [downloader] Downloaded PoS Headers      now=19141429 blk/sec=140.800
Feb 03 11:37:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:22.885] P2P                                      app=caplin peers=7
Feb 03 11:37:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8270382 blockNumber=19073965 blk/sec=29.1 mbps/sec=5.3092 peers=6 snapshots=0 reconnected=false
Feb 03 11:37:38 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:38.696] [txpool] stat                            pending=1297 baseFee=0 queued=30000 alloc=6.0GB sys=9.3GB
Feb 03 11:37:43 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:43.109] [downloader] Downloaded PoS Headers      now=19136821 blk/sec=153.600
Feb 03 11:37:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:59.175] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8269998 blockNumber=19073581 blk/sec=12.8 mbps/sec=2.6003 peers=3 snapshots=0 reconnected=false
Feb 03 11:38:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:38:13.425] [downloader] Downloaded PoS Headers      now=19131253 blk/sec=185.600
Feb 03 11:38:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:38:22.882] P2P                                      app=caplin peers=4
Feb 03 11:38:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:38:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8269774 blockNumber=19073360 blk/sec=7.5 mbps/sec=1.6564 peers=11 snapshots=0 reconnected=false
Feb 03 11:38:43 anon-r2 erigon[2250351]: [INFO] [02-03|11:38:43.423] [downloader] Downloaded PoS Headers      now=19124917 blk/sec=211.200
Feb 03 11:38:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:38:59.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8269582 blockNumber=19073169 blk/sec=6.4 mbps/sec=1.3525 peers=3 snapshots=0 reconnected=false
Feb 03 11:39:12 anon-r2 erigon[2250351]: [INFO] [02-03|11:39:12.990] [downloader] Downloaded PoS Headers      now=19116853 blk/sec=268.800
Feb 03 11:39:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:39:22.882] P2P                                      app=caplin peers=4
Feb 03 11:39:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:39:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8269326 blockNumber=19072915 blk/sec=8.5 mbps/sec=1.8904 peers=8 snapshots=0 reconnected=false
Feb 03 11:39:43 anon-r2 erigon[2250351]: [INFO] [02-03|11:39:43.116] [downloader] Downloaded PoS Headers      now=19108789 blk/sec=268.800
Feb 03 11:39:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:39:59.175] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8269198 blockNumber=19072788 blk/sec=4.3 mbps/sec=0.8474 peers=9 snapshots=0 reconnected=false
Feb 03 11:40:01 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:01.909] [p2p] GoodPeers                          eth68=17 eth67=27 eth66=2
Feb 03 11:40:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:13.339] [downloader] Downloaded PoS Headers      now=19098805 blk/sec=332.800
Feb 03 11:40:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:22.883] P2P                                      app=caplin peers=9
Feb 03 11:40:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8268398 blockNumber=19072000 blk/sec=26.7 mbps/sec=5.2127 peers=9 snapshots=0 reconnected=false
Feb 03 11:40:38 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:38.698] [txpool] stat                            pending=1335 baseFee=0 queued=30000 alloc=5.4GB sys=9.3GB
Feb 03 11:40:42 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:42.990] [downloader] Downloaded PoS Headers      now=19086325 blk/sec=416.000
Feb 03 11:40:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:59.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8267598 blockNumber=19071211 blk/sec=26.7 mbps/sec=4.4458 peers=9 snapshots=0 reconnected=false
Feb 03 11:41:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:41:13.124] [downloader] Downloaded PoS Headers      now=19070581 blk/sec=524.800
Feb 03 11:41:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:41:22.882] P2P                                      app=caplin peers=9
Feb 03 11:41:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:41:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8266670 blockNumber=19070293 blk/sec=30.9 mbps/sec=6.0149 peers=9 snapshots=0 reconnected=false
Feb 03 11:41:43 anon-r2 erigon[2250351]: [INFO] [02-03|11:41:43.167] [downloader] Downloaded PoS Headers      now=19047349 blk/sec=774.400
Feb 03 11:41:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:41:59.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8266030 blockNumber=19069660 blk/sec=21.3 mbps/sec=4.3020 peers=5 snapshots=0 reconnected=false
Feb 03 11:42:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:42:13.066] [downloader] Downloaded PoS Headers      now=19021429 blk/sec=864.000
Feb 03 11:42:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:42:22.882] P2P                                      app=caplin peers=4
Feb 03 11:42:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:42:29.175] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8265350 blockNumber=19068983 blk/sec=22.7 mbps/sec=4.5990 peers=12 snapshots=0 reconnected=false
Feb 03 11:42:43 anon-r2 erigon[2250351]: [INFO] [02-03|11:42:43.022] [downloader] Downloaded PoS Headers      now=18983413 blk/sec=1267.200
Feb 03 11:42:58 anon-r2 erigon[2250351]: [INFO] [02-03|11:42:58.798] [EngineBlockDownloader] Processing bodies... from=18967799 to=19147573
Feb 03 11:42:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:42:59.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8264750 blockNumber=19068387 blk/sec=20.0 mbps/sec=4.2126 peers=6 snapshots=0 reconnected=false
Feb 03 11:43:00 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:00.537] [NewPayload] Handling new payload        height=19147607 hash=0x4b68b9eb0159b75396b21c58cc30baeea088794fdd53822737b131c116e532a8
Feb 03 11:43:01 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:01.909] [p2p] GoodPeers                          eth68=18 eth67=27 eth66=1
Feb 03 11:43:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:13.013] [NewPayload] Handling new payload        height=19147608 hash=0x9a067e4382f1682a5b5df55dfdc6f15b96418dc1de69a636baee27aeb982b72c
Feb 03 11:43:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:22.883] P2P                                      app=caplin peers=5
Feb 03 11:43:24 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:24.625] [NewPayload] Handling new payload        height=19147609 hash=0x04b8c817f373f76e4642499e64fd51b10fc481e0f037c39e711204cf2f079370
Feb 03 11:43:28 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:28.800] [EngineBlockDownloader] Downloading block bodies block_num=18968346 delivery/sec=4.3MB wasted/sec=1.0MB remaining=179226 delivered=784 cache=38.2MB alloc=6.8GB sys=9.6GB
Feb 03 11:43:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8264289 blockNumber=19067938 blk/sec=15.4 mbps/sec=3.1864 peers=6 snapshots=0 reconnected=false
Feb 03 11:43:36 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:36.481] [NewPayload] Handling new payload        height=19147610 hash=0x71d848a468e01731ab1e386231d22573b1ee792719463ad631854a198dd74fae

Hi, You are running internalcl while forcing the connection to an externalcl, please turn off the external consensus layer

Giulio2002 commented 7 months ago

I restarted syncing from 0 due to a disk failure; now facing the same issue here (stuck at 18299999).

Hi, the eth_blockNumber does not work well with Erigon, do logs show progress?

wmitsuda commented 7 months ago

not sure if it is related, but my other (healthy, not stuck) node crashed (it has the "bad blocks" msg from caplin in common)

WARN[02-01|13:09:16.212] bad blocks segment received              err="replay block, code: 1"
INFO[02-01|13:09:25.146] [Caplin] Epoch downloaded                app=caplin stage=CatchUpEpochs epoch=260314
WARN[02-01|13:09:25.158] fail to process block                    reason="replay block, code: 1" slot=8330050
WARN[02-01|13:09:25.158] bad blocks segment received              err="replay block, code: 1"
INFO[02-01|13:09:29.583] [Caplin] Epoch downloaded                app=caplin stage=CatchUpEpochs epoch=260314
WARN[02-01|13:09:29.595] fail to process block                    reason="replay block, code: 1" slot=8330050
WARN[02-01|13:09:29.595] bad blocks segment received              err="replay block, code: 1"
INFO[02-01|13:09:36.989] P2P                                      app=caplin peers=2
INFO[02-01|13:09:47.645] [Caplin] Epoch downloaded                app=caplin stage=CatchUpEpochs epoch=260314
WARN[02-01|13:09:50.345] fail to process block                    reason="replay block, code: 1" slot=8330050
WARN[02-01|13:09:50.345] bad blocks segment received              err="replay block, code: 1"
INFO[02-01|13:10:24.556] [Caplin] Epoch downloaded                app=caplin stage=CatchUpEpochs epoch=260314
WARN[02-01|13:10:24.568] fail to process block                    reason="replay block, code: 1" slot=8330050
WARN[02-01|13:10:24.568] bad blocks segment received              err="replay block, code: 1"
INFO[02-01|13:10:28.098] [Caplin] Epoch downloaded                app=caplin stage=CatchUpEpochs epoch=260314
WARN[02-01|13:10:28.110] fail to process block                    reason="replay block, code: 1" slot=8330050
WARN[02-01|13:10:28.110] bad blocks segment received              err="replay block, code: 1"
INFO[02-01|13:10:36.988] P2P                                      app=caplin peers=2
INFO[02-01|13:10:55.187] [Caplin] Epoch downloaded                app=caplin stage=CatchUpEpochs epoch=260314
WARN[02-01|13:10:57.991] fail to process block                    reason="replay block, code: 1" slot=8330050
WARN[02-01|13:10:57.991] bad blocks segment received              err="replay block, code: 1"
INFO[02-01|13:11:36.988] P2P                                      app=caplin peers=10
./run-erigon2-gcloud.sh: line 22: 26327 Killed                  ~/erigon/build/bin/erigon --db.size.limit=8TB --datadi
caedmo commented 7 months ago

Erigon reached tip, then threw an error on insertion Feb 03 11:36:22 anon-r2 erigon[2250351]: [WARN] [02-03|11:36:22.320] [EngineBlockDownloader] Could not insert headers and bodies err="ethereumExecutionModule.InsertBlocks: could not insert: WriteRawTransactions: txId=2153968712, baseTxId=2153968712, label: chaindata, bucket: BlockTransaction, mdbx_cursor_put: MDBX_EKEYMISMATCH: The given key value is mismatched to the current cursor position" Has now restarted sync from 18299999 Also had another OOM a couple hours ago - nothing specific in the logs as to why, and it seems the node continued that time round, instead of restarting sync from snapshot tip

Feb 03 11:36:08 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:08.232] [EngineBlockDownloader] Downloading block bodies block_num=19146830 delivery/sec=6.9MB wasted/sec=1.3MB remaining=393 delivered=179304 cache=39.9MB alloc=5.9GB sys=9.3GB
Feb 03 11:36:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:13.152] [NewPayload] Handling new payload        height=19147573 hash=0x1583e47659d4868855a6b956cecb8d4e56f739223768257e3413ce8584106449
Feb 03 11:36:21 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:21.887] [EngineBlockDownloader] Processed        highest=19147224
Feb 03 11:36:21 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:21.890] Beginning downloaded blocks insertion
Feb 03 11:36:22 anon-r2 erigon[2250351]: [WARN] [02-03|11:36:22.320] [EngineBlockDownloader] Could not insert headers and bodies err="ethereumExecutionModule.InsertBlocks: could not insert: WriteRawTransactions: txId=2153968712, baseTxId=2153968712, label: chaindata, bucket: BlockTransaction, mdbx_cursor_put: MDBX_EKEYMISMATCH: The given key value is mismatched to the current cursor position"
Feb 03 11:36:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:22.883] P2P                                      app=caplin peers=6
Feb 03 11:36:24 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:24.902] [NewPayload] Handling new payload        height=19147574 hash=0x4e98257dfc7a466d22f889306e9a6f32f675ec5736c486b8b4d20d9a8ffced55
Feb 03 11:36:24 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:24.903] [EngineBlockDownloader] Downloading PoS headers... height=unknown hash=0x1583e47659d4868855a6b956cecb8d4e56f739223768257e3413ce8584106449 requestId=0
Feb 03 11:36:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8272014 blockNumber=19075577 blk/sec=6.4 mbps/sec=1.3418 peers=4 snapshots=0 reconnected=false
Feb 03 11:36:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:36:59.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8271256 blockNumber=19074827 blk/sec=25.3 mbps/sec=5.3596 peers=6 snapshots=0 reconnected=false
Feb 03 11:37:01 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:01.910] [p2p] GoodPeers                          eth68=17 eth67=28
Feb 03 11:37:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:13.402] [downloader] Downloaded PoS Headers      now=19141429 blk/sec=140.800
Feb 03 11:37:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:22.885] P2P                                      app=caplin peers=7
Feb 03 11:37:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8270382 blockNumber=19073965 blk/sec=29.1 mbps/sec=5.3092 peers=6 snapshots=0 reconnected=false
Feb 03 11:37:38 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:38.696] [txpool] stat                            pending=1297 baseFee=0 queued=30000 alloc=6.0GB sys=9.3GB
Feb 03 11:37:43 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:43.109] [downloader] Downloaded PoS Headers      now=19136821 blk/sec=153.600
Feb 03 11:37:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:37:59.175] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8269998 blockNumber=19073581 blk/sec=12.8 mbps/sec=2.6003 peers=3 snapshots=0 reconnected=false
Feb 03 11:38:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:38:13.425] [downloader] Downloaded PoS Headers      now=19131253 blk/sec=185.600
Feb 03 11:38:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:38:22.882] P2P                                      app=caplin peers=4
Feb 03 11:38:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:38:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8269774 blockNumber=19073360 blk/sec=7.5 mbps/sec=1.6564 peers=11 snapshots=0 reconnected=false
Feb 03 11:38:43 anon-r2 erigon[2250351]: [INFO] [02-03|11:38:43.423] [downloader] Downloaded PoS Headers      now=19124917 blk/sec=211.200
Feb 03 11:38:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:38:59.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8269582 blockNumber=19073169 blk/sec=6.4 mbps/sec=1.3525 peers=3 snapshots=0 reconnected=false
Feb 03 11:39:12 anon-r2 erigon[2250351]: [INFO] [02-03|11:39:12.990] [downloader] Downloaded PoS Headers      now=19116853 blk/sec=268.800
Feb 03 11:39:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:39:22.882] P2P                                      app=caplin peers=4
Feb 03 11:39:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:39:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8269326 blockNumber=19072915 blk/sec=8.5 mbps/sec=1.8904 peers=8 snapshots=0 reconnected=false
Feb 03 11:39:43 anon-r2 erigon[2250351]: [INFO] [02-03|11:39:43.116] [downloader] Downloaded PoS Headers      now=19108789 blk/sec=268.800
Feb 03 11:39:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:39:59.175] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8269198 blockNumber=19072788 blk/sec=4.3 mbps/sec=0.8474 peers=9 snapshots=0 reconnected=false
Feb 03 11:40:01 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:01.909] [p2p] GoodPeers                          eth68=17 eth67=27 eth66=2
Feb 03 11:40:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:13.339] [downloader] Downloaded PoS Headers      now=19098805 blk/sec=332.800
Feb 03 11:40:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:22.883] P2P                                      app=caplin peers=9
Feb 03 11:40:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8268398 blockNumber=19072000 blk/sec=26.7 mbps/sec=5.2127 peers=9 snapshots=0 reconnected=false
Feb 03 11:40:38 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:38.698] [txpool] stat                            pending=1335 baseFee=0 queued=30000 alloc=5.4GB sys=9.3GB
Feb 03 11:40:42 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:42.990] [downloader] Downloaded PoS Headers      now=19086325 blk/sec=416.000
Feb 03 11:40:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:40:59.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8267598 blockNumber=19071211 blk/sec=26.7 mbps/sec=4.4458 peers=9 snapshots=0 reconnected=false
Feb 03 11:41:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:41:13.124] [downloader] Downloaded PoS Headers      now=19070581 blk/sec=524.800
Feb 03 11:41:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:41:22.882] P2P                                      app=caplin peers=9
Feb 03 11:41:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:41:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8266670 blockNumber=19070293 blk/sec=30.9 mbps/sec=6.0149 peers=9 snapshots=0 reconnected=false
Feb 03 11:41:43 anon-r2 erigon[2250351]: [INFO] [02-03|11:41:43.167] [downloader] Downloaded PoS Headers      now=19047349 blk/sec=774.400
Feb 03 11:41:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:41:59.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8266030 blockNumber=19069660 blk/sec=21.3 mbps/sec=4.3020 peers=5 snapshots=0 reconnected=false
Feb 03 11:42:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:42:13.066] [downloader] Downloaded PoS Headers      now=19021429 blk/sec=864.000
Feb 03 11:42:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:42:22.882] P2P                                      app=caplin peers=4
Feb 03 11:42:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:42:29.175] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8265350 blockNumber=19068983 blk/sec=22.7 mbps/sec=4.5990 peers=12 snapshots=0 reconnected=false
Feb 03 11:42:43 anon-r2 erigon[2250351]: [INFO] [02-03|11:42:43.022] [downloader] Downloaded PoS Headers      now=18983413 blk/sec=1267.200
Feb 03 11:42:58 anon-r2 erigon[2250351]: [INFO] [02-03|11:42:58.798] [EngineBlockDownloader] Processing bodies... from=18967799 to=19147573
Feb 03 11:42:59 anon-r2 erigon[2250351]: [INFO] [02-03|11:42:59.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8264750 blockNumber=19068387 blk/sec=20.0 mbps/sec=4.2126 peers=6 snapshots=0 reconnected=false
Feb 03 11:43:00 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:00.537] [NewPayload] Handling new payload        height=19147607 hash=0x4b68b9eb0159b75396b21c58cc30baeea088794fdd53822737b131c116e532a8
Feb 03 11:43:01 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:01.909] [p2p] GoodPeers                          eth68=18 eth67=27 eth66=1
Feb 03 11:43:13 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:13.013] [NewPayload] Handling new payload        height=19147608 hash=0x9a067e4382f1682a5b5df55dfdc6f15b96418dc1de69a636baee27aeb982b72c
Feb 03 11:43:22 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:22.883] P2P                                      app=caplin peers=5
Feb 03 11:43:24 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:24.625] [NewPayload] Handling new payload        height=19147609 hash=0x04b8c817f373f76e4642499e64fd51b10fc481e0f037c39e711204cf2f079370
Feb 03 11:43:28 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:28.800] [EngineBlockDownloader] Downloading block bodies block_num=18968346 delivery/sec=4.3MB wasted/sec=1.0MB remaining=179226 delivered=784 cache=38.2MB alloc=6.8GB sys=9.6GB
Feb 03 11:43:29 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:29.176] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8264289 blockNumber=19067938 blk/sec=15.4 mbps/sec=3.1864 peers=6 snapshots=0 reconnected=false
Feb 03 11:43:36 anon-r2 erigon[2250351]: [INFO] [02-03|11:43:36.481] [NewPayload] Handling new payload        height=19147610 hash=0x71d848a468e01731ab1e386231d22573b1ee792719463ad631854a198dd74fae

Hi, You are running internalcl while forcing the connection to an externalcl, please turn off the external consensus layer

External consensus is offline. Unfortunately, saw another error when attempting to insert blocks.

Feb 07 07:03:16 anon-r2 erigon[2658140]: [INFO] [02-07|07:03:16.088] [txpool] stat                            pending=0 baseFee=0 queued=30000 alloc=4.8GB sys=9.8GB
Feb 07 07:03:43 anon-r2 erigon[2658140]: [INFO] [02-07|07:03:43.135] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8170393 blockNumber=18974813 blk/sec=8.5 mbps/sec=2.0696 peers=1 snapshots=0 reconnected=false
Feb 07 07:04:02 anon-r2 erigon[2658140]: [INFO] [02-07|07:04:02.120] P2P                                      app=caplin peers=3
Feb 07 07:04:13 anon-r2 erigon[2658140]: [INFO] [02-07|07:04:13.135] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8170233 blockNumber=18974654 blk/sec=5.3 mbps/sec=1.2442 peers=0 snapshots=0 reconnected=false
Feb 07 07:04:43 anon-r2 erigon[2658140]: [INFO] [02-07|07:04:43.135] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8169721 blockNumber=18974144 blk/sec=17.1 mbps/sec=2.8601 peers=2 snapshots=0 reconnected=false
Feb 07 07:05:02 anon-r2 erigon[2658140]: [INFO] [02-07|07:05:02.120] P2P                                      app=caplin peers=2
Feb 07 07:05:13 anon-r2 erigon[2658140]: [INFO] [02-07|07:05:13.135] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8169337 blockNumber=18973767 blk/sec=12.8 mbps/sec=1.9928 peers=1 snapshots=0 reconnected=false
Feb 07 07:05:43 anon-r2 erigon[2658140]: [INFO] [02-07|07:05:43.135] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8168377 blockNumber=18972817 blk/sec=32.0 mbps/sec=5.8099 peers=4 snapshots=0 reconnected=false
Feb 07 07:06:02 anon-r2 erigon[2658140]: [INFO] [02-07|07:06:02.120] P2P                                      app=caplin peers=2
Feb 07 07:06:12 anon-r2 erigon[2658140]: [INFO] [02-07|07:06:12.799] [p2p] GoodPeers                          eth68=33 eth67=33
Feb 07 07:06:13 anon-r2 erigon[2658140]: [INFO] [02-07|07:06:13.135] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8168217 blockNumber=18972657 blk/sec=5.3 mbps/sec=0.8737 peers=2 snapshots=0 reconnected=false
Feb 07 07:06:16 anon-r2 erigon[2658140]: [INFO] [02-07|07:06:16.087] [txpool] stat                            pending=0 baseFee=0 queued=30000 alloc=5.4GB sys=9.8GB
Feb 07 07:06:43 anon-r2 erigon[2658140]: [INFO] [02-07|07:06:43.136] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8167466 blockNumber=18971909 blk/sec=25.0 mbps/sec=4.8855 peers=6 snapshots=0 reconnected=false
Feb 07 07:07:02 anon-r2 erigon[2658140]: [INFO] [02-07|07:07:02.120] P2P                                      app=caplin peers=1
Feb 07 07:07:13 anon-r2 erigon[2658140]: [INFO] [02-07|07:07:13.135] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8166709 blockNumber=18971160 blk/sec=25.2 mbps/sec=4.6081 peers=1 snapshots=0 reconnected=false
Feb 07 07:07:43 anon-r2 erigon[2658140]: [INFO] [02-07|07:07:43.135] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8165625 blockNumber=18970088 blk/sec=36.1 mbps/sec=7.1318 peers=3 snapshots=0 reconnected=false
Feb 07 07:08:02 anon-r2 erigon[2658140]: [INFO] [02-07|07:08:02.120] P2P                                      app=caplin peers=7
Feb 07 07:08:13 anon-r2 erigon[2658140]: [INFO] [02-07|07:08:13.135] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8164697 blockNumber=18969166 blk/sec=30.9 mbps/sec=6.6207 peers=5 snapshots=0 reconnected=false
Feb 07 07:08:43 anon-r2 erigon[2658140]: [INFO] [02-07|07:08:43.135] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8163898 blockNumber=18968376 blk/sec=26.6 mbps/sec=5.8291 peers=8 snapshots=0 reconnected=false
Feb 07 07:09:02 anon-r2 erigon[2658140]: [INFO] [02-07|07:09:02.120] P2P                                      app=caplin peers=4
Feb 07 07:09:05 anon-r2 erigon[2658140]: [INFO] [02-07|07:09:05.043] Backfilling finished
Feb 07 07:09:08 anon-r2 erigon[2658140]: [INFO] [02-07|07:09:08.946] Ready to insert history, waiting for sync cycle to finish app=caplin stage=DownloadHistoricalBlocks
Feb 07 07:09:12 anon-r2 erigon[2658140]: [WARN] [02-07|07:09:12.580] error executing clstage                  app=caplin stage=DownloadHistoricalBlocks err="loadIntoTable Header: error inserting block during collection: ethereumExecutionModule.InsertBlocks: writeBody: Wr>
Feb 07 07:09:12 anon-r2 erigon[2658140]: [INFO] [02-07|07:09:12.580] Starting downloading History             app=caplin stage=DownloadHistoricalBlocks from=8369504
Feb 07 07:09:12 anon-r2 erigon[2658140]: [INFO] [02-07|07:09:12.799] [p2p] GoodPeers                          eth68=33 eth67=33
Feb 07 07:09:16 anon-r2 erigon[2658140]: [INFO] [02-07|07:09:16.087] [txpool] stat                            pending=0 baseFee=0 queued=30000 alloc=5.2GB sys=9.8GB
Feb 07 07:09:42 anon-r2 erigon[2658140]: [INFO] [02-07|07:09:42.580] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8368289 blockNumber=19170926 blk/sec=40.5 mbps/sec=6.5715 peers=1 snapshots=0 reconnected=false
Feb 07 07:10:02 anon-r2 erigon[2658140]: [INFO] [02-07|07:10:02.120] P2P                                      app=caplin peers=5
Feb 07 07:10:12 anon-r2 erigon[2658140]: [INFO] [02-07|07:10:12.580] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8367385 blockNumber=19170028 blk/sec=30.1 mbps/sec=4.7982 peers=6 snapshots=0 reconnected=false
Feb 07 07:10:42 anon-r2 erigon[2658140]: [INFO] [02-07|07:10:42.580] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8366935 blockNumber=19169585 blk/sec=15.0 mbps/sec=2.6324 peers=5 snapshots=0 reconnected=false
Feb 07 07:11:02 anon-r2 erigon[2658140]: [INFO] [02-07|07:11:02.120] P2P                                      app=caplin peers=5
Feb 07 07:11:12 anon-r2 erigon[2658140]: [INFO] [02-07|07:11:12.580] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8366366 blockNumber=19169032 blk/sec=19.0 mbps/sec=3.3211 peers=7 snapshots=0 reconnected=false
Feb 07 07:11:42 anon-r2 erigon[2658140]: [INFO] [02-07|07:11:42.580] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8365870 blockNumber=19168540 blk/sec=16.5 mbps/sec=2.8865 peers=10 snapshots=0 reconnected=false
Feb 07 07:12:02 anon-r2 erigon[2658140]: [INFO] [02-07|07:12:02.120] P2P                                      app=caplin peers=11
Feb 07 07:12:12 anon-r2 erigon[2658140]: [INFO] [02-07|07:12:12.580] Downloading History                      app=caplin stage=DownloadHistoricalBlocks slot=8365379 blockNumber=19168052 blk/sec=16.4 mbps/sec=2.7750 peers=13 snapshots=0 reconnected=false
Feb 07 07:12:12 anon-r2 erigon[2658140]: [INFO] [02-07|07:12:12.799] [p2p] GoodPeers                          eth68=33 eth67=32
Feb 07 07:12:16 anon-r2 erigon[2658140]: [INFO] [02-07|07:12:16.088] [txpool] stat                            pending=0 baseFee=0 queued=30000 alloc=6.8GB sys=9.8GB

Service

# cat /etc/systemd/system/erigon.service
[Unit]
Description=Erigon Client - Mainnet full
After=network.target
Wants=network.target
[Service]
User=erigon
Group=erigon
Type=simple
Restart=always
RestartSec=45
ExecStart=/usr/local/bin/erigon \
        --chain="mainnet" \
        --datadir="/storage/ethereum/erigon/data" \
        --snapshots="true" \
        --internalcl \
        --authrpc.jwtsecret="/var/ethereum/jwtsecret" \
        --torrent.download.rate="150mb" --torrent.upload.rate="15mb" \
        --http="true" --http.api="web3,net,eth" --http.addr="192.168.2.3" --http.vhosts="*" \
        --ws="true" \
        --ws.compression="false" \
#        --ws.api="web3,net,eth" \
#        --ws.addr="192.168.2.3" \
        --graphql="true" \
        --private.api.addr="192.168.2.3:9191" \
        --authrpc.addr="127.0.0.1" --authrpc.port="8551" --authrpc.vhosts="127.0.0.1"
[Install]
WantedBy=default.target
ehsanhajian commented 6 months ago

After resyncing from scratch my node got stuck at 18999999

erigon -v
erigon version 2.58.1

Erigon config

ExecStart=/usr/local/bin/erigon --datadir=/disk2/erigon --prune=hrtc  --metrics --metrics.addr 0.0.0.0 --http --ws  --nat extip:x.x.x.x --torrent.download.rate 1000mb --torrent.upload.rate 50mb --internalcl

Erigon log

Feb 27 09:49:17 erg-01-do erigon[441699]: [INFO] [02-27|09:49:17.739] Opening Database                         label=chaindata path=/disk2/erigon/chaindata
Feb 27 09:49:17 erg-01-do erigon[441699]: mdbx_setup_dxb:15946 filesize mismatch (expect 902060572672b/110114816p, have 1004854575104b/122662912p)
AskAlexSharov commented 6 months ago

@ehsanhajian --internalcl

ehsanhajian commented 6 months ago

@AskAlexSharov yes. I Already added --internalcl. Should I remove it?

AskAlexSharov commented 6 months ago

then you are good

ehsanhajian commented 6 months ago

@AskAlexSharov, sorry for asking again. It's been stuck at 18999999 for three days. So, is it normal? Do I need to wait for it to get synced?

AskAlexSharov commented 6 months ago

i don't know anything about your node: show logs

ehsanhajian commented 6 months ago

@AskAlexSharov In logs everything looks good

Feb 28 09:46:14 erg-01-do erigon[441699]: [INFO] [02-28|09:46:14.250] Write to db                              progress=4.2M/4.2M current table=Code
Feb 28 09:46:32 erg-01-do erigon[441699]: [INFO] [02-28|09:46:32.513] [p2p] GoodPeers                          eth67=94 eth66=6 eth68=100
Feb 28 09:46:44 erg-01-do erigon[441699]: [INFO] [02-28|09:46:44.435] Write to db                              progress=4.2M/4.2M current table=IncarnationMap
Feb 28 09:46:45 erg-01-do erigon[441699]: [INFO] [02-28|09:46:45.671] [4/12 Execution] Executed blocks         number=19284364 blk/s=0.0 tx/s=0.2 Mgas/s=0.0 gasState=0.00 batch=0B alloc=7.2GB sys=15.7GB
Feb 28 09:46:49 erg-01-do erigon[441699]: [INFO] [02-28|09:46:49.442] P2P                                      app=caplin peers=39
Feb 28 09:46:58 erg-01-do erigon[441699]: [INFO] [02-28|09:46:58.806] [txpool] stat                            pending=0 baseFee=0 queued=30000 alloc=7.6GB sys=15.7GB
Feb 28 09:47:04 erg-01-do erigon[441699]: [INFO] [02-28|09:47:04.260] [4/12 Execution] Executed blocks         number=19284408 blk/s=2.4 tx/s=315.4 Mgas/s=35.1 gasState=0.00 batch=1.3MB alloc=7.8GB sys=15.7GB
Feb 28 09:47:34 erg-01-do erigon[441699]: [INFO] [02-28|09:47:34.386] [4/12 Execution] Executed blocks         number=19284506 blk/s=3.3 tx/s=482.0 Mgas/s=48.3 gasState=0.00 batch=3.6MB alloc=8.9GB sys=15.7GB
Feb 28 09:47:49 erg-01-do erigon[441699]: [INFO] [02-28|09:47:49.441] P2P                                      app=caplin peers=39
Feb 28 09:48:04 erg-01-do erigon[441699]: [INFO] [02-28|09:48:04.383] [4/12 Execution] Executed blocks         number=19284613 blk/s=3.6 tx/s=573.3 Mgas/s=53.5 gasState=0.01 batch=5.8MB alloc=6.8GB sys=15.7GB
Feb 28 09:48:34 erg-01-do erigon[441699]: [INFO] [02-28|09:48:34.315] [4/12 Execution] Executed blocks         number=19284738 blk/s=4.2 tx/s=643.3 Mgas/s=63.2 gasState=0.01 batch=8.3MB alloc=8.1GB sys=15.7GB
Feb 28 09:48:49 erg-01-do erigon[441699]: [INFO] [02-28|09:48:49.441] P2P                                      app=caplin peers=42
Feb 28 09:49:04 erg-01-do erigon[441699]: [INFO] [02-28|09:49:04.261] [4/12 Execution] Executed blocks         number=19284867 blk/s=4.3 tx/s=652.7 Mgas/s=65.3 gasState=0.01 batch=10.9MB alloc=9.4GB sys=15.7GB
Feb 28 09:49:32 erg-01-do erigon[441699]: [INFO] [02-28|09:49:32.513] [p2p] GoodPeers                          eth68=100 eth67=94 eth66=6
Feb 28 09:49:34 erg-01-do erigon[441699]: [INFO] [02-28|09:49:34.309] [4/12 Execution] Executed blocks         number=19285002 blk/s=4.5 tx/s=699.2 Mgas/s=67.6 gasState=0.02 batch=13.2MB alloc=6.1GB sys=15.7GB
Feb 28 09:49:49 erg-01-do erigon[441699]: [INFO] [02-28|09:49:49.441] P2P                                      app=caplin peers=42
Feb 28 09:49:58 erg-01-do erigon[441699]: [INFO] [02-28|09:49:58.808] [txpool] stat                            pending=0 baseFee=0 queued=30000 alloc=7.2GB sys=15.7GB
Feb 28 09:50:04 erg-01-do erigon[441699]: [INFO] [02-28|09:50:04.268] [4/12 E

The only thing is when I restart erigon I see filesize mismatch in logs.

 Feb 27 09:49:17 erg-01-do erigon[441699]: [INFO] [02-27|09:49:17.739] Opening Database                         label=chaindata path=/disk2/erigon/chaindata
Feb 27 09:49:17 erg-01-do erigon[441699]: mdbx_setup_dxb:15946 filesize mismatch (expect 902060572672b/110114816p, have 1004854575104b/122662912p)
ehsanhajian commented 6 months ago

Update: after 4 days stuck at 18999999 it paased the block and got fully synced.

AskAlexSharov commented 6 months ago

it's not "stuck" - it's how erigon works: https://github.com/ledgerwatch/erigon/blob/devel/eth/stagedsync/README.md and it's how "database transactions work" - if something is not committed yet, then other readers can't see it. So, just see progress in logs/metrics/eth_syncing.

fridary commented 5 months ago

@AskAlexSharov is it correct that does not matter whatever pruning I set, it will syncing the same days? I am also stopped on 18999999 and waiting. My prune config (it's already syncing 9 days, NVMe drive) is: --prune.h.before=13916166 --prune.r.before=13916166 --prune.t.before=13916166 --prune.c.before=13916166 where block 13916166 is Jan-01-2022 12:00:03 AM +UTC. So I wanted to get all data only last 2 years and 3 months. It has been already took 1.7 Tb.

AskAlexSharov commented 5 months ago

is it correct that does not matter whatever pruning I set, it will syncing the same days? - yes. Erigon2 doesn't have "snap-sync" - it will execute all blocks from 0. Erigon3 will have "snap-sync".

AskAlexSharov commented 5 months ago

"stopped on 18999999" - probably you forgot --internalcl

fridary commented 5 months ago

@AskAlexSharov now it synced, took 12 days. Not to creating new topics, can you please clarify how much disk space costs full archive ethereum mainnet on April 2024? On github page: For an Archive node of Ethereum Mainnet we recommend >=3.5TB storage space: 2.3TiB state (as of March 2024) My disk space is used for 2.1Tb and I pruned all available flags from block 13916166 (Jan-01-2022 12:00:03 AM +UTC). So only 2 years and 2 months are 2.1Tb? That means that 3.5-2.1=1.4 Tb will cost 2022-2014=8 years? Config: /home/root/erigon/build/bin/erigon --internalcl --datadir=/disk_sde/erigon --http.api=eth,erigon,engine,web3,net,debug,trace,txpool --authrpc.jwtsecret=/home/root/erigon/jwtsecret --metrics --prune.h.before=13916166 --prune.r.before=13916166 --prune.t.before=13916166 --prune.c.before=13916166 --torrent.download.rate=128mb

$ df -Th
Filesystem     Type      Size  Used Avail Use% Mounted on
/dev/nvme0n1   ext4      5,8T  2,1T  3,5T  37% /disk_sde
AskAlexSharov commented 5 months ago

we recently released more aggressive pruning - see https://github.com/ledgerwatch/erigon/releases/tag/v2.59.0

show "integration print_stages"

fridary commented 5 months ago

@AskAlexSharov yes, I have exactly this version:

$ /home/root/erigon/build/bin/erigon --version
erigon version 2.59.3-088fd8ef
$ /home/root/erigon/build/bin/integration --datadir=/disk_sde/erigon --chain=mainnet print_stages
INFO[04-12|14:57:45.464] logging to file system                   log dir=/disk_sde/erigon/logs file prefix=integration log level=info json=false
INFO[04-12|14:57:45.466] [db] open                                lable=chaindata sizeLimit=12TB pageSize=8192
INFO[04-12|14:57:49.876] [snapshots:all] Blocks Stat              blocks=19549k indices=19549k alloc=2.8GB sys=2.9GB
INFO[04-12|14:57:49.884] [snapshots:all] Blocks Stat              blocks=0k indices=0k alloc=2.8GB sys=2.9GB
Note: prune_at doesn't mean 'all data before were deleted' - it just mean stage.Prune function were run to this block. Because 1 stage may prune multiple data types to different prune distance.

                 stage_at    prune_at
Snapshots            19639374    0
Headers              19639375    0
BorHeimdall              0       0
BlockHashes              19639375    0
Bodies               19639375    0
Senders              19639375    0
Execution            19639375    19639375
Translation              0       0
HashState            19639375    0
IntermediateHashes       19639375    19639375
AccountHistoryIndex          19639375    19639375
StorageHistoryIndex          19639375    19639375
LogIndex             19639375    19639375
CallTraces           19639375    19639375
TxLookup             19639375    18999999
Finish               19639375    0
--
prune distance: --prune.h.before=13916166 --prune.r.before=13916166 --prune.t.before=13916166 --prune.c.before=13916166

blocks.v2: true, blocks=19548999, segments=19548999, indices=19548999
blocks.bor.v2: segments=0, indices=0

history.v3: false,  idx steps: 0.00, lastBlockInSnap=0, TxNums_Index(0,1)

sequence: EthTx=2370691987, NonCanonicalTx=0

in db: first header 19549000, last header 19639375, first body 19549000, last body 19639375
--
fridary commented 4 months ago

@AskAlexSharov so, aggressive pruning does not work as expected? Or I did wrong steps when installing? As I wrote above, I set pruning before 1 Jan 2022. So only 2 years and 4 months took 2.1Tb