search

bnb-chain / bsc

A BNB Smart Chain client based on the go-ethereum fork
GNU Lesser General Public License v3.0
2.68k stars 1.54k forks source link

Fullnode stuck in sync state #1978

Closed morzhanov closed 9 months ago

morzhanov commented 10 months ago

System information

Geth version: 1.2.12 OS & Version: Amazon Linux release 2 (Karoo) / x86_64 arch OS Resources: 8cpu / 20gb / 25gbit Storage: 3.5T EBS volume (GP3 16000 iops) Environment: AWS EKS cluster

Expected behaviour

Fullnode state is successfully synced after 1 week when blocks are synced.

eth_syncing endpoint returns:

{
    "jsonrpc": "2.0",
    "id": 1,
    "result": false
}

Actual behaviour

The full node is not synced after 1 week of the sync process. The latest block is successfully updated but the node cannot exit from the sync phase. Main issue is that we cannot use websocket subscription endpoints as those require node to be fully synced.

eth_syncing endpoint returns:

{
    "jsonrpc": "2.0",
    "id": 1,
    "result": {
        "currentBlock": "0x1fcd10b",
        "healedBytecodeBytes": "0xe9b5eb7",
        "healedBytecodes": "0x6f31",
        "healedTrienodeBytes": "0x32e640d091",
        "healedTrienodes": "0x2b7b1556",
        "healingBytecode": "0x0",
        "healingTrienodes": "0x454",
        "highestBlock": "0x1fcd165",
        "startingBlock": "0x1fcbb2f",
        "syncedAccountBytes": "0xe51757115",
        "syncedAccounts": "0x10fe8e32",
        "syncedBytecodeBytes": "0x4d796afbe",
        "syncedBytecodes": "0x251458",
        "syncedStorage": "0xcf0fd89e",
        "syncedStorageBytes": "0xad8db11043"
    }
}

Steps to reproduce the behaviour

Run full node using the latest snapshot from https://github.com/bnb-chain/bsc-snapshots

genesis.json file location: https://api.github.com/repos/bnb-chain/bsc/releases/latest

config.toml file:

[Eth]
NetworkId = 56
LightPeers = 50
UltraLightFraction = 75
TrieTimeout = 150000000000

[Eth.Miner]
GasCeil = 140000000
GasPrice = 3000000000
Recommit = 10000000000

[Eth.TxPool]
Locals = []
NoLocals = true
Journal = "transactions.rlp"
Rejournal = 3600000000000
PriceLimit = 3000000000
PriceBump = 10
AccountSlots = 200
GlobalSlots = 8000
AccountQueue = 200
GlobalQueue = 4000

[Eth.GPO]
Blocks = 20
Percentile = 60
OracleThreshold = 1000

[Node]
IPCPath = "geth.ipc"
HTTPHost = "localhost"
InsecureUnlockAllowed = false
HTTPPort = 8545
HTTPVirtualHosts = ["localhost"]
HTTPModules = ["eth", "net", "web3", "txpool", "parlia"]
WSPort = 8546
WSModules = ["net", "web3", "eth"]

[Node.P2P]
MaxPeers = 100
NoDiscovery = false
StaticNodes = ["enode://87df685a762e3e25e8111d0a5957ecbe5756d34096703da5afa934f0e21de5ac9e60efd892aacd90aa4c792c7df0b1ebac0289a24d0cbcecfdee67305eee18a0@18.181.228.146:33311"]
BootstrapNodes = ["enode://433c8bfdf53a3e2268ccb1b829e47f629793291cbddf0c76ae626da802f90532251fc558e2e0d10d6725e759088439bf1cd4714716b03a259a35d4b2e4acfa7f@52.69.102.73:30311","enode://571bee8fb902a625942f10a770ccf727ae2ba1bab2a2b64e121594a99c9437317f6166a395670a00b7d93647eacafe598b6bbcef15b40b6d1a10243865a3e80f@35.73.84.120:30311","enode://fac42fb0ba082b7d1eebded216db42161163d42e4f52c9e47716946d64468a62da4ba0b1cac0df5e8bf1e5284861d757339751c33d51dfef318be5168803d0b5@18.203.152.54:30311","enode://3063d1c9e1b824cfbb7c7b6abafa34faec6bb4e7e06941d218d760acdd7963b274278c5c3e63914bd6d1b58504c59ec5522c56f883baceb8538674b92da48a96@34.250.32.100:30311","enode://ad78c64a4ade83692488aa42e4c94084516e555d3f340d9802c2bf106a3df8868bc46eae083d2de4018f40e8d9a9952c32a0943cd68855a9bc9fd07aac982a6d@34.204.214.24:30311","enode://5db798deb67df75d073f8e2953dad283148133acb520625ea804c9c4ad09a35f13592a762d8f89056248f3889f6dcc33490c145774ea4ff2966982294909b37a@107.20.191.97:30311"]
ListenAddr = ":30311"
EnableMsgEvents = false

#[Node.LogConfig]
#FilePath = "bsc.log"
#MaxBytesSize = 10485760
#Level = "info"
#FileRoot = ""

geth parameters:

  args:
    - '--config'
    - /node/bsc/config/config.toml
    - '--datadir'
    - /node/data
    - '--rpc.allow-unprotected-txs'
    - '--syncmode'
    - full
    - '--http'
    - '--http.api'
    - eth,txpool,net,web3,engine
    - '--http.vhosts'
    - '*'
    - '--graphql.vhosts'
    - '*'
    - '--http.corsdomain'
    - '*'
    - '--graphql'
    - '--ws'
    - '--ws.api'
    - web3,eth
    - '--rpc.evmtimeout'
    - 15s
    - '--ws.origins'
    - '*'
    - '--verbosity'
    - '5'
    - '--cache'
    - '16000'
    - '--txlookuplimit'
    - '0'
    - '--tries-verify-mode'
    - none
    - '--ipcdisable'

net_peerCount endpoint response:

{
    "jsonrpc": "2.0",
    "id": 1,
    "result": "0x47"
}
Chunk of node logs DEBUG[11-09|15:47:28.306] Persisted set of healing data type=trienodes bytes=33.58KiB TRACE[11-09|15:47:28.306] Fetching set of trie nodes peer=2e753bc8 reqid=6,591,669,147,356,816,575 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:28.402] Delivering set of healing trienodes peer=2e753bc8 reqid=6,591,669,147,356,816,575 trienodes=137 bytes=27.26KiB DEBUG[11-09|15:47:28.624] Persisted set of healing data type=trienodes bytes=29.71KiB TRACE[11-09|15:47:28.625] Fetching set of trie nodes peer=73f0313a reqid=1,100,057,035,030,134,389 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:28.633] Fetching full headers peer=e93f789d count=192 from=33,346,247 DEBUG[11-09|15:47:28.633] Fetching batch of headers id=e93f789d6a79c157 conn=dyndial count=192 fromnum=33,346,247 skip=0 reverse=false DEBUG[11-09|15:47:28.633] Recalculated msgrate QoS values proto=eth rtt=2s confidence=1.000 ttl=6s next=2023-11-09T15:47:30+0000 TRACE[11-09|15:47:28.633] Debug dump of mean capacities proto=eth caps="map[4:1341.580776158541 6:34.404474701038744 16:25.524947977666255]" TRACE[11-09|15:47:28.634] Scheduling new headers peer=e93f789d count=1 from=33,346,247 TRACE[11-09|15:47:28.634] Fetching full headers peer=e93f789d count=192 from=33,346,248 DEBUG[11-09|15:47:28.634] Fetching batch of headers id=e93f789d6a79c157 conn=dyndial count=192 fromnum=33,346,248 skip=0 reverse=false TRACE[11-09|15:47:28.635] All headers delayed, waiting peer=e93f789d INFO [11-09|15:47:28.637] Imported new block headers count=1 elapsed=3.180ms number=33,346,247 hash=66beaa..904e9a TRACE[11-09|15:47:28.637] Requesting new batch of receipts peer=2e753bc8 count=1 from=33,346,247 DEBUG[11-09|15:47:28.637] Fetching batch of receipts id=2e753bc8398aa451 conn=dyndial count=1 TRACE[11-09|15:47:28.638] Requesting new batch of bodies peer=e93f789d count=1 from=33,346,247 DEBUG[11-09|15:47:28.638] Fetching batch of block bodies id=e93f789d6a79c157 conn=dyndial count=1 TRACE[11-09|15:47:28.641] Delivered new batch of bodies peer=e93f789d count=1 accepted=1 TRACE[11-09|15:47:28.642] Delivered new batch of receipts peer=2e753bc8 count=1 accepted=1 TRACE[11-09|15:47:28.756] Delivering set of healing trienodes peer=73f0313a reqid=1,100,057,035,030,134,389 trienodes=141 bytes=36.73KiB DEBUG[11-09|15:47:28.886] Persisted set of healing data type=trienodes bytes=42.60KiB TRACE[11-09|15:47:28.886] Fetching set of trie nodes peer=82ed1450 reqid=8,614,644,942,323,186,820 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:28.929] Delivering set of healing trienodes peer=82ed1450 reqid=8,614,644,942,323,186,820 trienodes=138 bytes=31.04KiB DEBUG[11-09|15:47:29.150] Persisted set of healing data type=trienodes bytes=29.88KiB DEBUG[11-09|15:47:29.150] Updated trie node heal throttler rate=511.017 pending=827 throttle=1.000 TRACE[11-09|15:47:29.151] Fetching set of trie nodes peer=2b4afa01 reqid=360,651,606,719,197,818 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB DEBUG[11-09|15:47:29.151] Peer discarded announcement by distance peer=1db7fbf2a9eda081230bfa0aac466edc84a6547be759c50559de354787c85a6a number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.158] Peer discarded announcement by distance peer=e95fa0f62c8b1c3192c2335516729263fa7225c94f6a97074e52c6b2042bcecf number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.164] Peer discarded announcement by distance peer=f09744a5d630b727815525078c89246237d724745381aa9b40052bcdd63ff568 number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.187] Peer discarded announcement by distance peer=919e705de10a9ac4ec7870eb6037fd79362c879f61b486d6a3732380c26ec7a8 number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.190] Peer discarded announcement by distance peer=cf43792e96e46a793084f47c657ef287f22634c5e73cb6c04ebc6d1b305ab88a number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.237] Peer discarded announcement by distance peer=94f1f316c7aea29dd0bd3fefce6e3863e11bdfebcaff96bc0dd808e51a04ae17 number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.239] Peer discarded announcement by distance peer=b398012f04b48b843660d982d66237cd49b17f11ed5e825a3d9ec9ed159dfeef number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.244] Peer discarded announcement by distance peer=52bd007b441691b1820c8646dd3d053f03cce0a3f266fae4c98ec145a342e985 number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.254] Peer discarded announcement by distance peer=c4f3d0ff2f3b511470fa1995a0b0cf21edd8edaf17433834289f23bfc77fa51a number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 TRACE[11-09|15:47:29.254] Delivering set of healing trienodes peer=2b4afa01 reqid=360,651,606,719,197,818 trienodes=139 bytes=31.68KiB DEBUG[11-09|15:47:29.257] Peer discarded announcement by distance peer=c73a8be46fe54d49acdd1ccac0be37f188bfac6b3649751eeb634251502197fe number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.264] Peer discarded announcement by distance peer=82ed1450fee0eaafebd857fa397e9f2833c9ca7f9c2fecf85720225847dcadb5 number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.292] Peer discarded announcement by distance peer=2025f9246b21510d94a6e877d02d2f7d17ec7aa7a3697b9db571dfdd8417c00b number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.309] Peer discarded announcement by distance peer=2b4afa01dc8034e502e17786db30b6ab783db9f9ccb1a5e654abf3f68f3a10e8 number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.337] Peer discarded announcement by distance peer=10c1fae0b25ac54c851e46fb65d4c615d694edb20752fac0b01cec23426c865f number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.348] Peer discarded announcement by distance peer=1f3dafdc07212ff4d21de9c7cb8ad71922fc4b245d46565b4e1b169e40642a90 number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.353] Peer discarded announcement by distance peer=13edaeca09ce0d2dede2c4d63fb8215de29b0919a3bf7e820f5ca6b5e1bba213 number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.399] Peer discarded announcement by distance peer=b31b39d65990b97a2906fa5bf0da3571cd90cd41c9e0c506afa3e1bd5c7ecc32 number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.418] Peer discarded announcement by distance peer=85f414213ca8e09fb8ba068c1308904d0615fd8756bac0e275a010fdddcaecfb number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.425] Persisted set of healing data type=trienodes bytes=37.05KiB TRACE[11-09|15:47:29.426] Fetching set of trie nodes peer=52bd007b reqid=3,696,757,289,557,932,233 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:29.452] Delivering set of healing trienodes peer=52bd007b reqid=3,696,757,289,557,932,233 trienodes=135 bytes=24.98KiB DEBUG[11-09|15:47:29.486] Peer discarded announcement by distance peer=73f0313ac1420b1a5ba614919ef5d2c83b92a75f54f108404184a66de12f8af2 number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.501] Peer discarded announcement by distance peer=7058d2dcec9436a05db578a2589a201f963a6518e3bc337815b345a0084b6774 number=33,346,244 hash=d949e4..24386e distance=33,346,244 DEBUG[11-09|15:47:29.657] Persisted set of healing data type=trienodes bytes=35.77KiB DEBUG[11-09|15:47:29.657] Recalculated msgrate QoS values proto=snap rtt=2s confidence=1.000 ttl=6s next=2023-11-09T15:47:31+0000 TRACE[11-09|15:47:29.657] Debug dump of mean capacities proto=snap caps="map[5:51.13902036936107 7:497.800846178016]" TRACE[11-09|15:47:29.657] Fetching set of trie nodes peer=2025f924 reqid=4,970,885,386,494,792,360 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:29.740] Delivering set of healing trienodes peer=2025f924 reqid=4,970,885,386,494,792,360 trienodes=138 bytes=30.60KiB DEBUG[11-09|15:47:29.784] Peer discarded announcement by distance peer=fbca7bb1c8e97cb5d3b16a8169b3a8b668af5621718f19348f08b1d4564aada5 number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.814] Peer discarded announcement by distance peer=52f89ab89ba938e1e78fc5a09b90ef53818adc5b7db647639f30f3ad57a5e278 number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.814] Peer discarded announcement by distance peer=aae0ed11c47b653fa4b1d6bdf1790fd22aba8c30d9daa3e280eee75b37d13372 number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:29.890] Persisted set of healing data type=trienodes bytes=40.62KiB TRACE[11-09|15:47:29.890] Fetching set of trie nodes peer=e93f789d reqid=8,434,732,720,110,603,629 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:30.013] Delivering set of healing trienodes peer=e93f789d reqid=8,434,732,720,110,603,629 trienodes=139 bytes=34.13KiB DEBUG[11-09|15:47:30.136] Persisted set of healing data type=trienodes bytes=39.03KiB INFO [11-09|15:47:30.136] State heal in progress accounts=464,573@26.88MiB slots=889,522@65.42MiB codes=28485@233.84MiB nodes=730,028,391@203.75GiB pending=33410 TRACE[11-09|15:47:30.136] Fetching set of trie nodes peer=2e753bc8 reqid=7,145,491,214,201,630,368 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:30.252] Delivering set of healing trienodes peer=2e753bc8 reqid=7,145,491,214,201,630,368 trienodes=142 bytes=36.82KiB DEBUG[11-09|15:47:30.253] Peer discarded announcement by distance peer=7cf4b4e98140319b444d953c157f2d959586ce06da7f4c4e89937bec35040cb5 number=33,346,250 hash=2475e6..fc0f59 distance=33,346,250 DEBUG[11-09|15:47:30.427] Persisted set of healing data type=trienodes bytes=34.43KiB DEBUG[11-09|15:47:30.427] Updated trie node heal throttler rate=523.125 pending=831 throttle=1.000 TRACE[11-09|15:47:30.434] Fetching set of trie nodes peer=73f0313a reqid=4,645,309,470,360,138,868 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:30.560] Delivering set of healing trienodes peer=73f0313a reqid=4,645,309,470,360,138,868 trienodes=139 bytes=32.03KiB DEBUG[11-09|15:47:30.996] Persisted set of healing data type=trienodes bytes=28.74KiB TRACE[11-09|15:47:30.996] Fetching set of trie nodes peer=82ed1450 reqid=1,081,337,485,761,318,948 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:31.061] Delivering set of healing trienodes peer=82ed1450 reqid=1,081,337,485,761,318,948 trienodes=140 bytes=34.77KiB DEBUG[11-09|15:47:31.238] Persisted set of healing data type=trienodes bytes=35.29KiB TRACE[11-09|15:47:31.238] Fetching set of trie nodes peer=2b4afa01 reqid=757,213,434,095,439,570 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:31.330] Delivering set of healing trienodes peer=2b4afa01 reqid=757,213,434,095,439,570 trienodes=142 bytes=36.69KiB DEBUG[11-09|15:47:31.436] Persisted set of healing data type=trienodes bytes=44.15KiB DEBUG[11-09|15:47:31.436] Updated trie node heal throttler rate=579.430 pending=840 throttle=1.000 TRACE[11-09|15:47:31.436] Fetching set of trie nodes peer=52bd007b reqid=2,326,365,468,671,992,664 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:31.465] Delivering set of healing trienodes peer=52bd007b reqid=2,326,365,468,671,992,664 trienodes=133 bytes=21.68KiB TRACE[11-09|15:47:31.636] Fetching full headers peer=e93f789d count=192 from=33,346,248 DEBUG[11-09|15:47:31.636] Fetching batch of headers id=e93f789d6a79c157 conn=dyndial count=192 fromnum=33,346,248 skip=0 reverse=false DEBUG[11-09|15:47:31.636] Recalculated msgrate QoS values proto=eth rtt=2s confidence=1.000 ttl=6s next=2023-11-09T15:47:33+0000 TRACE[11-09|15:47:31.636] Debug dump of mean capacities proto=eth caps="map[4:1341.580776158541 6:34.4413276436704 16:25.589237588360827]" TRACE[11-09|15:47:31.637] Scheduling new headers peer=e93f789d count=1 from=33,346,248 TRACE[11-09|15:47:31.637] Fetching full headers peer=e93f789d count=192 from=33,346,249 DEBUG[11-09|15:47:31.638] Fetching batch of headers id=e93f789d6a79c157 conn=dyndial count=192 fromnum=33,346,249 skip=0 reverse=false TRACE[11-09|15:47:31.639] All headers delayed, waiting peer=e93f789d INFO [11-09|15:47:31.639] Imported new block headers count=1 elapsed=1.753ms number=33,346,248 hash=9e9841..a941e0 TRACE[11-09|15:47:31.639] Requesting new batch of receipts peer=2e753bc8 count=1 from=33,346,248 DEBUG[11-09|15:47:31.639] Fetching batch of receipts id=2e753bc8398aa451 conn=dyndial count=1 TRACE[11-09|15:47:31.639] Requesting new batch of bodies peer=e93f789d count=1 from=33,346,248 DEBUG[11-09|15:47:31.639] Fetching batch of block bodies id=e93f789d6a79c157 conn=dyndial count=1 TRACE[11-09|15:47:31.643] Delivered new batch of bodies peer=e93f789d count=1 accepted=1 TRACE[11-09|15:47:31.645] Delivered new batch of receipts peer=2e753bc8 count=1 accepted=1 DEBUG[11-09|15:47:31.677] Persisted set of healing data type=trienodes bytes=36.36KiB DEBUG[11-09|15:47:31.677] Recalculated msgrate QoS values proto=snap rtt=2s confidence=1.000 ttl=6s next=2023-11-09T15:47:33+0000 TRACE[11-09|15:47:31.677] Debug dump of mean capacities proto=snap caps="map[5:51.13902036936106 7:492.49352640690256]" TRACE[11-09|15:47:31.677] Fetching set of trie nodes peer=2025f924 reqid=6,524,510,854,336,740,441 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:31.801] Delivering set of healing trienodes peer=2025f924 reqid=6,524,510,854,336,740,441 trienodes=137 bytes=29.81KiB DEBUG[11-09|15:47:31.941] Persisted set of healing data type=trienodes bytes=43.09KiB TRACE[11-09|15:47:31.941] Fetching set of trie nodes peer=e93f789d reqid=5,248,302,664,143,663,489 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:32.087] Delivering set of healing trienodes peer=e93f789d reqid=5,248,302,664,143,663,489 trienodes=144 bytes=40.48KiB DEBUG[11-09|15:47:32.133] Peer discarded announcement by distance peer=f09744a5d630b727815525078c89246237d724745381aa9b40052bcdd63ff568 number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.143] Peer discarded announcement by distance peer=1db7fbf2a9eda081230bfa0aac466edc84a6547be759c50559de354787c85a6a number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.144] Peer discarded announcement by distance peer=919e705de10a9ac4ec7870eb6037fd79362c879f61b486d6a3732380c26ec7a8 number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.149] Peer discarded announcement by distance peer=c73a8be46fe54d49acdd1ccac0be37f188bfac6b3649751eeb634251502197fe number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.151] Peer discarded announcement by distance peer=e95fa0f62c8b1c3192c2335516729263fa7225c94f6a97074e52c6b2042bcecf number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.190] Peer discarded announcement by distance peer=c4f3d0ff2f3b511470fa1995a0b0cf21edd8edaf17433834289f23bfc77fa51a number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.203] Persisted set of healing data type=trienodes bytes=35.98KiB TRACE[11-09|15:47:32.203] Fetching set of trie nodes peer=2e753bc8 reqid=3,044,235,293,014,042,147 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB DEBUG[11-09|15:47:32.204] Peer discarded announcement by distance peer=52f89ab89ba938e1e78fc5a09b90ef53818adc5b7db647639f30f3ad57a5e278 number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.205] Peer discarded announcement by distance peer=aae0ed11c47b653fa4b1d6bdf1790fd22aba8c30d9daa3e280eee75b37d13372 number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.206] Peer discarded announcement by distance peer=b398012f04b48b843660d982d66237cd49b17f11ed5e825a3d9ec9ed159dfeef number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.221] Peer discarded announcement by distance peer=82ed1450fee0eaafebd857fa397e9f2833c9ca7f9c2fecf85720225847dcadb5 number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.229] Peer discarded announcement by distance peer=2b4afa01dc8034e502e17786db30b6ab783db9f9ccb1a5e654abf3f68f3a10e8 number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.230] Peer discarded announcement by distance peer=94f1f316c7aea29dd0bd3fefce6e3863e11bdfebcaff96bc0dd808e51a04ae17 number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.235] Peer discarded announcement by distance peer=52bd007b441691b1820c8646dd3d053f03cce0a3f266fae4c98ec145a342e985 number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.248] Peer discarded announcement by distance peer=73f0313ac1420b1a5ba614919ef5d2c83b92a75f54f108404184a66de12f8af2 number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.265] Peer discarded announcement by distance peer=e93f789d6a79c157cb926d2f478f81078fe25de7c5010b2a6f8e22986429c8f2 number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.267] Peer discarded announcement by distance peer=2e753bc8398aa45144eefc47d0dcc23e48cca403cb43c519f04258c34e9db89a number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.289] Peer discarded announcement by distance peer=cf43792e96e46a793084f47c657ef287f22634c5e73cb6c04ebc6d1b305ab88a number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.297] Peer discarded announcement by distance peer=2025f9246b21510d94a6e877d02d2f7d17ec7aa7a3697b9db571dfdd8417c00b number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.325] Peer discarded announcement by distance peer=85f414213ca8e09fb8ba068c1308904d0615fd8756bac0e275a010fdddcaecfb number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 TRACE[11-09|15:47:32.353] Delivering set of healing trienodes peer=2e753bc8 reqid=3,044,235,293,014,042,147 trienodes=139 bytes=33.27KiB DEBUG[11-09|15:47:32.357] Peer discarded announcement by distance peer=13edaeca09ce0d2dede2c4d63fb8215de29b0919a3bf7e820f5ca6b5e1bba213 number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.399] Peer discarded announcement by distance peer=10c1fae0b25ac54c851e46fb65d4c615d694edb20752fac0b01cec23426c865f number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.414] Peer discarded announcement by distance peer=b31b39d65990b97a2906fa5bf0da3571cd90cd41c9e0c506afa3e1bd5c7ecc32 number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 DEBUG[11-09|15:47:32.464] Persisted set of healing data type=trienodes bytes=31.11KiB DEBUG[11-09|15:47:32.464] Updated trie node heal throttler rate=540.063 pending=835 throttle=1.000 TRACE[11-09|15:47:32.465] Fetching set of trie nodes peer=73f0313a reqid=5,172,624,451,882,216,167 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB DEBUG[11-09|15:47:32.534] Peer discarded announcement by distance peer=1f3dafdc07212ff4d21de9c7cb8ad71922fc4b245d46565b4e1b169e40642a90 number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 TRACE[11-09|15:47:32.630] Delivering set of healing trienodes peer=73f0313a reqid=5,172,624,451,882,216,167 trienodes=142 bytes=37.01KiB DEBUG[11-09|15:47:32.760] Persisted set of healing data type=trienodes bytes=37.98KiB TRACE[11-09|15:47:32.760] Fetching set of trie nodes peer=82ed1450 reqid=6,476,641,583,680,851,893 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:32.815] Delivering set of healing trienodes peer=82ed1450 reqid=6,476,641,583,680,851,893 trienodes=139 bytes=33.53KiB TRACE[11-09|15:47:32.952] >> PING/v4 id=e5c17559715cadf1 addr=100.26.14.92:30311 err=nil TRACE[11-09|15:47:32.953] << PONG/v4 id=e5c17559715cadf1 addr=100.26.14.92:30311 err=nil TRACE[11-09|15:47:32.953] >> ENRREQUEST/v4 id=e5c17559715cadf1 addr=100.26.14.92:30311 err=nil TRACE[11-09|15:47:32.955] << ENRRESPONSE/v4 id=e5c17559715cadf1 addr=100.26.14.92:30311 err=nil DEBUG[11-09|15:47:32.955] Revalidated node b=14 id=e5c17559715cadf1 checks=1 TRACE[11-09|15:47:32.957] << PING/v4 id=e5c17559715cadf1 addr=100.26.14.92:30311 err=nil TRACE[11-09|15:47:32.957] >> PONG/v4 id=e5c17559715cadf1 addr=100.26.14.92:30311 err=nil TRACE[11-09|15:47:32.957] >> ENRREQUEST/v4 id=e5c17559715cadf1 addr=100.26.14.92:30311 err=nil TRACE[11-09|15:47:32.959] << ENRRESPONSE/v4 id=e5c17559715cadf1 addr=100.26.14.92:30311 err=nil DEBUG[11-09|15:47:33.075] Persisted set of healing data type=trienodes bytes=30.62KiB TRACE[11-09|15:47:33.075] Fetching set of trie nodes peer=2b4afa01 reqid=6,335,063,153,583,463,714 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB DEBUG[11-09|15:47:33.103] Peer discarded announcement by distance peer=fbca7bb1c8e97cb5d3b16a8169b3a8b668af5621718f19348f08b1d4564aada5 number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 TRACE[11-09|15:47:33.183] Delivering set of healing trienodes peer=2b4afa01 reqid=6,335,063,153,583,463,714 trienodes=139 bytes=32.37KiB DEBUG[11-09|15:47:33.261] Persisted set of healing data type=trienodes bytes=42.47KiB TRACE[11-09|15:47:33.261] Fetching set of trie nodes peer=52bd007b reqid=6,544,860,613,471,661,503 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:33.292] Delivering set of healing trienodes peer=52bd007b reqid=6,544,860,613,471,661,503 trienodes=135 bytes=26.15KiB TRACE[11-09|15:47:33.458] << ENRREQUEST/v4 id=e5c17559715cadf1 addr=100.26.14.92:30311 err=nil TRACE[11-09|15:47:33.458] >> ENRRESPONSE/v4 id=e5c17559715cadf1 addr=100.26.14.92:30311 err=nil DEBUG[11-09|15:47:33.504] Persisted set of healing data type=trienodes bytes=32.38KiB DEBUG[11-09|15:47:33.504] Updated trie node heal throttler rate=579.187 pending=838 throttle=1.000 TRACE[11-09|15:47:33.505] Fetching set of trie nodes peer=2025f924 reqid=7,302,565,316,647,046,830 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:33.603] Delivering set of healing trienodes peer=2025f924 reqid=7,302,565,316,647,046,830 trienodes=139 bytes=33.51KiB DEBUG[11-09|15:47:33.818] Persisted set of healing data type=trienodes bytes=27.87KiB DEBUG[11-09|15:47:33.818] Recalculated msgrate QoS values proto=snap rtt=2s confidence=1.000 ttl=6s next=2023-11-09T15:47:35+0000 TRACE[11-09|15:47:33.818] Debug dump of mean capacities proto=snap caps="map[5:51.13902036936108 7:482.0361671659068]" TRACE[11-09|15:47:33.818] Fetching set of trie nodes peer=e93f789d reqid=6,628,998,626,171,587,144 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB DEBUG[11-09|15:47:33.831] Peer discarded announcement by distance peer=7cf4b4e98140319b444d953c157f2d959586ce06da7f4c4e89937bec35040cb5 number=33,346,251 hash=aa870c..5a80ed distance=33,346,251 TRACE[11-09|15:47:34.083] Delivering set of healing trienodes peer=e93f789d reqid=6,628,998,626,171,587,144 trienodes=140 bytes=34.14KiB DEBUG[11-09|15:47:34.085] Persisted set of healing data type=trienodes bytes=44.80KiB TRACE[11-09|15:47:34.085] Fetching set of trie nodes peer=2e753bc8 reqid=5,945,243,426,260,316,416 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:34.287] Delivering set of healing trienodes peer=2e753bc8 reqid=5,945,243,426,260,316,416 trienodes=138 bytes=32.18KiB DEBUG[11-09|15:47:34.379] Persisted set of healing data type=trienodes bytes=23.54KiB TRACE[11-09|15:47:34.380] Fetching set of trie nodes peer=73f0313a reqid=1,461,345,841,690,776,926 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:34.528] Delivering set of healing trienodes peer=73f0313a reqid=1,461,345,841,690,776,926 trienodes=143 bytes=39.26KiB DEBUG[11-09|15:47:34.636] Persisted set of healing data type=trienodes bytes=39.06KiB DEBUG[11-09|15:47:34.636] Updated trie node heal throttler rate=522.353 pending=834 throttle=1.000 TRACE[11-09|15:47:34.636] Fetching set of trie nodes peer=82ed1450 reqid=5,971,607,732,878,028,983 root=0ec148..6aed4b pathsets=1024 bytes=512.00KiB TRACE[11-09|15:47:34.639] Fetching full headers peer=e93f789d count=192 from=33,346,249 DEBUG[11-09|15:47:34.639] Fetching batch of headers id=e93f789d6a79c157 conn=dyndial count=192 fromnum=33,346,249 skip=0 reverse=false DEBUG[11-09|15:47:34.639] Recalculated msgrate QoS values proto=eth rtt=2s confidence=1.000 ttl=6s next=2023-11-09T15:47:36+0000 TRACE[11-09|15:47:34.639] Debug dump of mean capacities proto=eth caps="map[4:1341.580776158542 6:34.43174381582538 16:25.5623930566584]"
weiihann commented 10 months ago

Hello, thanks for the detailed description of the problem. It helps a lot :) Let me try to reproduce the issue in my own environment.

Btw, you're setting --cache to 16000 which is ~15.64GB, while your system's RAM is only 16GB. Try setting cache to a lower amount like 5000 and sync again.

morzhanov commented 10 months ago

Btw, you're setting --cache to 16000 which is ~15.64GB, while your system's RAM is only 16GB. Try setting cache to a lower amount like 5000 and sync again.

Thanks for pointing this out! I'm using arguments from my previous node that had 16cpu/32gb. I reduced cache value to 8000 as I see that c5n.2xlarge ec2 instance has 20gb ram (I updated issue description).

BTW before the update with 16gb cache htop shows that node is only using 5gb ram:

image
weiihann commented 10 months ago

Can you show the logs with verbosity set to 3?

morzhanov commented 10 months ago

Can you show the logs with verbosity set to 3?

Sure, here are the logs:

verbosity=3 logs INFO [11-10|13:02:37.015] Starting Geth on Ethereum mainnet... INFO [11-10|13:02:37.016] Maximum peer count ETH=30 LES=0 total=30 INFO [11-10|13:02:37.017] Smartcard socket not found, disabling err="stat /run/pcscd/pcscd.comm: no such file or directory" WARN [11-10|13:02:37.019] Sanitizing cache to Go's GC limits provided=8000 updated=6811 INFO [11-10|13:02:37.024] Set global gas cap cap=50,000,000 INFO [11-10|13:02:37.024] Allocated trie memory caches clean=1021.00MiB dirty=1.66GiB INFO [11-10|13:02:37.024] Allocated cache and file handles database=/node/data/geth/chaindata cache=2.66GiB handles=524,288 INFO [11-10|13:02:46.731] AncientDB item count items=32,615,112 INFO [11-10|13:02:46.731] Opened ancient database database=/node/data/geth/chaindata/ancient readonly=false frozen=32,615,112 INFO [11-10|13:02:46.745] Initialised chain configuration config="{ChainID: 56 Homestead: 0 DAO: DAOSupport: false EIP150: 0 EIP155: 0 EIP158: 0 Byzantium: 0 Constantinople: 0 Petersburg: 0 Istanbul: 0, Muir Glacier: 0, Ramanujan: 0, Niels: 0, MirrorSync: 5184000, Bruno: 13082000, Berlin: 31302048, YOLO v3: , CatalystBlock: , London: 31302048, ArrowGlacier: , MergeFork:, Euler: 18907621, Gibbs: 23846001, Nano: 21962149, Moran: 22107423, Planck: 27281024,Luban: 29020050, Plato: 30720096, Hertz: 31302048, Engine: parlia}" INFO [11-10|13:02:53.922] Unprotected transactions allowed INFO [11-10|13:02:53.930] Initialising Ethereum protocol network=56 dbversion=8 INFO [11-10|13:02:54.031] Loaded most recent local header number=33,369,453 hash=b2398e..66ac88 td=66,301,476 age=1h43m33s INFO [11-10|13:02:54.031] Loaded most recent local full block number=0 hash=0d2184..d57b5b td=1 age=3y7mo1w INFO [11-10|13:02:54.031] Loaded most recent local fast block number=33,369,453 hash=b2398e..66ac88 td=66,301,476 age=1h43m33s INFO [11-10|13:02:54.031] Loaded last fast-sync pivot marker number=33,371,388 WARN [11-10|13:02:54.046] Snapshot maintenance disabled (syncing) WARN [11-10|13:02:54.046] Sanitizing invalid txpool lifetime provided=0s updated=3h0m0s WARN [11-10|13:02:54.046] Sanitizing invalid txpool reannounce time provided=0s updated=1m0s WARN [11-10|13:02:54.046] Switch sync mode from full sync to snap sync INFO [11-10|13:02:54.046] Create votePool successfully WARN [11-10|13:02:54.046] Sanitizing invalid gasprice oracle price cap provided= updated=100,000,000,000 WARN [11-10|13:02:54.046] Sanitizing invalid gasprice oracle ignore price provided= updated=4 WARN [11-10|13:02:54.046] Sanitizing invalid gasprice oracle max header history provided=0 updated=1 WARN [11-10|13:02:54.046] Sanitizing invalid gasprice oracle max block history provided=0 updated=1 INFO [11-10|13:02:54.053] Starting peer-to-peer node instance=Geth/v1.2.12-bb6bdc05/linux-amd64/go1.19.13 INFO [11-10|13:02:54.138] New local node record seq=1,697,498,035,679 id=cc4ae8fd6a2b8064 ip=127.0.0.1 udp=30311 tcp=30311 ERROR[11-10|13:02:54.139] Unavailable modules in HTTP API list unavailable=[engine] available="[admin debug web3 eth txpool personal parlia miner net]" INFO [11-10|13:02:54.140] HTTP server started endpoint=127.0.0.1:8545 prefix= cors=* vhosts=* INFO [11-10|13:02:54.140] GraphQL enabled url=http://127.0.0.1:8545/graphql INFO [11-10|13:02:54.140] GraphQL UI enabled url=http://127.0.0.1:8545/graphql/ui INFO [11-10|13:02:54.140] WebSocket enabled url=ws://127.0.0.1:8546 INFO [11-10|13:02:54.141] Started P2P networking self=enode://e02f87831f44d03839c67d37fb08ccbe7bbdccf3b7c32bbf9cc1cbc46220205344ec8b94d5666014d493e84292ec9b1deca5ed99fb68e9a590c77c323e5859cc@127.0.0.1:30311 INFO [11-10|13:03:04.246] Looking for peers peercount=5 tried=138 static=1 INFO [11-10|13:03:13.274] Block synchronisation started INFO [11-10|13:03:13.385] Disabling direct-ancient mode origin=33,369,453 ancient=32,615,111 INFO [11-10|13:03:13.389] State heal in progress accounts=0@0.00B slots=0@0.00B codes=29786@244.83MiB nodes=766,369,095@214.26GiB pending=1 WARN [11-10|13:03:16.294] Snapshot extension registration failed peer=e9f21729 err="peer connected on snap without compatible eth support" INFO [11-10|13:03:21.516] State heal in progress accounts=0@0.00B slots=0@0.00B codes=29786@244.83MiB nodes=766,369,367@214.26GiB pending=1701 INFO [11-10|13:03:29.650] State heal in progress accounts=5@228.00B slots=0@0.00B codes=29786@244.83MiB nodes=766,370,045@214.26GiB pending=4046 INFO [11-10|13:03:37.762] State heal in progress accounts=26@1.38KiB slots=0@0.00B codes=29786@244.83MiB nodes=766,370,847@214.26GiB pending=5933 INFO [11-10|13:03:47.108] State heal in progress accounts=166@8.52KiB slots=0@0.00B codes=29786@244.83MiB nodes=766,372,083@214.26GiB pending=7443 INFO [11-10|13:03:55.702] State heal in progress accounts=353@18.19KiB slots=6@501.00B codes=29786@244.83MiB nodes=766,373,438@214.26GiB pending=8356 INFO [11-10|13:04:04.105] State heal in progress accounts=514@26.70KiB slots=26@2.09KiB codes=29786@244.83MiB nodes=766,374,740@214.26GiB pending=9090 INFO [11-10|13:04:13.463] State heal in progress accounts=757@39.35KiB slots=49@3.92KiB codes=29786@244.83MiB nodes=766,376,217@214.26GiB pending=9583 INFO [11-10|13:04:14.609] Imported new block headers count=768 elapsed=1.208s number=33,370,221 hash=e5ade6..9b2a0f age=1h6m21s INFO [11-10|13:04:21.695] State heal in progress accounts=964@50.99KiB slots=86@6.90KiB codes=29786@244.83MiB nodes=766,377,697@214.26GiB pending=10565 INFO [11-10|13:04:30.242] State heal in progress accounts=1216@64.43KiB slots=146@11.66KiB codes=29787@244.84MiB nodes=766,379,478@214.26GiB pending=11823 INFO [11-10|13:04:38.259] State heal in progress accounts=1534@81.00KiB slots=269@21.47KiB codes=29787@244.84MiB nodes=766,381,201@214.26GiB pending=12180 INFO [11-10|13:04:46.764] State heal in progress accounts=1665@87.91KiB slots=429@33.79KiB codes=29787@244.84MiB nodes=766,382,952@214.26GiB pending=13082 INFO [11-10|13:04:54.941] State heal in progress accounts=1830@96.75KiB slots=833@63.89KiB codes=29787@244.84MiB nodes=766,385,052@214.26GiB pending=13271 INFO [11-10|13:05:03.628] State heal in progress accounts=1969@104.03KiB slots=1129@85.76KiB codes=29788@244.85MiB nodes=766,387,061@214.26GiB pending=13546 INFO [11-10|13:05:12.214] State heal in progress accounts=2237@117.81KiB slots=1643@123.82KiB codes=29788@244.85MiB nodes=766,389,483@214.26GiB pending=12481 ERROR[11-10|13:05:13.389] Expired request does not exist peer=e9df8079340c50ce625c43d92da94156e200080fde3b2975f80691fcfa6876fd ERROR[11-10|13:05:13.389] Expired request does not exist peer=e9df8079340c50ce625c43d92da94156e200080fde3b2975f80691fcfa6876fd INFO [11-10|13:05:13.392] Downloader queue stats receiptTasks=0 blockTasks=0 itemSize=49.33KiB throttle=5315 INFO [11-10|13:05:13.396] Imported new block receipts count=3 elapsed=3.826ms number=33,369,456 hash=4e75b1..9b0039 age=1h45m43s size=282.37KiB ERROR[11-10|13:05:14.611] Expired request does not exist peer=e921478257c66d9ee23fed94a334cc54d45a7e10b40dc85367aab8d449229b09 INFO [11-10|13:05:14.623] Imported new block receipts count=6 elapsed=10.523ms number=33,369,462 hash=5263a7..d0918f age=1h45m23s size=775.70KiB INFO [11-10|13:05:15.889] Imported new block receipts count=759 elapsed=1.250s number=33,370,221 hash=e5ade6..9b2a0f age=1h7m22s size=94.42MiB INFO [11-10|13:05:20.567] State heal in progress accounts=2698@142.18KiB slots=2052@154.35KiB codes=29788@244.85MiB nodes=766,391,972@214.26GiB pending=11293 INFO [11-10|13:05:29.659] State heal in progress accounts=3015@159.14KiB slots=2444@184.08KiB codes=29788@244.85MiB nodes=766,394,331@214.27GiB pending=10931 INFO [11-10|13:05:37.777] State heal in progress accounts=3177@167.48KiB slots=2742@206.95KiB codes=29788@244.85MiB nodes=766,396,346@214.27GiB pending=11188 INFO [11-10|13:05:46.073] State heal in progress accounts=3520@185.09KiB slots=3131@236.72KiB codes=29788@244.85MiB nodes=766,398,822@214.27GiB pending=10476 INFO [11-10|13:05:54.364] State heal in progress accounts=3884@204.57KiB slots=3478@263.24KiB codes=29788@244.85MiB nodes=766,401,225@214.27GiB pending=10271 INFO [11-10|13:06:02.991] State heal in progress accounts=4117@216.62KiB slots=3723@281.89KiB codes=29788@244.85MiB nodes=766,403,383@214.27GiB pending=11547 INFO [11-10|13:06:11.097] State heal in progress accounts=4466@234.78KiB slots=4045@306.38KiB codes=29789@244.87MiB nodes=766,405,689@214.27GiB pending=11399 INFO [11-10|13:06:19.558] State heal in progress accounts=4812@252.15KiB slots=4431@335.57KiB codes=29789@244.87MiB nodes=766,408,146@214.27GiB pending=10863 WARN [11-10|13:06:54.592] Pivot seemingly stale, moving old=33,371,461 new=33,371,525 INFO [11-10|13:06:54.701] State heal in progress accounts=4966@259.92KiB slots=4645@351.74KiB codes=29790@244.87MiB nodes=766,409,965@214.27GiB pending=11182 INFO [11-10|13:06:56.279] Imported new block headers count=1152 elapsed=1.689s number=33,371,373 hash=37c662..5e7bb6 age=11m19s INFO [11-10|13:06:56.484] Downloader queue stats receiptTasks=0 blockTasks=0 itemSize=322.55KiB throttle=813 INFO [11-10|13:06:56.484] State heal in progress accounts=4966@259.92KiB slots=4645@351.74KiB codes=29790@244.87MiB nodes=766,409,965@214.27GiB pending=11182 INFO [11-10|13:06:56.762] Imported new block receipts count=46 elapsed=126.596ms number=33,370,267 hash=ac667e..217333 age=1h6m41s size=5.75MiB INFO [11-10|13:06:56.826] Imported new block receipts count=26 elapsed=62.153ms number=33,370,293 hash=d7e724..85cbe8 age=1h5m23s size=3.44MiB INFO [11-10|13:06:56.863] Imported new block receipts count=16 elapsed=36.654ms number=33,370,309 hash=563c29..62ad93 age=1h4m35s size=2.02MiB INFO [11-10|13:06:56.925] Imported new block receipts count=19 elapsed=45.858ms number=33,370,328 hash=522eb1..c71268 age=1h3m38s size=2.72MiB INFO [11-10|13:06:56.988] Imported new block receipts count=21 elapsed=48.537ms number=33,370,349 hash=90b61a..7faaf6 age=1h2m35s size=2.37MiB INFO [11-10|13:06:57.056] Imported new block receipts count=21 elapsed=46.737ms number=33,370,370 hash=af6510..fc3e84 age=1h1m33s size=2.45MiB INFO [11-10|13:06:57.174] Imported new block receipts count=22 elapsed=103.091ms number=33,370,392 hash=5fd830..6f2a47 age=1h27s size=2.33MiB INFO [11-10|13:06:57.239] Imported new block receipts count=20 elapsed=63.784ms number=33,370,412 hash=175a29..595b8b age=59m27s size=2.37MiB INFO [11-10|13:06:57.311] Imported new block receipts count=21 elapsed=60.120ms number=33,370,433 hash=8f2c8f..2b1bed age=58m24s size=2.40MiB INFO [11-10|13:06:57.375] Imported new block receipts count=22 elapsed=46.548ms number=33,370,455 hash=5bc2f0..8fc886 age=57m18s size=2.36MiB INFO [11-10|13:06:57.427] Imported new block receipts count=19 elapsed=30.509ms number=33,370,474 hash=9da455..d93f72 age=56m21s size=2.33MiB INFO [11-10|13:06:57.689] Imported new block receipts count=120 elapsed=259.701ms number=33,370,594 hash=816404..e7cf5a age=50m21s size=17.10MiB INFO [11-10|13:06:57.828] Imported new block receipts count=74 elapsed=136.949ms number=33,370,668 hash=2e3ec9..77963c age=46m39s size=9.61MiB INFO [11-10|13:06:57.925] Imported new block receipts count=47 elapsed=95.518ms number=33,370,715 hash=d1cec7..69e774 age=44m18s size=7.14MiB INFO [11-10|13:06:57.952] Imported new block receipts count=19 elapsed=26.788ms number=33,370,734 hash=15e371..042ad8 age=43m21s size=2.19MiB INFO [11-10|13:07:05.450] State heal in progress accounts=4966@259.92KiB slots=4645@351.74KiB codes=29790@244.87MiB nodes=766,412,075@214.27GiB pending=20231 INFO [11-10|13:07:14.073] State heal in progress accounts=4966@259.92KiB slots=4645@351.74KiB codes=29790@244.87MiB nodes=766,414,432@214.27GiB pending=25723 WARN [11-10|13:07:15.790] Snapshot extension registration failed peer=9f9de7e9 err="peer connected on snap without compatible eth support" INFO [11-10|13:07:23.105] State heal in progress accounts=4982@260.83KiB slots=4645@351.74KiB codes=29790@244.87MiB nodes=766,416,529@214.27GiB pending=28300 ERROR[11-10|13:07:25.217] Expired request does not exist peer=09450f014714e019e87bb85d8bb2e432c33c3f962d1746a43ca8cb17384b6584 ERROR[11-10|13:07:25.219] Expired request does not exist peer=09450f014714e019e87bb85d8bb2e432c33c3f962d1746a43ca8cb17384b6584 INFO [11-10|13:07:25.610] Imported new block headers count=192 elapsed=381.114ms number=33,371,565 hash=6c77b0..25b2c0 age=2m12s INFO [11-10|13:07:25.716] Imported new block headers count=42 elapsed=105.569ms number=33,371,607 hash=2b3a34..5d11a4 INFO [11-10|13:07:27.004] Imported new block receipts count=47 elapsed=123.921ms number=33,370,781 hash=8a5981..47a1bd age=41m30s size=6.27MiB INFO [11-10|13:07:27.851] Imported new block receipts count=490 elapsed=837.519ms number=33,371,271 hash=2e2e11..807d8b age=16m56s size=53.13MiB INFO [11-10|13:07:28.311] Imported new block receipts count=253 elapsed=452.974ms number=33,371,524 hash=be7ac8..2cc8d6 age=4m18s size=30.18MiB INFO [11-10|13:07:28.314] Imported new block headers count=1 elapsed=2.738ms number=33,371,608 hash=23be03..21b71c INFO [11-10|13:07:29.319] State heal in progress accounts=5158@269.98KiB slots=4645@351.74KiB codes=29791@244.87MiB nodes=766,417,963@214.27GiB pending=29438 WARN [11-10|13:07:29.324] Unexpected trienode heal packet peer=e93f789d reqid=6,420,013,677,219,891,340 INFO [11-10|13:07:31.318] Imported new block headers count=1 elapsed=2.062ms number=33,371,609 hash=85a5d3..76efc2 INFO [11-10|13:07:34.323] Imported new block headers count=1 elapsed=2.912ms number=33,371,610 hash=d4f344..cf0947 INFO [11-10|13:07:37.327] Imported new block headers count=1 elapsed=2.361ms number=33,371,611 hash=5917aa..8d9849 INFO [11-10|13:07:37.336] State heal in progress accounts=5206@272.59KiB slots=4645@351.74KiB codes=29791@244.87MiB nodes=766,424,174@214.28GiB pending=27867 INFO [11-10|13:07:43.336] Imported new block headers count=2 elapsed=3.594ms number=33,371,613 hash=b4edc6..5752a5 INFO [11-10|13:07:45.872] State heal in progress accounts=5721@301.58KiB slots=4647@351.92KiB codes=29791@244.87MiB nodes=766,427,705@214.28GiB pending=29848 INFO [11-10|13:07:46.339] Imported new block headers count=1 elapsed=2.004ms number=33,371,614 hash=cc3640..22759a INFO [11-10|13:07:49.353] Imported new block headers count=1 elapsed=2.111ms number=33,371,615 hash=90926c..0c7421 INFO [11-10|13:07:52.357] Imported new block headers count=1 elapsed=1.912ms number=33,371,616 hash=d26903..6466e1 INFO [11-10|13:07:54.207] State heal in progress accounts=6247@330.59KiB slots=4704@356.45KiB codes=29791@244.87MiB nodes=766,430,551@214.28GiB pending=30982 INFO [11-10|13:07:55.361] Imported new block headers count=1 elapsed=2.019ms number=33,371,617 hash=da5b5f..ccdd39 INFO [11-10|13:07:58.365] Imported new block headers count=1 elapsed=2.135ms number=33,371,618 hash=942793..73fd9e INFO [11-10|13:07:59.333] Downloader queue stats receiptTasks=0 blockTasks=0 itemSize=220.42KiB throttle=1190 INFO [11-10|13:08:01.370] Imported new block headers count=1 elapsed=1.617ms number=33,371,619 hash=d29652..994de1 INFO [11-10|13:08:02.842] State heal in progress accounts=6515@345.06KiB slots=4773@361.85KiB codes=29791@244.87MiB nodes=766,432,931@214.28GiB pending=32475 INFO [11-10|13:08:04.374] Imported new block headers count=1 elapsed=1.627ms number=33,371,620 hash=290e30..888a3c INFO [11-10|13:08:07.379] Imported new block headers count=1 elapsed=2.238ms number=33,371,621 hash=a2e00f..b44091 INFO [11-10|13:08:10.383] Imported new block headers count=1 elapsed=1.609ms number=33,371,622 hash=bf8f88..616de5 INFO [11-10|13:08:11.111] State heal in progress accounts=6876@365.22KiB slots=4897@371.67KiB codes=29791@244.87MiB nodes=766,435,413@214.28GiB pending=33398 INFO [11-10|13:08:13.387] Imported new block headers count=1 elapsed=2.132ms number=33,371,623 hash=29fd3e..ac1c3e INFO [11-10|13:08:16.391] Imported new block headers count=1 elapsed=1.688ms number=33,371,624 hash=94d204..4dc311 INFO [11-10|13:08:19.287] State heal in progress accounts=7286@387.80KiB slots=5245@398.92KiB codes=29791@244.87MiB nodes=766,438,322@214.28GiB pending=33990 INFO [11-10|13:08:19.395] Imported new block headers count=1 elapsed=1.634ms number=33,371,625 hash=09ac9d..39cdef INFO [11-10|13:08:22.399] Imported new block headers count=1 elapsed=1.684ms number=33,371,626 hash=f71e07..74696b INFO [11-10|13:08:25.403] Imported new block headers count=1 elapsed=1.643ms number=33,371,627 hash=7818da..cfb965 INFO [11-10|13:08:27.297] State heal in progress accounts=7563@403.02KiB slots=5824@443.20KiB codes=29791@244.87MiB nodes=766,441,328@214.28GiB pending=34025 INFO [11-10|13:08:28.408] Imported new block headers count=1 elapsed=1.673ms number=33,371,628 hash=d7ab8c..ed8a88 INFO [11-10|13:08:31.413] Imported new block headers count=1 elapsed=2.006ms number=33,371,629 hash=3eed33..ac21ce INFO [11-10|13:08:34.418] Imported new block headers count=1 elapsed=2.490ms number=33,371,630 hash=84c7bb..891eab INFO [11-10|13:08:35.494] State heal in progress accounts=7936@422.95KiB slots=6511@496.29KiB codes=29791@244.87MiB nodes=766,444,639@214.28GiB pending=33307 INFO [11-10|13:08:37.423] Imported new block headers count=1 elapsed=2.098ms number=33,371,631 hash=2d2cd3..d99abd INFO [11-10|13:08:40.426] Imported new block headers count=1 elapsed=1.738ms number=33,371,632 hash=649818..5cedb1 INFO [11-10|13:08:43.644] State heal in progress accounts=8209@437.28KiB slots=7171@546.71KiB codes=29791@244.87MiB nodes=766,447,740@214.28GiB pending=32749 INFO [11-10|13:08:46.436] Imported new block headers count=2 elapsed=4.511ms number=33,371,634 hash=f49b71..dd18f7 INFO [11-10|13:08:49.438] Imported new block headers count=1 elapsed=1.623ms number=33,371,635 hash=d45f1e..059905 INFO [11-10|13:08:52.080] State heal in progress accounts=8489@452.46KiB slots=7961@607.54KiB codes=29791@244.87MiB nodes=766,451,205@214.28GiB pending=31669 INFO [11-10|13:08:52.442] Imported new block headers count=1 elapsed=2.027ms number=33,371,636 hash=786389..53d025 INFO [11-10|13:08:55.446] Imported new block headers count=1 elapsed=2.176ms number=33,371,637 hash=f6a891..bc37f8 INFO [11-10|13:08:58.451] Imported new block headers count=1 elapsed=2.088ms number=33,371,638 hash=1da13f..ee60bc WARN [11-10|13:08:58.451] Peer stalling, dropping peer=2d83c700 waited=2m2.054s WARN [11-10|13:08:58.451] Peer stalling, dropping peer=2d83c700 waited=2m2.151s WARN [11-10|13:08:58.451] Peer stalling, dropping peer=09132d55 waited=2m2.155s INFO [11-10|13:08:59.368] Downloader queue stats receiptTasks=0 blockTasks=0 itemSize=215.67KiB throttle=1216 INFO [11-10|13:09:00.300] State heal in progress accounts=8770@468.15KiB slots=8596@655.92KiB codes=29791@244.87MiB nodes=766,454,335@214.28GiB pending=30784 INFO [11-10|13:09:01.457] Imported new block headers count=1 elapsed=3.246ms number=33,371,639 hash=cbf843..77c49d INFO [11-10|13:09:04.460] Imported new block headers count=1 elapsed=2.176ms number=33,371,640 hash=ee934e..9ea213 INFO [11-10|13:09:07.464] Imported new block headers count=1 elapsed=2.188ms number=33,371,641 hash=50a640..46e892 INFO [11-10|13:09:08.810] State heal in progress accounts=8932@476.78KiB slots=9027@688.78KiB codes=29791@244.87MiB nodes=766,457,258@214.29GiB pending=31276 INFO [11-10|13:09:10.468] Imported new block headers count=1 elapsed=1.582ms number=33,371,642 hash=8333a0..8e8f78 INFO [11-10|13:09:13.473] Imported new block headers count=1 elapsed=2.111ms number=33,371,643 hash=33fcd8..49e6b2 INFO [11-10|13:09:16.477] Imported new block headers count=1 elapsed=1.967ms number=33,371,644 hash=1aec73..06e736 INFO [11-10|13:09:17.387] State heal in progress accounts=9158@489.21KiB slots=9583@731.23KiB codes=29793@244.88MiB nodes=766,460,218@214.29GiB pending=30934 INFO [11-10|13:09:19.481] Imported new block headers count=1 elapsed=1.975ms number=33,371,645 hash=42f2b4..bfcb19 INFO [11-10|13:09:22.486] Imported new block headers count=1 elapsed=2.509ms number=33,371,646 hash=dff918..90a690 INFO [11-10|13:09:25.489] Imported new block headers count=1 elapsed=1.661ms number=33,371,647 hash=677f80..cf5380 INFO [11-10|13:09:26.132] State heal in progress accounts=9460@505.67KiB slots=10096@770.15KiB codes=29794@244.89MiB nodes=766,463,208@214.29GiB pending=30253 INFO [11-10|13:09:28.495] Imported new block headers count=1 elapsed=2.986ms number=33,371,648 hash=e3750b..c54138 INFO [11-10|13:09:31.500] Imported new block headers count=1 elapsed=2.638ms number=33,371,649 hash=6dce39..cce32e INFO [11-10|13:09:34.506] Imported new block headers count=1 elapsed=1.698ms number=33,371,650 hash=eb1c74..8a6fbe INFO [11-10|13:09:34.615] State heal in progress accounts=9736@521.22KiB slots=10497@800.91KiB codes=29795@244.89MiB nodes=766,465,834@214.29GiB pending=30069 INFO [11-10|13:09:37.552] Imported new block headers count=1 elapsed=43.995ms number=33,371,651 hash=c716fe..f6b0da WARN [11-10|13:09:38.396] Pivot became stale, moving old=33,371,525 new=33,371,589 INFO [11-10|13:09:38.526] Imported new block receipts count=64 elapsed=129.221ms number=33,371,588 hash=32b9e9..3b8d2d age=3m16s size=7.55MiB INFO [11-10|13:09:38.825] State heal in progress accounts=9925@531.34KiB slots=10776@822.44KiB codes=29795@244.89MiB nodes=766,467,333@214.29GiB pending=29521 WARN [11-10|13:09:38.826] Unexpected trienode heal packet peer=b50369cc reqid=1,439,287,449,652,689,066 INFO [11-10|13:09:40.514] Imported new block headers count=1 elapsed=1.793ms number=33,371,652 hash=987abb..14f806 INFO [11-10|13:09:43.518] Imported new block headers count=1 elapsed=1.901ms number=33,371,653 hash=53af7b..995abd INFO [11-10|13:09:47.473] State heal in progress accounts=9925@531.34KiB slots=10776@822.44KiB codes=29795@244.89MiB nodes=766,470,357@214.29GiB pending=31539 INFO [11-10|13:09:49.527] Imported new block headers count=2 elapsed=3.707ms number=33,371,655 hash=bace4a..bdaf7c INFO [11-10|13:09:52.530] Imported new block headers count=1 elapsed=2.165ms number=33,371,656 hash=183ad2..be5ca1 INFO [11-10|13:09:55.537] Imported new block headers count=1 elapsed=2.069ms number=33,371,657 hash=54f76b..9ba958 INFO [11-10|13:09:55.938] State heal in progress accounts=9925@531.34KiB slots=10776@822.44KiB codes=29795@244.89MiB nodes=766,474,283@214.29GiB pending=38960 INFO [11-10|13:09:58.542] Imported new block headers count=1 elapsed=2.754ms number=33,371,658 hash=6e5e13..5b0b81 INFO [11-10|13:10:01.545] Imported new block headers count=1 elapsed=1.648ms number=33,371,659 hash=7647ea..3fb99d INFO [11-10|13:10:01.839] Downloader queue stats receiptTasks=0 blockTasks=0 itemSize=209.50KiB throttle=1252 INFO [11-10|13:10:04.550] Imported new block headers count=1 elapsed=1.686ms number=33,371,660 hash=d228ad..a113f4 INFO [11-10|13:10:04.822] State heal in progress accounts=10107@542.84KiB slots=10776@822.44KiB codes=29795@244.89MiB nodes=766,477,522@214.29GiB pending=42539 INFO [11-10|13:10:07.554] Imported new block headers count=1 elapsed=1.639ms number=33,371,661 hash=4a0c13..43812b INFO [11-10|13:10:10.558] Imported new block headers count=1 elapsed=1.596ms number=33,371,662 hash=ed2722..aa94cd INFO [11-10|13:10:12.877] State heal in progress accounts=11042@597.74KiB slots=10800@824.32KiB codes=29796@244.90MiB nodes=766,481,590@214.29GiB pending=43752 INFO [11-10|13:10:13.563] Imported new block headers count=1 elapsed=1.572ms number=33,371,663 hash=e9ccf0..87e47b INFO [11-10|13:10:16.569] Imported new block headers count=1 elapsed=2.312ms number=33,371,664 hash=7c719a..b0b4d1 INFO [11-10|13:10:19.573] Imported new block headers count=1 elapsed=2.123ms number=33,371,665 hash=eb1c97..d90754 INFO [11-10|13:10:20.993] State heal in progress accounts=11980@652.84KiB slots=10974@838.21KiB codes=29796@244.90MiB nodes=766,485,975@214.30GiB pending=45116 INFO [11-10|13:10:22.577] Imported new block headers count=1 elapsed=1.547ms number=33,371,666 hash=bbb8c7..5f9c63 INFO [11-10|13:10:25.582] Imported new block headers count=1 elapsed=2.001ms number=33,371,667 hash=565a08..cd8bdb INFO [11-10|13:10:28.585] Imported new block headers count=1 elapsed=1.586ms number=33,371,668 hash=8bfc40..b2c38d INFO [11-10|13:10:28.994] State heal in progress accounts=12292@671.52KiB slots=11480@877.95KiB codes=29797@244.91MiB nodes=766,489,729@214.30GiB pending=46647 INFO [11-10|13:10:31.590] Imported new block headers count=1 elapsed=1.654ms number=33,371,669 hash=c9ae4b..584ab2 INFO [11-10|13:10:34.594] Imported new block headers count=1 elapsed=1.585ms number=33,371,670 hash=326b7b..bff533 INFO [11-10|13:10:37.259] State heal in progress accounts=12387@677.98KiB slots=12259@938.42KiB codes=29797@244.91MiB nodes=766,493,444@214.30GiB pending=47310 INFO [11-10|13:10:37.599] Imported new block headers count=1 elapsed=1.680ms number=33,371,671 hash=19fb8c..536f26 INFO [11-10|13:10:40.603] Imported new block headers count=1 elapsed=1.746ms number=33,371,672 hash=97ed4b..a679ce INFO [11-10|13:10:43.608] Imported new block headers count=1 elapsed=2.032ms number=33,371,673 hash=1ba3a0..bca0f9 INFO [11-10|13:10:45.722] State heal in progress accounts=12400@679.01KiB slots=13073@1000.74KiB codes=29797@244.91MiB nodes=766,496,632@214.30GiB pending=47490 INFO [11-10|13:10:46.613] Imported new block headers count=1 elapsed=2.386ms number=33,371,674 hash=592cc7..646059 INFO [11-10|13:10:49.616] Imported new block headers count=1 elapsed=1.658ms number=33,371,675 hash=0d6f1d..96ec96 INFO [11-10|13:10:52.631] Imported new block headers count=1 elapsed=3.012ms number=33,371,676 hash=986ddf..edfe18 INFO [11-10|13:10:53.746] State heal in progress accounts=12427@680.55KiB slots=14213@1.06MiB codes=29797@244.91MiB nodes=766,500,683@214.30GiB pending=46677 INFO [11-10|13:10:55.633] Imported new block headers count=1 elapsed=1.621ms number=33,371,677 hash=e1ee9b..c63162 INFO [11-10|13:10:58.638] Imported new block headers count=1 elapsed=1.657ms number=33,371,678 hash=29bd67..b1e3a7 INFO [11-10|13:11:01.643] Imported new block headers count=1 elapsed=1.646ms number=33,371,679 hash=78713a..e73979 INFO [11-10|13:11:01.861] Downloader queue stats receiptTasks=0 blockTasks=0 itemSize=221.79KiB throttle=1182 INFO [11-10|13:11:01.970] State heal in progress accounts=12798@702.01KiB slots=15551@1.16MiB codes=29797@244.91MiB nodes=766,505,688@214.30GiB pending=44066 INFO [11-10|13:11:04.647] Imported new block headers count=1 elapsed=1.633ms number=33,371,680 hash=cac601..faf42f INFO [11-10|13:11:07.651] Imported new block headers count=1 elapsed=1.566ms number=33,371,681 hash=9964c1..0f54cd INFO [11-10|13:11:10.312] State heal in progress accounts=13120@720.21KiB slots=16675@1.24MiB codes=29797@244.91MiB nodes=766,510,322@214.30GiB pending=42320 INFO [11-10|13:11:10.655] Imported new block headers count=1 elapsed=1.740ms number=33,371,682 hash=2d7f8b..e60a54 INFO [11-10|13:11:13.660] Imported new block headers count=1 elapsed=1.695ms number=33,371,683 hash=42603b..ec7344

And here's the eth_syncing result:

{
    "jsonrpc": "2.0",
    "id": 1,
    "result": {
        "currentBlock": "0x1fd35c4",
        "healedBytecodeBytes": "0xf4e859d",
        "healedBytecodes": "0x7465",
        "healedTrienodeBytes": "0x35935ef3fc",
        "healedTrienodes": "0x2db0187f",
        "healingBytecode": "0x0",
        "healingTrienodes": "0x454",
        "highestBlock": "0x1fd3625",
        "startingBlock": "0x1fd2d6d",
        "syncedAccountBytes": "0xe51757115",
        "syncedAccounts": "0x10fe8e32",
        "syncedBytecodeBytes": "0x4d796afbe",
        "syncedBytecodes": "0x251458",
        "syncedStorage": "0xcf0fd89e",
        "syncedStorageBytes": "0xad8db11043"
    }
}

Peers count is 30

weiihann commented 10 months ago

That's interesting, those logs typically only appear when you run a node with snap sync.

Did you happen to run a node previously with snap sync enabled? Or did you start fresh by downloading the latest snapshot and do a full sync?

morzhanov commented 10 months ago

That's interesting, those logs typically only appear when you run a node with snap sync.

Did you happen to run a node previously with snap sync enabled? Or did you start fresh by downloading the latest snapshot and do a full sync?

Yes, from the start I tried to use syncmode=snap and I changed it to full after 3 days.

morzhanov commented 10 months ago

BTW I used this snapshot https://github.com/48Club/bsc-snapshots#geth-full-node

Official snapshot from this page is not working for me: https://github.com/bnb-chain/bsc-snapshots

When I tried to use official snapshot I was getting peers error: node was only connected to 3-8 peers and eth_syncing response was always:

{
    "jsonrpc": "2.0",
    "id": 1,
    "result": false
}
weiihann commented 10 months ago

Yes, from the start I tried to use syncmode=snap and I changed it to full after 3 days.

Ah, then I think running snap sync initially corrupted your database. There is some issue with snap sync right now (refer to #1934).

What I'd advise is to scrap off the old database, download the latest snapshot again, and sync it with --syncmode=full.

morzhanov commented 10 months ago

What I'd advice is to scrap off the old database, download the latest snapshot again, and sync it with --syncmode=false.

Thanks for the advice! I'll try to restart node with the latest snapshot from here: https://github.com/48Club/bsc-snapshots#geth-full-node. Also, I'll try to run my second node with the latest snapshot from here: https://github.com/bnb-chain/bsc-snapshots.

Both nodes will use --syncmode=false.

BTW what geth version you'd advice to use with the latest official snapshot? Should I use 1.2.12 or 1.3.0 ?

morzhanov commented 10 months ago

Also, is false a valid value for syncmode parameter? I only see 3 options for this parameter:

--syncmode value                    (default: snap)                    ($GETH_SYNCMODE)
      Blockchain sync mode ("snap", "full" or "light")
weiihann commented 10 months ago

Sorry, I meant --syncmode=full🥲. Edited the comment above.

weiihann commented 10 months ago

BTW what geth version you'd advice to use with the latest official snapshot? Should I use 1.2.12 or 1.3.0 ?

If your use case isn't business-critical, you may try v1.3.1-beta. Otherwise, you can use the latest stable version which is v1.2.13.

morzhanov commented 10 months ago

What I'd advise is to scrap off the old database, download the latest snapshot again, and sync it with --syncmode=full.

I ran a new bsc node with the latest snapshot and now I'm getting connecting to peers error.

I used geth-20231104.tar.lz4 snapshot and only copied /server/data-seed/geth/chaindata and /server/data-seed/geth/triecache directories into my data directory.

I'm using 1.2.13 bsc node and downloaded config and genesis files from here: https://github.com/bnb-chain/bsc/releases/tag/v1.2.13.

Geth parameters:

    - '--config'
    - /node/bsc/config/config.toml
    - '--datadir'
    - /node/data
    - '--rpc.allow-unprotected-txs'
    - '--syncmode'
    - full
    - '--http'
    - '--http.api'
    - eth,txpool,net,web3,engine
    - '--http.vhosts'
    - '*'
    - '--graphql.vhosts'
    - '*'
    - '--http.corsdomain'
    - '*'
    - '--graphql'
    - '--ws'
    - '--ws.api'
    - web3,eth
    - '--rpc.evmtimeout'
    - 15s
    - '--ws.origins'
    - '*'
    - '--verbosity'
    - '3'
    - '--cache'
    - '8000'
    - '--txlookuplimit'
    - '0'
    - '--tries-verify-mode'
    - none
    - '--ipcdisable'

Here's my config.toml file:

[Eth]
NetworkId = 56
LightPeers = 20
TrieTimeout = 150000000000

[Eth.Miner]
GasCeil = 140000000
GasPrice = 3000000000
Recommit = 10000000000

[Eth.TxPool]
Locals = []
NoLocals = true
Journal = "transactions.rlp"
Rejournal = 3600000000000
PriceLimit = 3000000000
PriceBump = 10
AccountSlots = 200
GlobalSlots = 8000
AccountQueue = 200
GlobalQueue = 4000

[Eth.GPO]
Blocks = 20
Percentile = 60
OracleThreshold = 1000

[Node]
IPCPath = "geth.ipc"
HTTPHost = "localhost"
InsecureUnlockAllowed = false
HTTPPort = 8545
HTTPVirtualHosts = ["localhost"]
HTTPModules = ["eth", "net", "web3", "txpool", "parlia"]
WSPort = 8546
WSModules = ["net", "web3", "eth"]

[Node.P2P]
MaxPeers = 40
NoDiscovery = false
StaticNodes = []
ListenAddr = ":30310"
EnableMsgEvents = false

net_peerCount response:

{
    "jsonrpc": "2.0",
    "id": 1,
    "result": "0x0"
}

eth_syncing response:

{
    "jsonrpc": "2.0",
    "id": 1,
    "result": {
        "currentBlock": "0xb442",
        "healedBytecodeBytes": "0x0",
        "healedBytecodes": "0x0",
        "healedTrienodeBytes": "0x0",
        "healedTrienodes": "0x0",
        "healingBytecode": "0x0",
        "healingTrienodes": "0x0",
        "highestBlock": "0xb4e8a1",
        "startingBlock": "0xb442",
        "syncedAccountBytes": "0x0",
        "syncedAccounts": "0x0",
        "syncedBytecodeBytes": "0x0",
        "syncedBytecodes": "0x0",
        "syncedStorage": "0x0",
        "syncedStorageBytes": "0x0"
    }
}

Logs with verbosity=3:

1.2.13 logs INFO [11-10|22:18:22.956] Maximum peer count ETH=50 LES=0 total=50 INFO [11-10|22:18:22.956] Smartcard socket not found, disabling err="stat /run/pcscd/pcscd.comm: no such file or directory" INFO [11-10|22:18:22.957] Set global gas cap cap=50,000,000 INFO [11-10|22:18:22.957] Allocated cache and file handles database=/bsc/geth.ipc/geth/chaindata cache=16.00MiB handles=16 INFO [11-10|22:18:22.962] Writing custom genesis block INFO [11-10|22:18:22.964] Persisted trie from memory database nodes=15 size=2.32KiB time="52.663µs" gcnodes=0 gcsize=0.00B gctime=0s livenodes=1 livesize=0.00B INFO [11-10|22:18:22.964] Successfully wrote genesis state database=chaindata hash=0d2184..d57b5b INFO [11-10|22:18:22.964] Allocated cache and file handles database=/bsc/geth.ipc/geth/lightchaindata cache=16.00MiB handles=16 INFO [11-10|22:18:22.970] Writing custom genesis block INFO [11-10|22:18:22.970] Persisted trie from memory database nodes=15 size=2.32KiB time="46.321µs" gcnodes=0 gcsize=0.00B gctime=0s livenodes=1 livesize=0.00B INFO [11-10|22:18:22.970] Successfully wrote genesis state database=lightchaindata hash=0d2184..d57b5b INFO [11-10|22:18:23.048] Starting Geth on Ethereum mainnet... INFO [11-10|22:18:23.049] Maximum peer count ETH=40 LES=0 total=40 INFO [11-10|22:18:23.049] Smartcard socket not found, disabling err="stat /run/pcscd/pcscd.comm: no such file or directory" WARN [11-10|22:18:23.050] Sanitizing cache to Go's GC limits provided=8000 updated=6811 INFO [11-10|22:18:23.053] Set global gas cap cap=50,000,000 INFO [11-10|22:18:23.053] Allocated trie memory caches clean=1021.00MiB dirty=1.66GiB INFO [11-10|22:18:23.053] Allocated cache and file handles database=/node/data/geth/chaindata cache=2.66GiB handles=524,288 INFO [11-10|22:18:23.993] AncientDB item count items=0 INFO [11-10|22:18:23.993] Opened ancient database database=/node/data/geth/chaindata/ancient readonly=false frozen=0 INFO [11-10|22:18:23.994] 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, Ramanujan: 0, Niels: 0, MirrorSync: 0, Bruno: 0, Berlin: 12244000, YOLO v3: , CatalystBlock: , London: 12965000, ArrowGlacier: 13773000, MergeFork:, Euler: 0, Gibbs: , Nano: , Moran: , Planck: ,Luban: , Plato: , Hertz: , Engine: ethash}" INFO [11-10|22:18:25.955] Unprotected transactions allowed INFO [11-10|22:18:25.955] Disk storage enabled for ethash caches dir=/node/data/geth/ethash count=3 INFO [11-10|22:18:25.955] Disk storage enabled for ethash DAGs dir=/bsc/.ethash count=2 INFO [11-10|22:18:25.956] Initialising Ethereum protocol network=56 dbversion=8 INFO [11-10|22:18:25.968] Loaded most recent local header number=46146 hash=5a41d0..038bfc td=42,682,691,795,132,124 age=8y4mo2w INFO [11-10|22:18:25.968] Loaded most recent local full block number=46146 hash=5a41d0..038bfc td=42,682,691,795,132,124 age=8y4mo2w INFO [11-10|22:18:25.968] Loaded most recent local fast block number=46146 hash=5a41d0..038bfc td=42,682,691,795,132,124 age=8y4mo2w INFO [11-10|22:18:25.973] Snapshot loaded diskRoot=d67e4d..532bf3 root=691fc4..128436 WARN [11-10|22:18:25.973] Sanitizing invalid txpool lifetime provided=0s updated=3h0m0s WARN [11-10|22:18:25.973] Sanitizing invalid txpool reannounce time provided=0s updated=1m0s WARN [11-10|22:18:25.973] Sanitizing invalid gasprice oracle price cap provided= updated=100,000,000,000 WARN [11-10|22:18:25.973] Sanitizing invalid gasprice oracle ignore price provided= updated=4 WARN [11-10|22:18:25.973] Sanitizing invalid gasprice oracle max header history provided=0 updated=1 WARN [11-10|22:18:25.973] Sanitizing invalid gasprice oracle max block history provided=0 updated=1 WARN [11-10|22:18:25.973] Subscribe for vote or finalized header event failed INFO [11-10|22:18:25.976] Starting peer-to-peer node instance=Geth/v1.2.13-4f82f18a/linux-amd64/go1.19.13 INFO [11-10|22:18:26.065] New local node record seq=1,699,652,206,795 id=37359206530f759d ip=127.0.0.1 udp=30310 tcp=30310 ERROR[11-10|22:18:26.066] Unavailable modules in HTTP API list unavailable=[engine] available="[admin debug web3 eth txpool personal ethash miner net]" INFO [11-10|22:18:26.067] HTTP server started endpoint=127.0.0.1:8545 prefix= cors=* vhosts=* INFO [11-10|22:18:26.067] GraphQL enabled url=http://127.0.0.1:8545/graphql INFO [11-10|22:18:26.067] GraphQL UI enabled url=http://127.0.0.1:8545/graphql/ui INFO [11-10|22:18:26.067] WebSocket enabled url=ws://127.0.0.1:8546 INFO [11-10|22:18:26.068] Started P2P networking self=enode://3a0c6f47a6544ca49a56de84298cf301f18b736baca341ae695c079b91b36411f741e57168436eed7c6e53fb016bccad8d6d257c5e8645b7899bd312f7c9de1e@127.0.0.1:30310 INFO [11-10|22:18:35.914] New local node record seq=1,699,652,206,796 id=37359206530f759d ip=54.164.8.1 udp=30310 tcp=30310 INFO [11-10|22:18:36.216] Looking for peers peercount=1 tried=133 static=0 WARN [11-10|22:18:39.598] Snapshot extension registration failed peer=450a16c3 err="peer connected on snap without compatible eth support" INFO [11-10|22:18:46.300] Looking for peers peercount=0 tried=59 static=0 ERROR[11-10|22:18:54.095] Bsc extension Handshake failed peer=7daf1131 err="read timeout" INFO [11-10|22:18:56.904] Looking for peers peercount=0 tried=111 static=0 INFO [11-10|22:19:06.912] Looking for peers peercount=0 tried=136 static=0 WARN [11-10|22:19:07.198] Snapshot extension registration failed peer=c6a68c50 err="peer connected on snap without compatible eth support" ERROR[11-10|22:19:11.985] Bsc extension Handshake failed peer=eef4e1e8 err="read timeout" WARN [11-10|22:19:14.994] Snapshot extension registration failed peer=7c9e16c2 err="peer connected on snap without compatible eth support" INFO [11-10|22:19:16.980] Looking for peers peercount=0 tried=185 static=0 INFO [11-10|22:19:27.051] Looking for peers peercount=1 tried=49 static=0 INFO [11-10|22:19:37.051] Looking for peers peercount=0 tried=167 static=0 INFO [11-10|22:19:47.136] Looking for peers peercount=1 tried=63 static=0 INFO [11-10|22:19:57.179] Looking for peers peercount=0 tried=52 static=0 INFO [11-10|22:20:07.359] Looking for peers peercount=0 tried=135 static=0 WARN [11-10|22:20:07.914] Snapshot extension registration failed peer=450a16c3 err="peer connected on snap without compatible eth support" WARN [11-10|22:20:10.127] Snapshot extension registration failed peer=48ec84b2 err="peer connected on snap without compatible eth support" INFO [11-10|22:20:17.614] Looking for peers peercount=0 tried=115 static=0 INFO [11-10|22:20:27.877] Looking for peers peercount=0 tried=26 static=0 INFO [11-10|22:20:37.889] Looking for peers peercount=2 tried=112 static=0 INFO [11-10|22:20:48.384] Looking for peers peercount=0 tried=199 static=0 WARN [11-10|22:20:50.232] Snapshot extension registration failed peer=1d4ddff1 err="peer connected on snap without compatible eth support" INFO [11-10|22:20:58.424] Looking for peers peercount=0 tried=164 static=0 INFO [11-10|22:21:08.552] Looking for peers peercount=1 tried=93 static=0 WARN [11-10|22:21:13.746] Snapshot extension registration failed peer=3decf86b err="peer connected on snap without compatible eth support" INFO [11-10|22:21:18.559] Looking for peers peercount=0 tried=40 static=0 INFO [11-10|22:21:28.568] Looking for peers peercount=1 tried=37 static=0 WARN [11-10|22:21:28.804] Snapshot extension registration failed peer=1d4fc8e3 err="peer connected on snap without compatible eth support" INFO [11-10|22:21:38.637] Looking for peers peercount=0 tried=54 static=0 INFO [11-10|22:21:48.640] Looking for peers peercount=1 tried=24 static=0 INFO [11-10|22:21:58.695] Looking for peers peercount=0 tried=190 static=0 WARN [11-10|22:22:05.267] Snapshot extension registration failed peer=d6e84626 err="peer connected on snap without compatible eth support" INFO [11-10|22:22:08.742] Looking for peers peercount=1 tried=11 static=0 INFO [11-10|22:22:19.010] Looking for peers peercount=1 tried=124 static=0 WARN [11-10|22:22:20.044] Snapshot extension registration failed peer=ddf20e83 err="peer connected on snap without compatible eth support" WARN [11-10|22:22:21.367] Snapshot extension registration failed peer=450a16c3 err="peer connected on snap without compatible eth support" WARN [11-10|22:22:24.936] Snapshot extension registration failed peer=77e9f1ea err="peer connected on snap without compatible eth support" INFO [11-10|22:22:29.185] Looking for peers peercount=1 tried=84 static=0 INFO [11-10|22:22:39.257] Looking for peers peercount=0 tried=91 static=0 WARN [11-10|22:22:46.345] Snapshot extension registration failed peer=c6a68c50 err="peer connected on snap without compatible eth support" INFO [11-10|22:22:49.468] Looking for peers peercount=1 tried=121 static=0 INFO [11-10|22:22:59.621] Looking for peers peercount=1 tried=132 static=0 INFO [11-10|22:23:09.651] Looking for peers peercount=2 tried=88 static=0 ERROR[11-10|22:23:12.602] Bsc extension Handshake failed peer=aae0ed11 err="read timeout" INFO [11-10|22:23:19.810] Looking for peers peercount=2 tried=122 static=0 INFO [11-10|22:23:29.818] Looking for peers peercount=0 tried=92 static=0 INFO [11-10|22:23:40.316] Looking for peers peercount=1 tried=133 static=0 WARN [11-10|22:23:40.778] Snapshot extension registration failed peer=450a16c3 err="peer connected on snap without compatible eth support" WARN [11-10|22:23:45.711] Snapshot extension registration failed peer=c6a68c50 err="peer connected on snap without compatible eth support" INFO [11-10|22:23:50.374] Looking for peers peercount=1 tried=241 static=0 INFO [11-10|22:24:01.042] Looking for peers peercount=0 tried=43 static=0 INFO [11-10|22:24:11.065] Looking for peers peercount=1 tried=93 static=0 WARN [11-10|22:24:14.214] Snapshot extension registration failed peer=953907a2 err="peer connected on snap without compatible eth support" INFO [11-10|22:24:21.105] Looking for peers peercount=0 tried=164 static=0 INFO [11-10|22:24:31.251] Looking for peers peercount=0 tried=99 static=0 INFO [11-10|22:24:41.252] Looking for peers peercount=0 tried=98 static=0 INFO [11-10|22:24:51.681] Looking for peers peercount=1 tried=97 static=0 INFO [11-10|22:24:57.164] Block synchronisation started ERROR[11-10|22:25:00.440] Bsc extension Handshake failed peer=d7aea09c err="read timeout" INFO [11-10|22:25:00.603] Downloader queue stats receiptTasks=0 blockTasks=283 itemSize=528.02B throttle=8192 ERROR[11-10|22:25:00.608] validate state failed error="invalid receipt root hash (remote: fe2bf2a941abf41d72637e5b91750332a30283efd40c424dc522b77e6f0ed8c4 local: c2ed11006d45b290f1f9326af8afc285a96789c8e9fd5f8b9ef04a6452fdc1fb)" INFO [11-10|22:25:00.608] Skip duplicated bad block number=46147 hash=4e3a37..5a1bdd ERROR[11-10|22:25:00.608] ########## BAD BLOCK ######### Chain 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, Ramanujan: 0, Niels: 0, MirrorSync: 0, Bruno: 0, Berlin: 12244000, YOLO v3: , CatalystBlock: , London: 12965000, ArrowGlacier: 13773000, MergeFork:, Euler: 0, Gibbs: , Nano: , Moran: , Planck: ,Luban: , Plato: , Hertz: , Engine: ethash} Number: 46147 Hash: 0x4e3a3754410177e6937ef1f84bba68ea139e8d1a2258c5f85db9f1cd715a1bdd 0: cumulative: 21000 gas: 21000 contract: 0x0000000000000000000000000000000000000000 status: 1 tx: 0x5c504ed432cb51138bcf09aa5e8a410dd4a1e204ef84bfed1be16dfba1b22060 logs: [] bloom: 00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 state: 0e0df2706b0a4fb8bd08c9246d472abbe850af446405d9eba1db41db18b4a169 Error: invalid receipt root hash (remote: fe2bf2a941abf41d72637e5b91750332a30283efd40c424dc522b77e6f0ed8c4 local: c2ed11006d45b290f1f9326af8afc285a96789c8e9fd5f8b9ef04a6452fdc1fb) ############################## WARN [11-10|22:25:00.608] Synchronisation failed, dropping peer peer=f92007ee936569cdff8c1189467c69d6af1d64356a9a7459bf0269806b7aa767 err="retrieved hash chain is invalid: invalid receipt root hash (remote: fe2bf2a941abf41d72637e5b91750332a30283efd40c424dc522b77e6f0ed8c4 local: c2ed11006d45b290f1f9326af8afc285a96789c8e9fd5f8b9ef04a6452fdc1fb)" INFO [11-10|22:25:01.682] Looking for peers peercount=0 tried=129 static=0 INFO [11-10|22:25:12.286] Looking for peers peercount=0 tried=69 static=0 INFO [11-10|22:25:23.363] Looking for peers peercount=0 tried=89 static=0 INFO [11-10|22:25:34.016] Looking for peers peercount=1 tried=222 static=0 INFO [11-10|22:25:44.900] Looking for peers peercount=1 tried=74 static=0 WARN [11-10|22:25:50.976] Snapshot extension registration failed peer=3af25a30 err="peer connected on snap without compatible eth support" WARN [11-10|22:25:52.290] Snapshot extension registration failed peer=450a16c3 err="peer connected on snap without compatible eth support" INFO [11-10|22:25:54.904] Looking for peers peercount=0 tried=193 static=0 INFO [11-10|22:26:05.077] Looking for peers peercount=0 tried=28 static=0 WARN [11-10|22:26:07.130] Snapshot extension registration failed peer=63e0d242 err="peer connected on snap without compatible eth support" WARN [11-10|22:26:12.238] Snapshot extension registration failed peer=c6a68c50 err="peer connected on snap without compatible eth support" WARN [11-10|22:26:13.454] Snapshot extension registration failed peer=c1e0a49a err="peer connected on snap without compatible eth support" INFO [11-10|22:26:15.090] Looking for peers peercount=0 tried=179 static=0 INFO [11-10|22:26:25.098] Looking for peers peercount=2 tried=126 static=0 WARN [11-10|22:26:25.126] Snapshot extension registration failed peer=48ec84b2 err="peer connected on snap without compatible eth support" WARN [11-10|22:26:25.255] Multiple headers for single request peer=48dad1f6 headers=0 WARN [11-10|22:26:25.255] Synchronisation failed, dropping peer peer=48dad1f621d6deb0d5d22376881a95437654e440eab31a38778754e27b1412e6 err="action from bad peer ignored: multiple headers (0) for single request" WARN [11-10|22:26:25.699] Snapshot extension registration failed peer=48ddf5d8 err="peer connected on snap without compatible eth support" INFO [11-10|22:26:35.348] Looking for peers peercount=1 tried=175 static=0 INFO [11-10|22:26:35.743] Downloader queue stats receiptTasks=0 blockTasks=86 itemSize=580.02B throttle=8192 ERROR[11-10|22:26:35.749] validate state failed error="invalid receipt root hash (remote: fe2bf2a941abf41d72637e5b91750332a30283efd40c424dc522b77e6f0ed8c4 local: c2ed11006d45b290f1f9326af8afc285a96789c8e9fd5f8b9ef04a6452fdc1fb)" INFO [11-10|22:26:35.749] Skip duplicated bad block number=46147 hash=4e3a37..5a1bdd ERROR[11-10|22:26:35.749] ########## BAD BLOCK ######### Chain 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, Ramanujan: 0, Niels: 0, MirrorSync: 0, Bruno: 0, Berlin: 12244000, YOLO v3: , CatalystBlock: , London: 12965000, ArrowGlacier: 13773000, MergeFork:, Euler: 0, Gibbs: , Nano: , Moran: , Planck: ,Luban: , Plato: , Hertz: , Engine: ethash} Number: 46147 Hash: 0x4e3a3754410177e6937ef1f84bba68ea139e8d1a2258c5f85db9f1cd715a1bdd 0: cumulative: 21000 gas: 21000 contract: 0x0000000000000000000000000000000000000000 status: 1 tx: 0x5c504ed432cb51138bcf09aa5e8a410dd4a1e204ef84bfed1be16dfba1b22060 logs: [] bloom: 00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 state: 0e0df2706b0a4fb8bd08c9246d472abbe850af446405d9eba1db41db18b4a169 Error: invalid receipt root hash (remote: fe2bf2a941abf41d72637e5b91750332a30283efd40c424dc522b77e6f0ed8c4 local: c2ed11006d45b290f1f9326af8afc285a96789c8e9fd5f8b9ef04a6452fdc1fb) ############################## WARN [11-10|22:26:35.750] Synchronisation failed, dropping peer peer=48c7bbeede02e9b61ba24301867c35dbe331a37ff647d534a4a76abbfb5369e3 err="retrieved hash chain is invalid: invalid receipt root hash (remote: fe2bf2a941abf41d72637e5b91750332a30283efd40c424dc522b77e6f0ed8c4 local: c2ed11006d45b290f1f9326af8afc285a96789c8e9fd5f8b9ef04a6452fdc1fb)" INFO [11-10|22:26:45.450] Looking for peers peercount=1 tried=98 static=0 WARN [11-10|22:26:47.984] Snapshot extension registration failed peer=450a16c3 err="peer connected on snap without compatible eth support" INFO [11-10|22:26:55.488] Looking for peers peercount=1 tried=192 static=0 INFO [11-10|22:27:05.536] Looking for peers peercount=0 tried=94 static=0 WARN [11-10|22:27:06.450] Snapshot extension registration failed peer=c6a68c50 err="peer connected on snap without compatible eth support" INFO [11-10|22:27:15.657] Looking for peers peercount=1 tried=93 static=0 INFO [11-10|22:27:25.933] Looking for peers peercount=1 tried=138 static=0 WARN [11-10|22:27:35.502] Snapshot extension registration failed peer=bfaaa73a err="peer connected on snap without compatible eth support" INFO [11-10|22:27:35.941] Looking for peers peercount=0 tried=115 static=0 INFO [11-10|22:27:45.988] Looking for peers peercount=0 tried=187 static=0 INFO [11-10|22:27:56.267] Looking for peers peercount=0 tried=89 static=0 WARN [11-10|22:27:56.397] Snapshot extension registration failed peer=450a16c3 err="peer connected on snap without compatible eth support" WARN [11-10|22:28:00.306] Snapshot extension registration failed peer=1d4fc8e3 err="peer connected on snap without compatible eth support" INFO [11-10|22:28:06.282] Looking for peers peercount=0 tried=192 static=0 INFO [11-10|22:28:16.454] Looking for peers peercount=1 tried=194 static=0 INFO [11-10|22:28:26.459] Looking for peers peercount=0 tried=64 static=0 INFO [11-10|22:28:32.230] Downloader queue stats receiptTasks=0 blockTasks=262 itemSize=585.14B throttle=8192 ERROR[11-10|22:28:32.234] validate state failed error="invalid receipt root hash (remote: fe2bf2a941abf41d72637e5b91750332a30283efd40c424dc522b77e6f0ed8c4 local: c2ed11006d45b290f1f9326af8afc285a96789c8e9fd5f8b9ef04a6452fdc1fb)" INFO [11-10|22:28:32.234] Skip duplicated bad block number=46147 hash=4e3a37..5a1bdd ERROR[11-10|22:28:32.234] ########## BAD BLOCK ######### Chain 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, Ramanujan: 0, Niels: 0, MirrorSync: 0, Bruno: 0, Berlin: 12244000, YOLO v3: , CatalystBlock: , London: 12965000, ArrowGlacier: 13773000, MergeFork:, Euler: 0, Gibbs: , Nano: , Moran: , Planck: ,Luban: , Plato: , Hertz: , Engine: ethash} Number: 46147 Hash: 0x4e3a3754410177e6937ef1f84bba68ea139e8d1a2258c5f85db9f1cd715a1bdd 0: cumulative: 21000 gas: 21000 contract: 0x0000000000000000000000000000000000000000 status: 1 tx: 0x5c504ed432cb51138bcf09aa5e8a410dd4a1e204ef84bfed1be16dfba1b22060 logs: [] bloom: 00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 state: 0e0df2706b0a4fb8bd08c9246d472abbe850af446405d9eba1db41db18b4a169 Error: invalid receipt root hash (remote: fe2bf2a941abf41d72637e5b91750332a30283efd40c424dc522b77e6f0ed8c4 local: c2ed11006d45b290f1f9326af8afc285a96789c8e9fd5f8b9ef04a6452fdc1fb) ############################## WARN [11-10|22:28:32.234] Synchronisation failed, dropping peer peer=c01903b846981445f42e04212d784ba260d7aacef1adcd0ba9a20c5cd7307990 err="retrieved hash chain is invalid: invalid receipt root hash (remote: fe2bf2a941abf41d72637e5b91750332a30283efd40c424dc522b77e6f0ed8c4 local: c2ed11006d45b290f1f9326af8afc285a96789c8e9fd5f8b9ef04a6452fdc1fb)" WARN [11-10|22:28:33.241] Snapshot extension registration failed peer=450a16c3 err="peer connected on snap without compatible eth support" INFO [11-10|22:28:36.466] Looking for peers peercount=0 tried=242 static=0 WARN [11-10|22:28:37.596] Snapshot extension registration failed peer=1d4ddff1 err="peer connected on snap without compatible eth support" INFO [11-10|22:28:46.725] Looking for peers peercount=0 tried=136 static=0 WARN [11-10|22:28:55.870] Snapshot extension registration failed peer=50942a79 err="peer connected on snap without compatible eth support" INFO [11-10|22:28:56.747] Looking for peers peercount=0 tried=84 static=0 INFO [11-10|22:29:06.780] Looking for peers peercount=0 tried=114 static=0 INFO [11-10|22:29:16.793] Looking for peers peercount=0 tried=48 static=0 INFO [11-10|22:29:26.829] Looking for peers peercount=0 tried=16 static=0 WARN [11-10|22:29:35.060] Snapshot extension registration failed peer=4637aa71 err="peer connected on snap without compatible eth support" INFO [11-10|22:29:36.881] Looking for peers peercount=0 tried=165 static=0 WARN [11-10|22:29:41.372] Snapshot extension registration failed peer=450a16c3 err="peer connected on snap without compatible eth support" WARN [11-10|22:29:41.673] Snapshot extension registration failed peer=b0c6a97a err="peer connected on snap without compatible eth support" INFO [11-10|22:29:47.083] Looking for peers peercount=1 tried=110 static=0 INFO [11-10|22:29:57.107] Looking for peers peercount=0 tried=158 static=0 WARN [11-10|22:30:02.773] Snapshot extension registration failed peer=4ba692d3 err="peer connected on snap without compatible eth support" INFO [11-10|22:30:07.129] Looking for peers peercount=1 tried=119 static=0 INFO [11-10|22:30:17.211] Looking for peers peercount=0 tried=17 static=0 WARN [11-10|22:30:21.218] Snapshot extension registration failed peer=07f28f75 err="peer connected on snap without compatible eth support" WARN [11-10|22:30:24.340] Snapshot extension registration failed peer=450a16c3 err="peer connected on snap without compatible eth support" INFO [11-10|22:30:27.281] Looking for peers peercount=0 tried=220 static=0 INFO [11-10|22:30:37.300] Looking for peers peercount=1 tried=97 static=0 WARN [11-10|22:30:41.488] Snapshot extension registration failed peer=3af25a30 err="peer connected on snap without compatible eth support" INFO [11-10|22:30:45.628] Downloader queue stats receiptTasks=0 blockTasks=260 itemSize=585.65B throttle=8192 ERROR[11-10|22:30:45.632] validate state failed error="invalid receipt root hash (remote: fe2bf2a941abf41d72637e5b91750332a30283efd40c424dc522b77e6f0ed8c4 local: c2ed11006d45b290f1f9326af8afc285a96789c8e9fd5f8b9ef04a6452fdc1fb)" INFO [11-10|22:30:45.632] Skip duplicated bad block number=46147 hash=4e3a37..5a1bdd ERROR[11-10|22:30:45.632] ########## BAD BLOCK ######### Chain 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, Ramanujan: 0, Niels: 0, MirrorSync: 0, Bruno: 0, Berlin: 12244000, YOLO v3: , CatalystBlock: , London: 12965000, ArrowGlacier: 13773000, MergeFork:, Euler: 0, Gibbs: , Nano: , Moran: , Planck: ,Luban: , Plato: , Hertz: , Engine: ethash} Number: 46147 Hash: 0x4e3a3754410177e6937ef1f84bba68ea139e8d1a2258c5f85db9f1cd715a1bdd 0: cumulative: 21000 gas: 21000 contract: 0x0000000000000000000000000000000000000000 status: 1 tx: 0x5c504ed432cb51138bcf09aa5e8a410dd4a1e204ef84bfed1be16dfba1b22060 logs: [] bloom: 00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 state: 0e0df2706b0a4fb8bd08c9246d472abbe850af446405d9eba1db41db18b4a169 Error: invalid receipt root hash (remote: fe2bf2a941abf41d72637e5b91750332a30283efd40c424dc522b77e6f0ed8c4 local: c2ed11006d45b290f1f9326af8afc285a96789c8e9fd5f8b9ef04a6452fdc1fb) ############################## WARN [11-10|22:30:45.632] Synchronisation failed, dropping peer peer=c01903b846981445f42e04212d784ba260d7aacef1adcd0ba9a20c5cd7307990 err="retrieved hash chain is invalid: invalid receipt root hash (remote: fe2bf2a941abf41d72637e5b91750332a30283efd40c424dc522b77e6f0ed8c4 local: c2ed11006d45b290f1f9326af8afc285a96789c8e9fd5f8b9ef04a6452fdc1fb)" INFO [11-10|22:30:48.009] Looking for peers peercount=0 tried=100 static=0 INFO [11-10|22:30:58.269] Looking for peers peercount=1 tried=78 static=0 WARN [11-10|22:30:59.941] Snapshot extension registration failed peer=c6a68c50 err="peer connected on snap without compatible eth support" ERROR[11-10|22:31:05.459] Bsc extension Handshake failed peer=d7a611f0 err="read timeout" INFO [11-10|22:31:08.359] Looking for peers peercount=0 tried=117 static=0 WARN [11-10|22:31:17.445] Snapshot extension registration failed peer=5081b3d4 err="peer connected on snap without compatible eth support" WARN [11-10|22:31:18.488] Snapshot extension registration failed peer=8067642d err="peer connected on snap without compatible eth support" INFO [11-10|22:31:18.488] Looking for peers peercount=1 tried=16 static=0 ERROR[11-10|22:31:25.674] Bsc extension Handshake failed peer=bbe0c174 err="read timeout" INFO [11-10|22:31:28.530] Looking for peers peercount=0 tried=76 static=0 INFO [11-10|22:31:38.531] Looking for peers peercount=0 tried=77 static=0 WARN [11-10|22:31:41.018] Snapshot extension registration failed peer=450a16c3 err="peer connected on snap without compatible eth support" WARN [11-10|22:31:42.114] Snapshot extension registration failed peer=4ba692d3 err="peer connected on snap without compatible eth support" INFO [11-10|22:31:48.550] Looking for peers peercount=2 tried=206 static=0 WARN [11-10|22:31:53.488] Snapshot extension registration failed peer=7a4f667f err="peer connected on snap without compatible eth support" INFO [11-10|22:31:58.600] Looking for peers peercount=0 tried=72 static=0 INFO [11-10|22:32:09.070] Looking for peers peercount=0 tried=23 static=0 INFO [11-10|22:32:19.079] Looking for peers peercount=0 tried=77 static=0 WARN [11-10|22:32:20.368] Snapshot extension registration failed peer=c6a68c50 err="peer connected on snap without compatible eth support" INFO [11-10|22:32:29.244] Looking for peers peercount=0 tried=76 static=0 WARN [11-10|22:32:30.584] Snapshot extension registration failed peer=450a16c3 err="peer connected on snap without compatible eth support" INFO [11-10|22:32:39.667] Looking for peers peercount=1 tried=97 static=0 WARN [11-10|22:32:48.960] Snapshot extension registration failed peer=63e0d242 err="peer connected on snap without compatible eth support" INFO [11-10|22:32:49.710] Looking for peers peercount=0 tried=111 static=0 WARN [11-10|22:32:56.804] Snapshot extension registration failed peer=42fea0e2 err="peer connected on snap without compatible eth support" WARN [11-10|22:32:57.032] Snapshot extension registration failed peer=bfd22e9c err="peer connected on snap without compatible eth support" WARN [11-10|22:32:57.390] Snapshot extension registration failed peer=bfaaa73a err="peer connected on snap without compatible eth support" WARN [11-10|22:32:58.852] Snapshot extension registration failed peer=e9f21729 err="peer connected on snap without compatible eth support" INFO [11-10|22:32:59.741] Looking for peers peercount=0 tried=131 static=0 WARN [11-10|22:33:01.476] Snapshot extension registration failed peer=5f67ba47 err="peer connected on snap without compatible eth support" WARN [11-10|22:33:09.520] Snapshot extension registration failed peer=c6a68c50 err="peer connected on snap without compatible eth support" INFO [11-10|22:33:09.755] Looking for peers peercount=0 tried=265 static=0 INFO [11-10|22:33:20.039] Looking for peers peercount=0 tried=185 static=0 INFO [11-10|22:33:30.057] Looking for peers peercount=1 tried=159 static=0 INFO [11-10|22:33:40.181] Looking for peers peercount=0 tried=142 static=0 WARN [11-10|22:33:47.131] Snapshot extension registration failed peer=c6a68c50 err="peer connected on snap without compatible eth support" INFO [11-10|22:33:50.546] Looking for peers peercount=1 tried=184 static=0 WARN [11-10|22:33:53.043] Snapshot extension registration failed peer=c9fd13e9 err="peer connected on snap without compatible eth support" WARN [11-10|22:34:00.150] Snapshot extension registration failed peer=450a16c3 err="peer connected on snap without compatible eth support" INFO [11-10|22:34:00.602] Looking for peers peercount=0 tried=147 static=0 INFO [11-10|22:34:10.606] Looking for peers peercount=0 tried=161 static=0 WARN [11-10|22:34:18.957] Snapshot extension registration failed peer=1fa04c2a err="peer connected on snap without compatible eth support" WARN [11-10|22:34:19.047] Snapshot extension registration failed peer=8cdeb12a err="peer connected on snap without compatible eth support" INFO [11-10|22:34:20.766] Looking for peers peercount=1 tried=79 static=0 INFO [11-10|22:34:30.826] Looking for peers peercount=0 tried=213 static=0 INFO [11-10|22:34:40.828] Looking for peers peercount=1 tried=269 static=0 WARN [11-10|22:34:47.050] Snapshot extension registration failed peer=5f67ba47 err="peer connected on snap without compatible eth support" WARN [11-10|22:34:48.172] Snapshot extension registration failed peer=0cae2994 err="peer connected on snap without compatible eth support" INFO [11-10|22:34:51.005] Looking for peers peercount=0 tried=75 static=0 INFO [11-10|22:35:01.437] Looking for peers peercount=0 tried=174 static=0 WARN [11-10|22:35:07.117] Snapshot extension registration failed peer=450a16c3 err="peer connected on snap without compatible eth support" WARN [11-10|22:35:08.824] Multiple headers for single request peer=48dad1f6 headers=0 WARN [11-10|22:35:08.824] Synchronisation failed, dropping peer peer=48dad1f621d6deb0d5d22376881a95437654e440eab31a38778754e27b1412e6 err="action from bad peer ignored: multiple headers (0) for single request" INFO [11-10|22:35:11.522] Looking for peers peercount=0 tried=106 static=0 INFO [11-10|22:35:22.006] Looking for peers peercount=0 tried=204 static=0 INFO [11-10|22:35:32.092] Looking for peers peercount=0 tried=209 static=0 INFO [11-10|22:35:42.104] Looking for peers peercount=0 tried=110 static=0 WARN [11-10|22:35:47.084] Snapshot extension registration failed peer=101502b5 err="peer connected on snap without compatible eth support" WARN [11-10|22:35:51.390] Snapshot extension registration failed peer=450a16c3 err="peer connected on snap without compatible eth support" INFO [11-10|22:35:52.111] Looking for peers peercount=1 tried=190 static=0 INFO [11-10|22:36:02.115] Looking for peers peercount=0 tried=245 static=0 INFO [11-10|22:36:12.142] Looking for peers peercount=0 tried=87 static=0 INFO [11-10|22:36:22.176] Looking for peers peercount=0 tried=24 static=0 INFO [11-10|22:36:33.261] Looking for peers peercount=0 tried=125 static=0 INFO [11-10|22:36:43.422] Looking for peers peercount=1 tried=70 static=0 INFO [11-10|22:36:53.491] Looking for peers peercount=0 tried=45 static=0 INFO [11-10|22:37:03.620] Looking for peers peercount=0 tried=116 static=0 ERROR[11-10|22:37:13.424] Bsc extension Handshake failed peer=d7a611f0 err="read timeout" INFO [11-10|22:37:13.729] Looking for peers peercount=0 tried=159 static=0 INFO [11-10|22:37:23.876] Looking for peers peercount=1 tried=128 static=0 WARN [11-10|22:37:32.897] Snapshot extension registration failed peer=450a16c3 err="peer connected on snap without compatible eth support" INFO [11-10|22:37:33.920] Looking for peers peercount=1 tried=157 static=0 WARN [11-10|22:37:38.083] Snapshot extension registration failed peer=c6a68c50 err="peer connected on snap without compatible eth support" INFO [11-10|22:37:43.927] Looking for peers peercount=0 tried=158 static=0 INFO [11-10|22:37:53.928] Looking for peers peercount=0 tried=30 static=0 INFO [11-10|22:38:03.945] Looking for peers peercount=0 tried=154 static=0 INFO [11-10|22:38:13.984] Looking for peers peercount=0 tried=52 static=0 WARN [11-10|22:38:20.836] Snapshot extension registration failed peer=450a16c3 err="peer connected on snap without compatible eth support" INFO [11-10|22:38:23.985] Looking for peers peercount=1 tried=162 static=0 INFO [11-10|22:38:33.998] Looking for peers peercount=1 tried=196 static=0 INFO [11-10|22:38:44.018] Looking for peers peercount=1 tried=197 static=0 INFO [11-10|22:38:54.791] Looking for peers peercount=1 tried=88 static=0 INFO [11-10|22:39:04.969] Looking for peers peercount=1 tried=73 static=0 INFO [11-10|22:39:15.236] Looking for peers peercount=0 tried=50 static=0 WARN [11-10|22:39:18.923] Synchronisation failed, dropping peer peer=36443600717926505df5ae5dc7abb284f3a5c5c8b1f9f4973b5327cdd51834ed err=timeout WARN [11-10|22:39:24.416] Snapshot extension registration failed peer=4454199d err="peer connected on snap without compatible eth support" INFO [11-10|22:39:25.581] Looking for peers peercount=0 tried=105 static=0 INFO [11-10|22:39:36.247] Looking for peers peercount=0 tried=131 static=0
weiihann commented 10 months ago

INFO [11-10|22:18:23.994] 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, Ramanujan: 0, Niels: 0, MirrorSync: 0, Bruno: 0, Berlin: 12244000, YOLO v3: , CatalystBlock: , London: 12965000, ArrowGlacier: 13773000, MergeFork:, Euler: 0, Gibbs: , Nano: , Moran: , Planck: ,Luban: , Plato: , Hertz: , Engine: ethash}"

This log states that you're running ChainID of 1, which is the ETH mainnet. Also, the other config fields seem off. You may double check if the config file has been placed in the correct directory.

morzhanov commented 10 months ago

This log states that you're running ChainID of 1, which is the ETH mainnet. Also, the other config fields seem off. You may double check if the config file has been placed in the correct directory.

I think config.toml location is correct and it is the same as in the geth argument. I tried to add WrongConfigValue to the config and now my bsc node is failing to start:

INFO [11-11|12:34:55.193] Maximum peer count                       ETH=50 LES=0 total=50
INFO [11-11|12:34:55.193] Smartcard socket not found, disabling    err="stat /run/pcscd/pcscd.comm: no such file or directory"
INFO [11-11|12:34:55.193] Set global gas cap                       cap=50,000,000
INFO [11-11|12:34:55.193] Allocated cache and file handles         database=/bsc/geth.ipc/geth/chaindata cache=16.00MiB handles=16
INFO [11-11|12:34:55.200] Writing custom genesis block 
INFO [11-11|12:34:55.201] Persisted trie from memory database      nodes=15 size=2.32KiB time="59.472µs" gcnodes=0 gcsize=0.00B gctime=0s livenodes=1 livesize=0.00B
INFO [11-11|12:34:55.201] Successfully wrote genesis state         database=chaindata                    hash=0d2184..d57b5b
INFO [11-11|12:34:55.201] Allocated cache and file handles         database=/bsc/geth.ipc/geth/lightchaindata cache=16.00MiB handles=16
INFO [11-11|12:34:55.207] Writing custom genesis block 
INFO [11-11|12:34:55.208] Persisted trie from memory database      nodes=15 size=2.32KiB time="38.623µs" gcnodes=0 gcsize=0.00B gctime=0s livenodes=1 livesize=0.00B
INFO [11-11|12:34:55.208] Successfully wrote genesis state         database=lightchaindata                    hash=0d2184..d57b5b
INFO [11-11|12:34:55.296] Starting Geth on Ethereum mainnet... 
Fatal: /node/bsc/config/config.toml, line 4: field 'WrongConfigValue' is not defined in ethconfig.Config, see https://godoc.org/github.com/ethereum/go-ethereum/eth/ethconfig#Config for available fields
Fatal: /node/bsc/config/config.toml, line 4: field 'WrongConfigValue' is not defined in ethconfig.Config, see https://godoc.org/github.com/ethereum/go-ethereum/eth/ethconfig#Config for available fields

Here's chunk of genesis.json file, here chainId also set to 56:

{
  "config": {
    "chainId": 56,
    "homesteadBlock": 0,
    "eip150Block": 0,
    "eip150Hash": "0x0000000000000000000000000000000000000000000000000000000000000000",
    "eip155Block": 0,
    "eip158Block": 0,
    "byzantiumBlock": 0,
    "constantinopleBlock": 0,    "petersburgBlock": 0,    "istanbulBlock": 0,    "muirGlacierBlock": 0,    "ramanujanBlock": 0,    "nielsBlock": 0,    "parlia": {      "period": 3,      "ep$
  "gasLimit": "0x2625a00",
  "difficulty": "0x1",
  "mixHash": "0x0000000000000000000000000000000000000000000000000000000000000000",
  "coinbase": "0xffffFFFfFFffffffffffffffFfFFFfffFFFfFFfE",

So I guess the node read the config correctly, but I'm not sure why ChainID: 1 is in the logs.

Also, you can see that network=56 and I'm only setting this value in the config.toml

INFO [11-11|13:23:42.431] Initialising Ethereum protocol           network=56 dbversion=8
weiihann commented 9 months ago

I didn't manage to reproduce the issue and was able to get my node up and running from scratch. Let me just post the exact steps that I did here:

  1. Extract the latest snapshot

    wget -q -O - <snapshot URL> | tar -I lz4 -xvf -

  2. Get the config and genesis files

    wget   $(curl -s https://api.github.com/repos/bnb-chain/bsc/releases/latest |grep browser_ |grep mainnet |cut -d\" -f4)
unzip mainnet.zip

  3. Run the node

    ./server/bsc --config server/config.toml --cache 5000 --pprof --pprof.port 6071 --metrics --allow-insecure-unlock --txlookuplimit 0 --ws.port 8545 --rpc.allow-unprotected-txs --ws --datadir server/data-seed --http.corsdomain *

Do check again if any of the steps differ from yours (aside from the difference in command line flags, that shouldn't be the cause of the issue). If something seems odd, we can work together to solve it.

morzhanov commented 9 months ago

I didn't manage to sync node using this snapshot: https://pub-c0627345c16f47ab858c9469133073a8.r2.dev/geth-20231114.tar.lz4 because of the issue that I've described in my previous message.

But I did manage to sync it using a secondary snapshot from here: https://github.com/48Club/bsc-snapshots#geth-full-node.

I think you were right - the main issue why the previous node sync attempt with the unofficial snapshot stuck for 2 weeks is because of the snap sync parameter. When I started it with full sync from the beginning it managed to sync after 2 days.

weiihann commented 9 months ago

Awesome! :)