go-ethereum icon indicating copy to clipboard operation
go-ethereum copied to clipboard
verified publisher icon ethereum

Why is block synchronization too slow since The Merge?

Open mone-d opened this issue 3 years ago • 10 comments

Hi.

I set up geth in the ropsten network today. However, since The Merge the block sync has been very slow. I am having trouble connecting to Prysm until the sync is complete. (thrown error chain not synced beyond EIP-155 replay-protection fork block) Can someone please help me?

The synced in the log only increase about 1(%/hours).

Logs

INFO [06-09\|13:40:03.191] State sync in progress                   synced=63.82% state=43.22GiB  accounts=180,703,[email protected]  slots=140,921,[email protected] codes=1,588,[email protected]  eta=5h55m25.246s
--
WARN [06-09\|13:40:03.425] Unexpected storage ranges packet         peer=74d6bf99 reqid=751,920,643,234,831,158
INFO [06-09\|13:40:08.336] Disabling direct-ancient mode            origin=12,350,644 ancient=11,370,495
INFO [06-09\|13:40:09.164] Imported new block headers               count=0    elapsed=25.993ms  number=12,350,712 hash=d3a581..1b1f0c age=21h31m51s  ignored=68
INFO [06-09\|13:40:09.164] Legacy sync reached merge threshold      number=12,350,713 hash=4e8451..5809f6 td=50,001,647,293,494,169 ttd=50,000,000,000,000,000
INFO [06-09\|13:40:09.431] State sync in progress                   synced=63.82% state=43.22GiB  accounts=180,711,[email protected]  slots=140,921,[email protected] codes=1,588,[email protected]  eta=5h55m19.006s
WARN [06-09\|13:40:09.431] Local chain is post-merge, waiting for beacon client sync switch-over...
WARN [06-09\|13:40:09.445] Unexpected storage ranges packet         peer=139fa632 reqid=8,341,754,189,849,960,006
WARN [06-09\|13:40:09.471] Unexpected storage ranges packet         peer=7f028ebd reqid=6,525,341,925,455,961,726
WARN [06-09\|13:40:09.505] Unexpected storage ranges packet         peer=690cd285 reqid=7,552,573,475,475,694,766
WARN [06-09\|13:40:09.604] Unexpected bytecode packet               peer=89e423c2 reqid=7,717,371,443,965,220,234
WARN [06-09\|13:40:09.680] Unexpected bytecode packet               peer=139fa632 reqid=6,387,226,010,901,989,452
WARN [06-09\|13:40:09.776] Unexpected storage ranges packet         peer=020d56d0 reqid=5,598,532,868,875,383,147
WARN [06-09\|13:40:09.928] Unexpected storage ranges packet         peer=3c15c082 reqid=6,829,926,272,469,738,836
WARN [06-09\|13:40:09.940] Unexpected storage ranges packet         peer=6bf4950c reqid=6,322,430,112,030,367,198
INFO [06-09\|13:40:10.139] Disabling direct-ancient mode            origin=12,350,644 ancient=11,370,495
INFO [06-09\|13:40:10.715] Imported new block headers               count=0    elapsed=7.572ms   number=12,350,712 hash=d3a581..1b1f0c age=21h31m52s  ignored=68
INFO [06-09\|13:40:10.716] Legacy sync reached merge threshold      number=12,350,713 hash=4e8451..5809f6 td=50,001,647,293,494,169 ttd=50,000,000,000,000,000
INFO [06-09\|13:40:10.729] State sync in progress                   synced=63.82% state=43.22GiB  accounts=180,728,[email protected]  slots=140,921,[email protected] codes=1,588,[email protected]  eta=5h55m17.708s
WARN [06-09\|13:40:10.733] Unexpected storage ranges packet         peer=c7a1f268 reqid=1,428,977,203,650,163,118
WARN [06-09\|13:40:10.765] Unexpected storage ranges packet         peer=020d56d0 reqid=5,183,934,805,055,301,607
WARN [06-09\|13:40:10.784] Unexpected storage ranges packet         peer=6bf4950c reqid=7,863,450,888,859,115,793
WARN [06-09\|13:40:10.839] Unexpected account range packet          peer=95776194 reqid=3,182,830,736,341,631,612
WARN [06-09\|13:40:10.882] Unexpected storage ranges packet         peer=80ebb6c5 reqid=4,301,557,464,865,831,026
WARN [06-09\|13:40:10.898] Unexpected storage ranges packet         peer=ec2dbd80 reqid=8,976,612,203,248,359,907
WARN [06-09\|13:40:10.899] Unexpected bytecode packet               peer=89e423c2 reqid=4,369,980,328,153,340,208
WARN [06-09\|13:40:10.920] Unexpected storage ranges packet         peer=139fa632 reqid=7,730,018,495,098,011,298
WARN [06-09\|13:40:10.934] Unexpected storage ranges packet         peer=aec9b010 reqid=4,319,047,538,334,092,498
WARN [06-09\|13:40:10.959] Unexpected storage ranges packet         peer=74d6bf99 reqid=2,300,836,965,669,043,203
WARN [06-09\|13:40:10.959] Unexpected bytecode packet               peer=b0445182 reqid=7,750,143,651,971,368,596
WARN [06-09\|13:40:10.992] Unexpected account range packet          peer=cedad5c1 reqid=4,555,338,015,580,145,645
WARN [06-09\|13:40:11.000] Unexpected storage ranges packet         peer=43ceb5c9 reqid=4,319,548,347,599,431,808
WARN [06-09|13:40:11.813] Served eth_chainId                       reqid=1                         duration="36.653µs" err="chain not synced beyond EIP-155 replay-protection fork block"

Startup command /usr/local/bin/geth --config /home/app/.ethereum/config/config.toml --cache 1024 --snapshot=false

Configuration File

[Eth]
    NetworkId = 3
    SyncMode = "snap"
    NoPruning = false
    LightPeers = 100
    DatabaseCache = 768
    TrieCleanCache = 256
    TrieDirtyCache = 256
    TrieTimeout = 3600000000000
    EnablePreimageRecording = false
[Eth.Miner]
    GasFloor = 8000000
    GasCeil = 8000000
    GasPrice = 1000000000
    Recommit = 3000000000
    Noverify = false
[Eth.Ethash]
    CacheDir = "ethash"
    DatasetDir = "/home/app/.ethash"
    CachesInMem = 2
    CachesOnDisk = 3
    DatasetsInMem = 1
    DatasetsOnDisk = 2
    PowMode = 0
[Eth.TxPool]
    Locals = []
    NoLocals = false
    Journal = "transactions.rlp"
    Rejournal = 3600000000000
    PriceLimit = 1
    PriceBump = 10
    AccountSlots = 16
    GlobalSlots = 4096
    AccountQueue = 64
    GlobalQueue = 1024
    Lifetime = 10800000000000
[Eth.GPO]
    Blocks = 20
    Percentile = 60
[Node]
    DataDir             = "/home/app/.ethereum/testnet"
    IPCPath             = "geth.ipc"
    HTTPHost            = "0.0.0.0"
    HTTPPort            = 8545
    HTTPCors            = ["*"]
    HTTPVirtualHosts    = ["*"]
    HTTPModules         = ["admin", "eth", "debug", "miner", "net", "txpool", "personal", "web3"]
    WSHost              = "0.0.0.0"
    WSPort              = 8546
    WSOrigins           = ["*"]
    WSModules           = ["admin", "eth", "debug", "miner", "net", "txpool", "personal", "web3"]
[Node.P2P]
    MaxPeers            = 100
    NoDiscovery         = false
    ListenAddr          = ":30303"
    EnableMsgEvents     = false
[Node.HTTPTimeouts]
    ReadTimeout = 30000000000
    WriteTimeout = 30000000000
    IdleTimeout = 120000000000

mone-d avatar Jun 09 '22 13:06 mone-d

My guess is that there are probably a lot of Ropsten nodes that have not merged, so all of a sudden it's a lot less peers to serve. The network partitioning code wasn't enabled, so there's no split atm. Will look into some way to help a bit.

karalabe avatar Jun 09 '22 14:06 karalabe

Any updates on this?

safwentrabelsi avatar Jun 14 '22 06:06 safwentrabelsi

You should setup consensys client for ropsten, for example prysm (https://geth.ethereum.org/docs/interface/merge) Add to geth startup command:

--authrpc.addr localhost --authrpc.port 8551 --authrpc.vhosts localhost --authrpc.jwtsecret /tmp/jwtsecret \
--override.terminaltotaldifficulty 50000000000000000

Prysm startup command:

beacon-chain-v2.1.3-rc.3-modern-linux-amd64 --ropsten --accept-terms-of-use \
    --datadir='./prysm_data' \
    --http-web3provider='http://localhost:8551' \
    --genesis-state=genesis.ssz --jwt-secret='/tmp/jwtsecret' \
    --terminal-total-difficulty-override=50000000000000000

genesis-state: https://github.com/eth-clients/merge-testnets/blob/main/ropsten-beacon-chain/genesis.ssz prysm builded for ropsten: https://github.com/prysmaticlabs/prysm/releases/download/v2.1.3-rc.3/beacon-chain-v2.1.3-rc.3-modern-linux-amd64

amidmast avatar Jun 14 '22 13:06 amidmast

I still get "Legacy sync reached merge threshold number=12,350,713" even if I started a prysm beacon. I tried also teku and it reports "ETH1 is invalid or synching"

sconstro avatar Jun 20 '22 08:06 sconstro

I still get "Legacy sync reached merge threshold number=12,350,713" even if I started a prysm beacon. I tried also teku and it reports "ETH1 is invalid or synching"

What in the prysm and eth logs?

amidmast avatar Jun 20 '22 10:06 amidmast

Good news! After some time, Prysm logs are showing: INFO initial-sync: Processing block batch of size 62 starting from 0x7a8c3a92... 99840/149837 - estimated time remaining 1h6m8s blocksPerSecond=12.6 peers=34 And Geth logs start to show: Imported new potential chain segment blocks=1 txs=13 mgas=0.886 elapsed=8.521ms mgasps=103.942 number=12,386,196 hash=91b93f..cde4e4 age=6d18h6s dirty=1023.75MiB

sconstro avatar Jun 20 '22 10:06 sconstro

The prysm beacon node is stuck at block slot 65504 after POS activation:

time="2022-06-20 13:20:38" level=warning msg="Batch is not processed" error="could not process block in batch: block 0xd99d8bd1860c is not a descendant of the current finalized block slot 65504, 0xd99d8bd1860c != 0x20a766bf94d6" prefix=initial-sync
time="2022-06-20 13:20:38" level=info msg="Processing block batch of size 58 starting from  0x6bfc01f7... 65344/150703 - estimated time remaining 24m54s" blocksPerSecond=57.1 peers=24 prefix=initial-sync
time="2022-06-20 13:20:38" level=warning msg="Batch is not processed" error="could not process block in batch: block 0x83ac86c72af2 is not a descendant of the current finalized block slot 65504, 0x83ac86c72af2 != 0x20a766bf94d6" prefix=initial-sync
time="2022-06-20 13:20:38" level=info msg="Processing block batch of size 62 starting from  0x6bc69414... 65408/150703 - estimated time remaining 23m36s" blocksPerSecond=60.2 peers=24 prefix=initial-sync
time="2022-06-20 13:20:38" level=warning msg="Batch is not processed" error="could not process block in batch: block 0xc374da4e7502 is not a descendant of the current finalized block slot 65504, 0xc374da4e7502 != 0x20a766bf94d6" prefix=initial-sync
time="2022-06-20 13:20:38" level=info msg="Processing block batch of size 63 starting from  0x19d6d017... 65472/150703 - estimated time remaining 22m25s" blocksPerSecond=63.4 peers=24 prefix=initial-sync
time="2022-06-20 13:20:38" level=warning msg="Batch is not processed" error="could not process block in batch: block 0xedacd6625316 is not a descendant of the current finalized block slot 65504, 0xedacd6625316 != 0x20a766bf94d6" prefix=initial-sync
time="2022-06-20 13:20:38" level=info msg="Processing block batch of size 61 starting from  0x8f1a6d3e... 65536/150703 - estimated time remaining 21m22s" blocksPerSecond=66.4 peers=24 prefix=initial-sync

safwentrabelsi avatar Jun 20 '22 13:06 safwentrabelsi

I use this startup command: GETH /usr/bin/geth --nousb --ropsten --ws --datadir=/data/.ethereum --ws.port=8332 --ws.addr="0.0.0.0" --ws.api eth,web3,net,debug,admin --ws.origins="*" --http --http.port=8545 --http.addr="0.0.0.0" --snapshot="false" --txlookuplimit=0 --cache.preimages --rpc.allow-unprotected-txs --authrpc.addr localhost --authrpc.port 8551 --authrpc.vhosts localhost --authrpc.jwtsecret=/data/jwtsecret --override.terminaltotaldifficulty 50000000000000000

Prysm /usr/local/bin/beacon-chain --ropsten --datadir=/data/.prysm/beaconchain --http-web3provider=http://localhost:8551 --terminal-total-difficulty-override 50000000000000000 --genesis-state=/data/.prysm/genesis/genesis.ssz --chain-config-file=/data/.prysm/config/config.yaml --jwt-secret=/data/jwtsecret --accept-terms-of-use

However, both clients return "chain not synced beyond EIP-155 replay-protection fork block" Geth: geth[508795]: WARN [06-23|03:05:23.714] Local chain is post-merge, waiting for beacon client sync switch-over... geth[508795]: WARN [06-23|02:46:25.684] Served eth_chainId conn=127.0.0.1:45248 reqid=1 duration="40.852µs" err="chain not synced beyond EIP-155 replay-protection fork block"

Prysm: beacon-chain[508902]: time="2022-06-23 02:52:10" level=error msg="Could not connect to execution client endpoint: could not make initial request to verify execution chain ID: chain not syncedbeyond EIP-155 replay-protection fork block" prefix=powchain beacon-chain[508902]: time="2022-06-23 02:52:10" level=info msg="Peer summary" activePeers=0 inbound=0 outbound=0 prefix=p2p beacon-chain[508902]: time="2022-06-23 02:52:10" level=info msg="Waiting for enough suitable peers before syncing" prefix=initial-sync required=3 suitable=0

kkhoac avatar Jun 23 '22 02:06 kkhoac

I used this command to pick the right post merge peers:

- '--eth.requiredblocks'
            - 12308104=0x2a45451c8c2bfd4a110fd5865289f214cf29917706233864671f18b4b9bdeeab,12404042=0x48857952e9392048e2b8e1ffaf84b26859914348e7981acd735565c00b8e4179,12361752=0x27c093bdabb1530095d6ce23d9f2ed1f280fc6fb3d15baeb5e25ecc456af7ad1,12082227=0x33025036e9b0a1f901f2821bf231dc6e2df22e0921b42fb3b04dde3d560d8d00,12350712=0x5010949c3acdf1d076c9e4ee8aedbb539aca48ebe19638330bc02c5b1bfb953d

safwentrabelsi avatar Jun 23 '22 07:06 safwentrabelsi

Have you managed to get this fixed? My syncing is slow too, i don't seem to have the same problem as you but i am unable to get the latestblock from my node. It's rather annoying, it always returns 0

FahdW avatar Nov 18 '22 00:11 FahdW

Have you managed to get this fixed? My syncing is slow too, i don't seem to have the same problem as you but i am unable to get the latestblock from my node. It's rather annoying, it always returns 0

it's ridiculous, getting longer and longer to sync.

defeedme avatar Nov 24 '22 17:11 defeedme

Closing this issue because it is not about a specific bug in go-ethereum, Sync is slow, we know it, and we are all unhappy about it.

fjl avatar Dec 08 '22 09:12 fjl