bnb-chain / bsc

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

BSC node can't sync the new block #162

Closed 1b1og-com closed 3 years ago

1b1og-com commented 3 years ago

eth.syncing { currentBlock: 6784288, highestBlock: 6784407, knownStates: 133873248, pulledStates: 133865063, startingBlock: 6783739 } eth.blockNumber 0

1b1og-com commented 3 years ago

this is bsc log t=2021-04-22T18:12:33+0800 lvl=info msg="Imported new block headers" count=1 elapsed=452.972µs number=6784423 hash=0xbeb0d038cbf21c40545999bba37a546bd120e9291e3252abc1597c29c7e557a0 t=2021-04-22T18:12:33+0800 lvl=info msg="Imported new state entries" count=993 elapsed=2.396ms processed=133910127 pending=40211 retry=70 duplicate=39 unexpected=4366 t=2021-04-22T18:12:34+0800 lvl=info msg="Imported new state entries" count=1166 elapsed=2.437ms processed=133911293 pending=39991 retry=70 duplicate=39 unexpected=4366 t=2021-04-22T18:12:35+0800 lvl=info msg="Imported new state entries" count=1105 elapsed=2.242ms processed=133912398 pending=39910 retry=70 duplicate=39 unexpected=4366 t=2021-04-22T18:12:36+0800 lvl=info msg="Imported new state entries" count=925 elapsed=1.680ms processed=133913323 pending=40460 retry=0 duplicate=39 unexpected=4366 t=2021-04-22T18:12:36+0800 lvl=info msg="Imported new state entries" count=1092 elapsed=3.503ms processed=133914415 pending=39419 retry=58 duplicate=39 unexpected=4366 t=2021-04-22T18:12:37+0800 lvl=info msg="Imported new block headers" count=2 elapsed=971.39µs number=6784425 hash=0xcdf221668b1f3bca8af3e10166d5b40f70cea94d3f4a00f7e6202ee10c3c1652 t=2021-04-22T18:12:37+0800 lvl=info msg="Imported new state entries" count=755 elapsed=1.953ms processed=133915170 pending=39954 retry=116 duplicate=39 unexpected=4366 t=2021-04-22T18:12:38+0800 lvl=info msg="Imported new state entries" count=879 elapsed=2.513ms processed=133916049 pending=39505 retry=151 duplicate=39 unexpected=4366 t=2021-04-22T18:12:39+0800 lvl=info msg="Imported new state entries" count=680 elapsed=1.575ms processed=133916729 pending=39828 retry=4 duplicate=39 unexpected=4366 t=2021-04-22T18:12:40+0800 lvl=info msg="Imported new block headers" count=1 elapsed=428.76µs number=6784426 hash=0x8366967d5af37c03353176e3710189027894394311bc6403853166561dfd756e t=2021-04-22T18:12:40+0800 lvl=info msg="Imported new block headers" count=1 elapsed=391.428µs number=6784427 hash=0x58557834404c684ef692e4f1f589c2bdb963cb94a04d83438d43bad77e8c69a6 t=2021-04-22T18:12:40+0800 lvl=info msg="Imported new state entries" count=809 elapsed=1.288ms processed=133917538 pending=41141 retry=156 duplicate=39 unexpected=4366 t=2021-04-22T18:12:41+0800 lvl=info msg="Imported new state entries" count=387 elapsed=627.89µs processed=133917925 pending=42649 retry=1 duplicate=39 unexpected=4366 t=2021-04-22T18:12:44+0800 lvl=info msg="Imported new state entries" count=1441 elapsed=3.990ms processed=133919366 pending=41706 retry=3 duplicate=39 unexpected=4366 t=2021-04-22T18:12:44+0800 lvl=info msg="Imported new block headers" count=1 elapsed=433.053µs number=6784428 hash=0xb3911273b4edf945935fb0ea0210b707a8a4a5612e6d56cdbb0334e2cdf19f94 t=2021-04-22T18:12:44+0800 lvl=info msg="Imported new state entries" count=1019 elapsed=2.815ms processed=133920385 pending=41334 retry=10 duplicate=39 unexpected=4366 t=2021-04-22T18:12:45+0800 lvl=info msg="Imported new state entries" count=836 elapsed=3.937ms processed=133921221 pending=41848 retry=0 duplicate=39 unexpected=4366 t=2021-04-22T18:12:46+0800 lvl=info msg="Imported new state entries" count=1100 elapsed=3.169ms processed=133922321 pending=40889 retry=51 duplicate=39 unexpected=4366

psdlt commented 3 years ago

You gotta wait, it's still syncing. You're like halfway there.

1b1og-com commented 3 years ago

You gotta wait, it's still syncing. You're like halfway there.

@psdlt It's been 100 blocks away for a week what can i do?

psdlt commented 3 years ago

@1b1og-com yea, sorry, i saw processed=133... and though you just started syncing, as currently there are ~200M state entries. I have similar issue, my geth client seems to always stay behind by ~3 minutes and after some time it just stops doing anything. Don't have a solution, sorry.

issaxyz commented 3 years ago

@psdlt similar issue here. I've to restart the geth, mostly, the height start grew again. I've tried and verified that, If you didn't expose the p2p port to internet, it seems happen more frequently. Appears like the status of the bsc peer network isn't good enough.

1b1og-com commented 3 years ago

@psdlt similar issue here. I've to restart the geth, mostly, the height start grew again. I've tried and verified that, If you didn't expose the p2p port to internet, it seems happen more frequently. Appears like the status of the bsc peer network isn't good enough.

@issaxyz can you help me? what's step? why i can't sync the new bsc block and eth_blocknumber is 0

psdlt commented 3 years ago

@issaxyz yea, after several restarts my geth caught up with the network and was stable for the past couple days.

psdlt commented 3 years ago

@1b1og-com 2 days ago state count was ~237M:

t=2021-04-23T03:31:29+0000 lvl=info msg="Imported new state entries"            count=583  elapsed=2.336ms   processed=237263917 pending=803    retry=0    duplicate=9535 unexpected=134561
t=2021-04-23T03:31:30+0000 lvl=info msg="Imported new state entries"            count=479  elapsed=4.725ms   processed=237264396 pending=0      retry=0    duplicate=9535 unexpected=134561

what's your eth.syncing? what hardware are you running your geth on?

1b1og-com commented 3 years ago

look

@1b1og-com 2 days ago state count was ~237M:

t=2021-04-23T03:31:29+0000 lvl=info msg="Imported new state entries"            count=583  elapsed=2.336ms   processed=237263917 pending=803    retry=0    duplicate=9535 unexpected=134561
t=2021-04-23T03:31:30+0000 lvl=info msg="Imported new state entries"            count=479  elapsed=4.725ms   processed=237264396 pending=0      retry=0    duplicate=9535 unexpected=134561

what's your eth.syncing? what hardware are you running your geth on?

look this

│> eth.syncing
{
  currentBlock: 6866290,
  highestBlock: 6866355,
  knownStates: 217406692,
  pulledStates: 217396756,
  startingBlock: 6866217
}

./geth --datadir datadir --config config.toml --pprofaddr 0.0.0.0 --metrics --pprof --syncmode=fast --gcmode=archive --nousb

t=2021-04-25T15:20:29+0800 lvl=info msg="Imported new block headers"          count=1    elapsed=447.321µs number=6866450 hash=0x2214b0c5930798adc2577302d9002d7d3692553664e65832ce4998e03e7bb64a
t=2021-04-25T15:20:29+0800 lvl=info msg="Imported new state entries"          count=458  elapsed=1.428ms   processed=217476371 pending=9296  retry=0   duplicate=4 unexpected=401
t=2021-04-25T15:20:32+0800 lvl=info msg="Imported new state entries"          count=872  elapsed=5.287ms   processed=217477243 pending=9503  retry=192 duplicate=4 unexpected=401
t=2021-04-25T15:20:32+0800 lvl=info msg="Initializing fast sync bloom"        items=167227635 errorrate=0.000 elapsed=8m48.882s
t=2021-04-25T15:20:34+0800 lvl=info msg="Imported new state entries"          count=384  elapsed=1.217ms   processed=217477627 pending=10006 retry=2   duplicate=4 unexpected=401
t=2021-04-25T15:20:35+0800 lvl=info msg="Imported new block headers"          count=2    elapsed=1.113ms   number=6866452 hash=0x512d517089560370921302462ce8f6d2bb25a55fcb26ad25988a5dfbbe1bae7f
t=2021-04-25T15:20:37+0800 lvl=info msg="Imported new state entries"          count=384  elapsed=977.518µs processed=217478011 pending=10655 retry=0   duplicate=4 unexpected=401
t=2021-04-25T15:20:39+0800 lvl=info msg="Imported new block headers"          count=1    elapsed=533.907µs number=6866453 hash=0x552d81e7a8be9f63178ed40f5eeb1153dc6a35ef8562c2bd17ea39e191f5ccf5
t=2021-04-25T15:20:40+0800 lvl=info msg="Initializing fast sync bloom"        items=174298789 errorrate=0.000 elapsed=8m56.882s
t=2021-04-25T15:20:41+0800 lvl=info msg="Imported new state entries"          count=1153 elapsed=6.086ms   processed=217479164 pending=10466 retry=0   duplicate=4 unexpected=401
t=2021-04-25T15:20:42+0800 lvl=info msg="Imported new block headers"          count=1    elapsed=544.292µs number=6866454 hash=0x4a43230945589e8fc8bb70a41bcddd80365bb726717e11cd2f84c32e8719cc6b
t=2021-04-25T15:20:43+0800 lvl=warn msg="Stalling state sync, dropping peer"  peer=9ea09b238aae926c
t=2021-04-25T15:20:44+0800 lvl=info msg="Imported new state entries"          count=826  elapsed=5.736ms   processed=217479990 pending=9967  retry=148 duplicate=4 unexpected=401
t=2021-04-25T15:20:45+0800 lvl=info msg="Imported new block headers"          count=2    elapsed=1.776ms   number=6866456 hash=0xa10d33447d5e76967a509871314e77a9028e9bc496f1a0cebef025cfa53f378c
t=2021-04-25T15:20:46+0800 lvl=info msg="Imported new state entries"          count=844  elapsed=5.412ms   processed=217480834 pending=9575  retry=0   duplicate=4 unexpected=401
t=2021-04-25T15:20:48+0800 lvl=info msg="Initializing fast sync bloom"        items=181431418 errorrate=0.000 elapsed=9m4.882s
t=2021-04-25T15:20:49+0800 lvl=info msg="Imported new state entries"          count=781  elapsed=26.961ms  processed=217481615 pending=9726  retry=2   duplicate=4 unexpected=401
t=2021-04-25T15:20:52+0800 lvl=info msg="Imported new block headers"          count=2    elapsed=1.495ms   number=6866458 hash=0xff8d73818481cae5ca518412aac052a8a4263ed301d4f83da994a2077749a5ad
t=2021-04-25T15:20:52+0800 lvl=info msg="Imported new state entries"          count=1157 elapsed=6.677ms   processed=217482772 pending=9238  retry=2   duplicate=4 unexpected=401
t=2021-04-25T15:20:54+0800 lvl=info msg="Imported new state entries"          count=386  elapsed=3.035ms   processed=217483158 pending=9041  retry=0   duplicate=4 unexpected=401
t=2021-04-25T15:20:55+0800 lvl=info msg="Imported new block headers"          count=1    elapsed=774.99µs  number=6866459 hash=0xe6a3f12549105f78d73524ccf2059b79062c020802b489a85de594c042a7a997
t=2021-04-25T15:20:56+0800 lvl=info msg="Initializing fast sync bloom"        items=188511532 errorrate=0.000 elapsed=9m12.882s
t=2021-04-25T15:20:57+0800 lvl=info msg="Imported new state entries"          count=769  elapsed=5.908ms   processed=217483927 pending=8860  retry=2   duplicate=4 unexpected=401
t=2021-04-25T15:20:58+0800 lvl=info msg="Imported new block headers"          count=1    elapsed=642.056µs number=6866460 hash=0x919a33d99e741d6c342679735aafac573a57da2a3c3baf08ee43a6c35dda9001
t=2021-04-25T15:21:00+0800 lvl=info msg="Imported new state entries"          count=770  elapsed=4.483ms   processed=217484697 pending=9136  retry=0   duplicate=4 unexpected=401
t=2021-04-25T15:21:02+0800 lvl=info msg="Imported new state entries"          count=1153 elapsed=6.790ms   processed=217485850 pending=8787  retry=2   duplicate=4 unexpected=401
t=2021-04-25T15:21:04+0800 lvl=info msg="Imported new block headers"          count=2    elapsed=825.606µs number=6866462 hash=0x60cd44c8bcb1d47e6e0c41bcec9ea100bf11d9f2e5e0bf69b4ca1c7db757bb24
t=2021-04-25T15:21:04+0800 lvl=info msg="Initializing fast sync bloom"        items=195636065 errorrate=0.000 elapsed=9m20.882s
t=2021-04-25T15:21:06+0800 lvl=info msg="Imported new state entries"          count=774  elapsed=3.902ms   processed=217486624 pending=8972  retry=3   duplicate=4 unexpected=401
t=2021-04-25T15:21:07+0800 lvl=info msg="Imported new block headers"          count=1    elapsed=515.842µs number=6866463 hash=0x5479e5857b1fc85009e52c7daa0bb8fe3e238d9ecd7e337076cec983fe72cdab
t=2021-04-25T15:21:07+0800 lvl=info msg="Imported new state entries"          count=384  elapsed=2.310ms   processed=217487008 pending=8996  retry=2   duplicate=4 unexpected=401
t=2021-04-25T15:21:10+0800 lvl=info msg="Imported new block headers"          count=1    elapsed=1.290ms   number=6866464 hash=0x6d9c42e859392da68a6cac8f65a6165597a78dbe7c910b83d83fd123e587ceb5
1b1og-com commented 3 years ago

@psdlt can you find problem ?

1b1og-com commented 3 years ago

i need used eth_blocknumber data, but return 0, It's terrible.

psdlt commented 3 years ago

@1b1og-com your geth is still syncing. Currently you're at 217M state entries; 2 days ago there were 237M, so you're behind by quite a lot. BTW, are you building an archive node? Why do you have --gcmode=archive in your options? What hardware are you running your geth on?

1b1og-com commented 3 years ago

@1b1og-com your geth is still syncing. Currently you're at 217M state entries; 2 days ago there were 237M, so you're behind by quite a lot. BTW, are you building an archive node? Why do you have --gcmode=archive in your options? What hardware are you running your geth on?

@psdlt I need to serve to graph-node, so I need to use --syncmode=fast --gcmode=archive But it's strange, that both Ethnet and heconet are OK

1b1og-com commented 3 years ago

@psdlt @issaxyz @fjl @holiman any body here?

1b1og-com commented 3 years ago

@huangsuyu

holiman commented 3 years ago

I have zero affiliation with bsc, please don't @ me.

1b1og-com commented 3 years ago

my wechat is wu4yyy, Let's discuss it together @issaxyz @psdlt @fjl @HaoyangLiu

stillnaughty commented 3 years ago

I have similar issue as well. Always ~100 blocks behind Is there anybody have any progress so far? Is it the reason that the machine is not fast enough? But the case is I'm using the new M1 mac mini already... Stuck the syncing process for almost a week already. Should be the problem on state sync

heliosVII-tech commented 3 years ago

I haven’t had any issues at all. You definitely need good hardware. I9+/AMD equivalent, an NVME SSD, 16GB+ of memory, and 100Mb/s or faster Internet. Another thing that could help is increasing your maximum number of peers. Also, setting Syncmode=“fast” in config.toml can help a lot

chainwhisper commented 3 years ago

@psdlt @stillnaughty @1b1og-com

Please update your static nodes to increase connectivity

StaticNodes = ["enode://f56dcbe59ddcf52e2abe5d5f5fded28bf823e7e2fb887cebbfe3c540ed0dfbbd778872e6b0c9c6243fcb79fdf3e1805ae98a7c389091e9cc55bfe6dedfce04b8@3.115.208.145:30311","enode://b4feb14a8247917f25a4603a0a3a58827e6e3954fa1fc0499f3e084476dcb2dc32e444e7c51cecbc1066d2c94062fc16aa80da1a008c94e576b67b84a3a111c5@13.112.103.141:30311","enode://7fed0d5ebfec2d68106cf91d4bbf2c794a22f12a11c18ef643818e8b8a5022f63abccfa50cb34fd30343530f67a70523525d94247b4f8d143dca7524d2ba8630@52.194.28.137:30311","enode://64e87612bf91e145e019a2cf877891973151ba0acfe822346d5f6876feb4b031f80b6ff2334d9fccc7522d4c27f4a0003cfc29e20db25f6eb89fc72f5d058d89@99.80.96.58:30311","enode://c67e08daecbef6e78832a1fb7eef09725ee6671aeb6dd63cd880b9a2075b945df64b4a6181bf8ed31d43bd7b77587c5380d61095e6d7989e3880656b2fb9448d@54.76.80.25:30311","enode://45ad31700cfd9bce487b912d4b10d8f657a6b4a12f46a71707a351f350a28ea9183fe38f8e4cbd4371972bd6f096072fa65bcf59c0ffb719a8ef83f403b4d656@52.18.62.124:30311","enode://935d02d00d9c5ecdc3bee7a56201eb68c9a9e2fc684ff1e606d56bebcb45722b3812df2c408bd74495140b92214e4bd28a00853641e581cbc3ebbe6ee6b2f794@50.17.94.194:30311","enode://8e68f76aef70929084fbcdc527357aa97cf0091ed80639ba8e5c35933e50034c22a0c6d30775ec9bfdeef21fc029bb895ac2221b97e1595d35110a5a27589089@54.157.26.59:30311","enode://3da255f8abdeaafe3e8acd8e861314782aec365216948f203b5da5fa5457e92ac7dd7519e2e95487d99d7158a1b47e276c6a23efefbe8da423dfe090578d3bec@3.218.173.35:30311"]
cbosss commented 3 years ago

Having the same issue. @huangsuyu setting those static nodes didn't make a difference.

> cat config.toml

[Eth]
NetworkId = 56
NoPruning = false
NoPrefetch = false
LightPeers = 100
UltraLightFraction = 75
TrieTimeout = 100000000000
EnablePreimageRecording = false
EWASMInterpreter = ""
EVMInterpreter = ""

[Eth.Miner]
GasFloor = 30000000
GasCeil = 40000000
GasPrice = 1000000000
Recommit = 10000000000
Noverify = false

[Eth.TxPool]
Locals = []
NoLocals = true
Journal = "transactions.rlp"
Rejournal = 3600000000000
PriceLimit = 1000000000
PriceBump = 10
AccountSlots = 512
GlobalSlots = 10000
AccountQueue = 256
GlobalQueue = 5000
Lifetime = 10800000000000

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

[Node.P2P]
MaxPeers = 1000
NoDiscovery = false
BootstrapNodes = ["enode://1cc4534b14cfe351ab740a1418ab944a234ca2f702915eadb7e558a02010cb7c5a8c295a3b56bcefa7701c07752acd5539cb13df2aab8ae2d98934d712611443@52.71.43.172:30311","enode://28b1d16562dac280dacaaf45d54516b85bc6c994252a9825c5cc4e080d3e53446d05f63ba495ea7d44d6c316b54cd92b245c5c328c37da24605c4a93a0d099c4@34.246.65.14:30311","enode://5a7b996048d1b0a07683a949662c87c09b55247ce774aeee10bb886892e586e3c604564393292e38ef43c023ee9981e1f8b335766ec4f0f256e57f8640b079d5@35.73.137.11:30311"]
StaticNodes = ["enode://f56dcbe59ddcf52e2abe5d5f5fded28bf823e7e2fb887cebbfe3c540ed0dfbbd778872e6b0c9c6243fcb79fdf3e1805ae98a7c389091e9cc55bfe6dedfce04b8@3.115.208.145:30311","enode://b4feb14a8247917f25a4603a0a3a58827e6e3954fa1fc0499f3e084476dcb2dc32e444e7c51cecbc1066d2c94062fc16aa80da1a008c94e576b67b84a3a111c5@13.112.103.141:30311","enode://7fed0d5ebfec2d68106cf91d4bbf2c794a22f12a11c18ef643818e8b8a5022f63abccfa50cb34fd30343530f67a70523525d94247b4f8d143dca7524d2ba8630@52.194.28.137:30311","enode://64e87612bf91e145e019a2cf877891973151ba0acfe822346d5f6876feb4b031f80b6ff2334d9fccc7522d4c27f4a0003cfc29e20db25f6eb89fc72f5d058d89@99.80.96.58:30311","enode://c67e08daecbef6e78832a1fb7eef09725ee6671aeb6dd63cd880b9a2075b945df64b4a6181bf8ed31d43bd7b77587c5380d61095e6d7989e3880656b2fb9448d@54.76.80.25:30311","enode://45ad31700cfd9bce487b912d4b10d8f657a6b4a12f46a71707a351f350a28ea9183fe38f8e4cbd4371972bd6f096072fa65bcf59c0ffb719a8ef83f403b4d656@52.18.62.124:30311","enode://935d02d00d9c5ecdc3bee7a56201eb68c9a9e2fc684ff1e606d56bebcb45722b3812df2c408bd74495140b92214e4bd28a00853641e581cbc3ebbe6ee6b2f794@50.17.94.194:30311","enode://8e68f76aef70929084fbcdc527357aa97cf0091ed80639ba8e5c35933e50034c22a0c6d30775ec9bfdeef21fc029bb895ac2221b97e1595d35110a5a27589089@54.157.26.59:30311","enode://3da255f8abdeaafe3e8acd8e861314782aec365216948f203b5da5fa5457e92ac7dd7519e2e95487d99d7158a1b47e276c6a23efefbe8da423dfe090578d3bec@3.218.173.35:30311"]
ListenAddr = ":30311"
EnableMsgEvents = false

[Node.HTTPTimeouts]
ReadTimeout = 30000000000
WriteTimeout = 30000000000
IdleTimeout = 120000000000

[Node.LogConfig]
FilePath = "bsc.log"
MaxBytesSize = 10485760
Level = "info"
FileRoot = ""
> eth.syncing
{
  currentBlock: 6976722,
  highestBlock: 6976827,
  knownStates: 275436723,
  pulledStates: 275427097,
  startingBlock: 6940271
}
> admin.peers.length
713
> tail -n 10 bsc.log
tail -n 10 node/bsc.log
t=2021-04-29T03:53:19+0000 lvl=info msg="Imported new block headers"            count=1    elapsed=723.314µs number=6976836 hash=0x8c467a32a804a25fe38715a0845db7d1241e5419160a763d4b702eef7c8a69d2
t=2021-04-29T03:53:21+0000 lvl=info msg="Imported new state entries"            count=595  elapsed=2.104ms   processed=275433253 pending=9506  retry=2   duplicate=21292 unexpected=109664
t=2021-04-29T03:53:23+0000 lvl=info msg="Imported new block headers"            count=1    elapsed=871.241µs number=6976837 hash=0x6af1baae3c4ad784e554268a1df0d1384e302908d3aad719e31e6ca0f6fae1e1
t=2021-04-29T03:53:24+0000 lvl=info msg="Imported new state entries"            count=577  elapsed=5.149ms   processed=275433830 pending=9279  retry=2   duplicate=21292 unexpected=109664
t=2021-04-29T03:53:26+0000 lvl=info msg="Imported new block headers"            count=1    elapsed=493.779µs number=6976838 hash=0xa98cd367d4139f6e42a0578e3c5265dc647eb31853e3a888ae388a3e592552f9
t=2021-04-29T03:53:28+0000 lvl=info msg="Imported new state entries"            count=550  elapsed=2.449ms   processed=275434380 pending=9411  retry=0   duplicate=21292 unexpected=109664
t=2021-04-29T03:53:29+0000 lvl=info msg="Imported new block headers"            count=1    elapsed=443.582µs number=6976839 hash=0x6cc93b5d1f73a120d89007de8d34be4c7636b48d13994565f86803928d2abf63
t=2021-04-29T03:53:30+0000 lvl=info msg="Imported new state entries"            count=527  elapsed=2.469ms   processed=275434907 pending=9708  retry=0   duplicate=21292 unexpected=109664
t=2021-04-29T03:53:32+0000 lvl=info msg="Imported new block headers"            count=1    elapsed=521.156µs number=6976840 hash=0xf778bf9e7365e4b61a01a9fc82b6b838fcb5df4b208bd054d5893992311a01d3
t=2021-04-29T03:53:33+0000 lvl=info msg="Imported new state entries"            count=507  elapsed=1.404ms   processed=275435414 pending=13983 retry=0   duplicate=21292 unexpected=109664

Looking at my instance stats. It doesn't seem like i'm pinning the CPU, network, or disk IO. It just seems like the application is stuck slightly behind the current state of the BSC chain. I'm running:

I'm at a loss here. What can I do to get this thing sync'd?

heliosVII-tech commented 3 years ago

You’re still importing state entries. See: https://github.com/ethereum/go-ethereum/issues/16251

cbosss commented 3 years ago

@heliosVII-tech - thanks for the link. Do you mind checking how many states there are right now? If i'm at 275M, how far do I have to go?

havsar commented 3 years ago

Having the same problem. Tried the different StatisNodes lists given in the answers. Anyone had luck?

AdrienMrl commented 3 years ago

@cbosss I'm at about 300M. I'd also like to know how many there are in total. I wish we could find this information somewhere. I'll update the number when I'm done syncing.

Edit: 340M, still syncing. Edit2: 402M now. Edit3: 530M states. Edit4: The node nows stops running after a few seconds without any error log. I won't be updating the numbers anymore.

tculig commented 3 years ago

Does anyone have an actual number of current total state entries??

a04512 commented 3 years ago

@cbosss I'm at about 300M. I'd also like to know how many there are in total. I wish we could find this information somewhere. I'll update the number when I'm done syncing.

Edit: 340M, still syncing. Edit2: 402M now. Edit3: 530M states. Edit4: The node nows stops running after a few seconds without any error log. I won't be updating the numbers anymore.

catch up the latest block?

AdrienMrl commented 3 years ago

@a04512 I don't think it has synced because the geth process shuts down after about 20s with error 1.

adri@adribox:~/fullnode$ ./geth --config ./config.toml --datadir ./node --pprofaddr 0.0.0.0 --metrics --pprof --gcmode archive
INFO [05-02|11:16:40.406] Starting pprof server                    addr=http://0.0.0.0:6060/debug/pprof
INFO [05-02|11:16:40.406] Starting Geth on Ethereum mainnet...
INFO [05-02|11:16:40.406] Bumping default cache on mainnet         provided=1024 updated=4096
INFO [05-02|11:16:40.407] Enabling metrics collection
INFO [05-02|11:16:40.409] Maximum peer count                       ETH=30 LES=0 total=30
INFO [05-02|11:16:40.409] Smartcard socket not found, disabling    err="stat /run/pcscd/pcscd.comm: no such file or directory"
adri@adribox:~/fullnode$ echo $?
1

The bsc.log just looks like this

adri@adribox:~/fullnode$ tail node/bsc.log
t=2021-05-02T11:16:41+0000 lvl=info msg="Allocated fast sync bloom"           size="1.80 GiB"
t=2021-05-02T11:16:41+0000 lvl=info msg="New local node record"               seq=694 id=2e1b87f995d11a6b789ba44d01cf9f5aa3ab638bdd907294811880fa15ff5f1f ip=127.0.0.1 udp=30311 tcp=30311
t=2021-05-02T11:16:41+0000 lvl=info msg="Started P2P networking"              self=enode://ba8c280776d94370133208cacec059670b12841b36efe022a0b1f0b3dadef0386694860f097a9b3ffb38c842b806eafd921600d5f5b798651bf214a4fb4119f1@127.0.0.1:30311
t=2021-05-02T11:16:41+0000 lvl=info msg="IPC endpoint opened"                 url=/home/adri/fullnode/node/geth.ipc
t=2021-05-02T11:16:41+0000 lvl=info msg="HTTP endpoint opened"                url=http://127.0.0.1:8545/            cors= vhosts=localhost
t=2021-05-02T11:16:43+0000 lvl=info msg="New local node record"               seq=695 id=2e1b87f995d11a6b789ba44d01cf9f5aa3ab638bdd907294811880fa15ff5f1f ip=176.173.238.28 udp=30311 tcp=30311
t=2021-05-02T11:16:43+0000 lvl=info msg="Mapped network port"                 proto=tcp extport=30311 intport=30311 interface="UPNP IGDv2-IP2"
t=2021-05-02T11:16:43+0000 lvl=info msg="Mapped network port"                 proto=udp extport=30311 intport=30311 interface="UPNP IGDv2-IP2"
t=2021-05-02T11:16:43+0000 lvl=info msg="Block synchronisation started"
t=2021-05-02T11:16:44+0000 lvl=info msg="Disabling direct-ancient mode"       origin=7067434 ancient=6876533
havsar commented 3 years ago

Yes there is definitely an issue right now because the sync used the work some weeks ago.

abarath94 commented 3 years ago

I have the same problem, is there a potential fix ?

KyTiXo commented 3 years ago

I just wanted to mention I'm stuck 100 blocks behind as well on Dell R710 server v8 CPU's + SSDs. I've tried restarting geth multiple times but can't seem to get caught up.

I spun up a Digital Ocean VM with SSD's and 32 CPUs and was able to get synced in about 8 hours no problem, same config files and all.

I'm guessing hardware limitations requirements have gone up since the network congestion.

koen84 commented 3 years ago

@zkoolkyle it's quite surprising you get anywhere near chainhead on spinners.

koen84 commented 3 years ago

Isn't it easier to look at the blocknumber, that you can compare (e.g. on bscscan), than at states ? Imported new chain segment" blocks=5 txs=1950 mgas=181.360 elapsed=8.195s mgasps=22.128 number=7115648 So block 7115648 currently.

cbosss commented 3 years ago

@zkoolkyle - any ideas where your droplet was located (North American, Europe, Asia...). I'm wondering if latency to other BSC nodes is an issue.

tculig commented 3 years ago

Isn't it easier to look at the blocknumber, that you can compare (e.g. on bscscan), than at states ? Imported new chain segment" blocks=5 txs=1950 mgas=181.360 elapsed=8.195s mgasps=22.128 number=7115648 So block 7115648 currently.

No because you get to ~100 blocks behind current block and then are stuck there for weeks until the node picks up all states from the network.

CryptoPasa commented 3 years ago

I ran into the same problem yesterday. The bottleneck was the NVM SSD. It was fixed after switching IO scheduling algorithm as explained here : https://www.golinuxcloud.com/how-to-improve-disk-io-performance-in-linux/#The_deadline_elevator

Edit: The problem reappeared after some hours.

KyTiXo commented 3 years ago

@zkoolkyle - any ideas where your droplet was located (North American, Europe, Asia...). I'm wondering if latency to other BSC nodes is an issue.

I used data center 3 in NY.

KyTiXo commented 3 years ago

I ran into the same problem yesterday. The bottleneck was the NVM SSD. It was fixed after switching IO scheduling algorithm as explained here : https://www.golinuxcloud.com/how-to-improve-disk-io-performance-in-linux/#The_deadline_elevator

Which algo did you change it too out of curiosity? I assume you changed it from MQ to None

KyTiXo commented 3 years ago

Isn't it easier to look at the blocknumber, that you can compare (e.g. on bscscan), than at states ? Imported new chain segment" blocks=5 txs=1950 mgas=181.360 elapsed=8.195s mgasps=22.128 number=7115648 So block 7115648 currently.

I actually wrote a node monitoring script for this exact purpose. Just requires a free API key from BSCscan.com

Link if interested: https://github.com/zkoolkyle/BSC-Node-Block-Monitor

2021-05-04_14-28-18

CryptoPasa commented 3 years ago

I ran into the same problem yesterday. The bottleneck was the NVM SSD. It was fixed after switching IO scheduling algorithm as explained here : https://www.golinuxcloud.com/how-to-improve-disk-io-performance-in-linux/#The_deadline_elevator

Which algo did you change it too out of curiosity? I assume you changed it from MQ to None

I switched the algorithm from none to mq-deadline, see my updated comment.

abarath94 commented 3 years ago

WARN [05-04|18:19:00.005] Node data write error err="state node 91f2a5…e66b2a failed with all peers (10 tries, 10 peers)" INFO [05-04|18:19:00.006] Imported new state entries count=255 elapsed=1.029ms processed=54803256 pending=6101 retry=2 duplicate=82 unexpected=3047 WARN [05-04|18:19:00.006] Synchronisation failed, retrying err="state node 91f2a5…e66b2a failed with all peers (10 tries, 10 peers)"

I started a new synchronization and that is the error I got on a fresh dedicated server.

havsar commented 3 years ago

Same for me with the node write error.

JohnsonCaii commented 3 years ago

Same issues I got.

> eth.syncing
{
  currentBlock: 7475944,
  highestBlock: 7476069,
  knownStates: 346938391,
  pulledStates: 346927049,
  startingBlock: 7473908
}
> eth.blockNumber
0
INFO [05-17|02:37:50.348] Imported new state entries               count=204 elapsed="2.788µs"   processed=346,928,882 pending=13768 trieretry=0 coderetry=0 duplicate=0 unexpected=0

Seems like always has the pending number, wonder why?

I'm running the node with AWS c5.xlarge 4 CPU 8 GiB memory.

$ cat config.toml

[Eth]
NetworkId = 56
NoPruning = false
NoPrefetch = false
LightPeers = 100
UltraLightFraction = 75
TrieTimeout = 100000000000
EnablePreimageRecording = false
EWASMInterpreter = ""
EVMInterpreter = ""

[Eth.Miner]
GasFloor = 30000000
GasCeil = 40000000
GasPrice = 1000000000
Recommit = 10000000000
Noverify = false

[Eth.TxPool]
Locals = []
NoLocals = true
Journal = "transactions.rlp"
Rejournal = 3600000000000
PriceLimit = 1000000000
PriceBump = 10
AccountSlots = 512
GlobalSlots = 10000
AccountQueue = 256
GlobalQueue = 5000
Lifetime = 10800000000000

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

[Node.P2P]
MaxPeers = 30
NoDiscovery = false
BootstrapNodes = ["enode://1cc4534b14cfe351ab740a1418ab944a234ca2f702915eadb7e558a02010cb7c5a8c295a3b56bcefa7701c07752acd5539cb13df2aab8ae2d98934d712611443@52.71.43.172:30311","enode://28b1d16562dac280dacaaf45d54516b85bc6c994252a9825c5cc4e080d3e53446d05f63ba495ea7d44d6c316b54cd92b245c5c328c37da24605c4a93a0d099c4@34.246.65.14:30311","enode://5a7b996048d1b0a07683a949662c87c09b55247ce774aeee10bb886892e586e3c604564393292e38ef43c023ee9981e1f8b335766ec4f0f256e57f8640b079d5@35.73.137.11:30311"]
StaticNodes = ["enode://f56dcbe59ddcf52e2abe5d5f5fded28bf823e7e2fb887cebbfe3c540ed0dfbbd778872e6b0c9c6243fcb79fdf3e1805ae98a7c389091e9cc55bfe6dedfce04b8@3.115.208.145:30311","enode://b4feb14a8247917f25a4603a0a3a58827e6e3954fa1fc0499f3e084476dcb2dc32e444e7c51cecbc1066d2c94062fc16aa80da1a008c94e576b67b84a3a111c5@13.112.103.141:30311","enode://7fed0d5ebfec2d68106cf91d4bbf2c794a22f12a11c18ef643818e8b8a5022f63abccfa50cb34fd30343530f67a70523525d94247b4f8d143dca7524d2ba8630@52.194.28.137:30311","enode://64e87612bf91e145e019a2cf877891973151ba0acfe822346d5f6876feb4b031f80b6ff2334d9fccc7522d4c27f4a0003cfc29e20db25f6eb89fc72f5d058d89@99.80.96.58:30311","enode://c67e08daecbef6e78832a1fb7eef09725ee6671aeb6dd63cd880b9a2075b945df64b4a6181bf8ed31d43bd7b77587c5380d61095e6d7989e3880656b2fb9448d@54.76.80.25:30311","enode://45ad31700cfd9bce487b912d4b10d8f657a6b4a12f46a71707a351f350a28ea9183fe38f8e4cbd4371972bd6f096072fa65bcf59c0ffb719a8ef83f403b4d656@52.18.62.124:30311","enode://935d02d00d9c5ecdc3bee7a56201eb68c9a9e2fc684ff1e606d56bebcb45722b3812df2c408bd74495140b92214e4bd28a00853641e581cbc3ebbe6ee6b2f794@50.17.94.194:30311","enode://8e68f76aef70929084fbcdc527357aa97cf0091ed80639ba8e5c35933e50034c22a0c6d30775ec9bfdeef21fc029bb895ac2221b97e1595d35110a5a27589089@54.157.26.59:30311","enode://3da255f8abdeaafe3e8acd8e861314782aec365216948f203b5da5fa5457e92ac7dd7519e2e95487d99d7158a1b47e276c6a23efefbe8da423dfe090578d3bec@3.218.173.35:30311"]
ListenAddr = ":30311"
EnableMsgEvents = false

[Node.HTTPTimeouts]
ReadTimeout = 30000000000
WriteTimeout = 30000000000
IdleTimeout = 120000000000

My questions:

koen84 commented 3 years ago

@JohnsonCaii 8GB RAM is very little for BSC.

dwjpeng commented 3 years ago

I have similar issue as well. Always ~100 blocks behind Is there anybody have any progress so far? Is it the reason that the machine is not fast enough? But the case is I'm using the new M1 mac mini already... Stuck the syncing process for almost a week already. Should be the problem on state sync

I have the same problems, do you solve them all;

JohnsonCaii commented 3 years ago

Same issues I got.

> eth.syncing
{
  currentBlock: 7475944,
  highestBlock: 7476069,
  knownStates: 346938391,
  pulledStates: 346927049,
  startingBlock: 7473908
}
> eth.blockNumber
0
INFO [05-17|02:37:50.348] Imported new state entries               count=204 elapsed="2.788µs"   processed=346,928,882 pending=13768 trieretry=0 coderetry=0 duplicate=0 unexpected=0

Seems like always has the pending number, wonder why?

I'm running the node with AWS c5.xlarge 4 CPU 8 GiB memory.

$ cat config.toml

[Eth]
NetworkId = 56
NoPruning = false
NoPrefetch = false
LightPeers = 100
UltraLightFraction = 75
TrieTimeout = 100000000000
EnablePreimageRecording = false
EWASMInterpreter = ""
EVMInterpreter = ""

[Eth.Miner]
GasFloor = 30000000
GasCeil = 40000000
GasPrice = 1000000000
Recommit = 10000000000
Noverify = false

[Eth.TxPool]
Locals = []
NoLocals = true
Journal = "transactions.rlp"
Rejournal = 3600000000000
PriceLimit = 1000000000
PriceBump = 10
AccountSlots = 512
GlobalSlots = 10000
AccountQueue = 256
GlobalQueue = 5000
Lifetime = 10800000000000

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

[Node.P2P]
MaxPeers = 30
NoDiscovery = false
BootstrapNodes = ["enode://1cc4534b14cfe351ab740a1418ab944a234ca2f702915eadb7e558a02010cb7c5a8c295a3b56bcefa7701c07752acd5539cb13df2aab8ae2d98934d712611443@52.71.43.172:30311","enode://28b1d16562dac280dacaaf45d54516b85bc6c994252a9825c5cc4e080d3e53446d05f63ba495ea7d44d6c316b54cd92b245c5c328c37da24605c4a93a0d099c4@34.246.65.14:30311","enode://5a7b996048d1b0a07683a949662c87c09b55247ce774aeee10bb886892e586e3c604564393292e38ef43c023ee9981e1f8b335766ec4f0f256e57f8640b079d5@35.73.137.11:30311"]
StaticNodes = ["enode://f56dcbe59ddcf52e2abe5d5f5fded28bf823e7e2fb887cebbfe3c540ed0dfbbd778872e6b0c9c6243fcb79fdf3e1805ae98a7c389091e9cc55bfe6dedfce04b8@3.115.208.145:30311","enode://b4feb14a8247917f25a4603a0a3a58827e6e3954fa1fc0499f3e084476dcb2dc32e444e7c51cecbc1066d2c94062fc16aa80da1a008c94e576b67b84a3a111c5@13.112.103.141:30311","enode://7fed0d5ebfec2d68106cf91d4bbf2c794a22f12a11c18ef643818e8b8a5022f63abccfa50cb34fd30343530f67a70523525d94247b4f8d143dca7524d2ba8630@52.194.28.137:30311","enode://64e87612bf91e145e019a2cf877891973151ba0acfe822346d5f6876feb4b031f80b6ff2334d9fccc7522d4c27f4a0003cfc29e20db25f6eb89fc72f5d058d89@99.80.96.58:30311","enode://c67e08daecbef6e78832a1fb7eef09725ee6671aeb6dd63cd880b9a2075b945df64b4a6181bf8ed31d43bd7b77587c5380d61095e6d7989e3880656b2fb9448d@54.76.80.25:30311","enode://45ad31700cfd9bce487b912d4b10d8f657a6b4a12f46a71707a351f350a28ea9183fe38f8e4cbd4371972bd6f096072fa65bcf59c0ffb719a8ef83f403b4d656@52.18.62.124:30311","enode://935d02d00d9c5ecdc3bee7a56201eb68c9a9e2fc684ff1e606d56bebcb45722b3812df2c408bd74495140b92214e4bd28a00853641e581cbc3ebbe6ee6b2f794@50.17.94.194:30311","enode://8e68f76aef70929084fbcdc527357aa97cf0091ed80639ba8e5c35933e50034c22a0c6d30775ec9bfdeef21fc029bb895ac2221b97e1595d35110a5a27589089@54.157.26.59:30311","enode://3da255f8abdeaafe3e8acd8e861314782aec365216948f203b5da5fa5457e92ac7dd7519e2e95487d99d7158a1b47e276c6a23efefbe8da423dfe090578d3bec@3.218.173.35:30311"]
ListenAddr = ":30311"
EnableMsgEvents = false

[Node.HTTPTimeouts]
ReadTimeout = 30000000000
WriteTimeout = 30000000000
IdleTimeout = 120000000000

My questions:

  • Any suggestions here?
  • Would like to know how many states in total

I have solved these issues and have caught up with the blockchain.

The things I have done:

Hope this helps!

tculig commented 3 years ago

OK, so here is what I found: Running a node on my PC (Intel(R) Core(TM) i5-9400F CPU @ 2.90GHz 2.90 GHz, 32Gb of RAM, nvme SSD) for two and a half weeks resulted in an unsynced state. The known states kept growing and growing, I stopped when they went over 400mil. Then I rented an AWS server, a i3en.2xlarge and it synced within a day.

Please be advised that Binance often updates this doc: https://docs.binance.org/smart-chain/developer/fullnode.html It is now not the same as last week, and last week was not the same as two weeks before. They are actively fixing the problems. Last week the start command was: sudo geth --config ./config.toml --datadir ./node --syncmode snap Now it is: geth --config ./config.toml --datadir ./node --cache 18000 --rpc.allow-unprotected-txs --txlookuplimit 0

The last week's (10.05.2021.) start command resulted in a synced state with 0 known states. Zero! But it is fully synced and is working well and fast.

Here is what I think is the core problem: I was running the node in a virtual machine inside Windows, which had Ubuntu installed. I think that such a setup does not have full speed access to storage drives (namely the nvme SSD) and thus does not have sufficient IOPS to track the network. I suspect that had I installed Linux on my PC and ran it natively, I would have been able to sync, but can't confirm.

Just a warning: Running i3en.2xlarge is costing be about $30 per day.

Happy syncing!

muyinliu commented 3 years ago

IMPORTANT NOTE: native NVMe SSD is required, AWS EBS gp3/gp2/io2/io1 all fail to complete the sync(just keep logging Pivot became stale and never catch up the highest block after fall behind about 100 blocks)

More detail see my comment in #258

j75689 commented 3 years ago

Hi all. Thank you for your report. We have received many report of a sync issue. You can try the latest version. If you have any probleums, please feedback #338. We will pay attention to the issue #338 for a long time, and if there are any updates, we will explain it on this issue.

Thanks.