ethereum / go-ethereum

Go implementation of the Ethereum protocol
https://geth.ethereum.org
GNU Lesser General Public License v3.0
47.13k stars 19.95k forks source link

What is the upper bound of "imported new state entries"? #14647

Closed sonulrk closed 6 years ago

sonulrk commented 7 years ago

System information

Geth version: 1.6.5 OS & Version: Windows 7 x64 geth Command: geth --fast --cache 8192

Expected behaviour

Geth should start in full mode.

Actual behaviour

After nearing the current block geth is continuously "imported new state entries".

Steps to reproduce the behaviour

Currently running since 10 days.

Geth console info

eth.blockNumber 6 eth.syncing { currentBlock: 3890742, highestBlock: 3890893, knownStates: 17124512, pulledStates: 17105895, startingBlock: 3890340 }

Backtrace

INFO [06-18|10:10:31] Imported new state entries count=384 elapsed=22.001ms processed=17118951 pending=24263 INFO [06-18|10:10:32] Imported new state entries count=384 elapsed=33.001ms processed=17119335 pending=23819 INFO [06-18|10:10:33] Imported new state entries count=384 elapsed=111.006ms processed=17119719 pending=23875 INFO [06-18|10:10:34] Imported new state entries count=384 elapsed=131.007ms processed=17120103 pending=23855 INFO [06-18|10:10:35] Imported new state entries count=384 elapsed=116.006ms processed=17120487 pending=23978 INFO [06-18|10:10:36] Imported new state entries count=384 elapsed=134.007ms processed=17120871 pending=24186 INFO [06-18|10:10:38] Imported new state entries count=384 elapsed=305.017ms processed=17121255 pending=27727 INFO [06-18|10:10:42] Imported new state entries count=384 elapsed=448.025ms processed=17121639 pending=33614 INFO [06-18|10:10:46] Imported new state entries count=384 elapsed=441.025ms processed=17122023 pending=39642 INFO [06-18|10:10:48] Imported new state entries count=384 elapsed=44.002ms processed=17122407 pending=39170 INFO [06-18|10:10:52] Imported new state entries count=384 elapsed=427.024ms processed=17122791 pending=45142 INFO [06-18|10:10:55] Imported new state entries count=384 elapsed=473.027ms processed=17123175 pending=51166 INFO [06-18|10:10:58] Imported new state entries count=384 elapsed=448.025ms processed=17123559 pending=57128 INFO [06-18|10:11:01] Imported new state entries count=384 elapsed=444.025ms processed=17123943 pending=63129 INFO [06-18|10:11:04] Imported new state entries count=384 elapsed=441.025ms processed=17124327 pending=69173 INFO [06-18|10:11:04] Imported new state entries count=1 elapsed=0s processed=17124328 pending=69172 INFO [06-18|10:11:07] Imported new state entries count=384 elapsed=442.025ms processed=17124712 pending=75182 INFO [06-18|10:11:10] Imported new state entries count=384 elapsed=470.026ms processed=17125096 pending=81186 INFO [06-18|10:11:11] Imported new state entries count=384 elapsed=335.019ms processed=17125480 pending=81736 INFO [06-18|10:11:14] Imported new state entries count=384 elapsed=440.025ms processed=17125864 pending=87718 INFO [06-18|10:11:15] Imported new state entries count=384 elapsed=140.008ms processed=17126248 pending=87812 INFO [06-18|10:11:16] Imported new state entries count=384 elapsed=31.001ms processed=17126632 pending=87226 INFO [06-18|10:11:18] Imported new state entries count=384 elapsed=88.005ms processed=17127016 pending=87040 INFO [06-18|10:11:19] Imported new state entries count=384 elapsed=39.002ms processed=17127400 pending=86803 INFO [06-18|10:11:20] Imported new state entries count=384 elapsed=36.002ms processed=17127784 pending=86585 INFO [06-18|10:11:23] Imported new state entries count=1 elapsed=0s processed=17127785 pending=86272 INFO [06-18|10:11:23] Imported new state entries count=384 elapsed=1.610s processed=17128169 pending=86271 INFO [06-18|10:11:25] Imported new state entries count=384 elapsed=143.008ms processed=17128553 pending=87792 INFO [06-18|10:11:28] Imported new state entries count=384 elapsed=183.010ms processed=17128937 pending=90117 INFO [06-18|10:11:28] Imported new state entries count=1 elapsed=1ms processed=17128938 pending=90120 INFO [06-18|10:11:28] Imported new state entries count=1 elapsed=0s processed=17128939 pending=90118 INFO [06-18|10:11:29] Imported new state entries count=384 elapsed=102.005ms processed=17129323 pending=90022 INFO [06-18|10:11:30] Imported new state entries count=384 elapsed=184.010ms processed=17129707 pending=92320 INFO [06-18|10:11:32] Imported new state entries count=384 elapsed=185.010ms processed=17130091 pending=94665 INFO [06-18|10:11:34] Imported new state entries count=384 elapsed=187.010ms processed=17130475 pending=97053 INFO [06-18|10:11:36] Imported new state entries count=384 elapsed=194.011ms processed=17130859 pending=99550 INFO [06-18|10:11:38] Imported new state entries count=384 elapsed=183.010ms processed=17131243 pending=101954 INFO [06-18|10:11:40] Imported new state entries count=384 elapsed=202.011ms processed=17131627 pending=104395 INFO [06-18|10:11:42] Imported new state entries count=384 elapsed=196.011ms processed=17132011 pending=106904 INFO [06-18|10:11:44] Imported new state entries count=384 elapsed=186.010ms processed=17132395 pending=109176 INFO [06-18|10:11:47] Imported new state entries count=384 elapsed=184.010ms processed=17132779 pending=111554 INFO [06-18|10:11:47] Imported new state entries count=2 elapsed=184.010ms processed=17132781 pending=111554 INFO [06-18|10:11:48] Imported new state entries count=384 elapsed=34.002ms processed=17133165 pending=110760 INFO [06-18|10:11:50] Imported new state entries count=384 elapsed=193.011ms processed=17133549 pending=113172

garyng2000 commented 6 years ago

so it would be at least 10M state to import. these sync always depend on what peer you have connected to. it was pretty bad yesterday but after restart, it proceeded with much higher rate. I was expecting at least another 2 days based on what I saw yesterday but some how, it got quicker over the night, no idea why.

winsvega commented 6 years ago

geth 1.8 still having this issue. after reboot geth shows this error

WARN [01-05|02:54:25] Ancestor below allowance                 peer=2586937320363579 number=4015416 hash=abc963…9b3dc5 allowance=4765509
WARN [01-05|02:54:25] Synchronisation failed, dropping peer    peer=2586937320363579 err="retrieved ancestor is invalid"

now fast sync is dropping peers and not syncing. ~100 blocks to finish but it never gets synced.

cecilia-to commented 6 years ago

this is the nature of p2p networking, you are at the mercy of the peers and network condition. usually when you wait enough, it would work. ctrl-c and restart is fine too(which hopefully can get you a better peer). another alternative is find a good peer and add it manually.

Shipwreck commented 6 years ago

Is there a place to see the current max knownStates?

cecilia-to commented 6 years ago

not simple. it basically depends on the transactions. at this moment do a rough estimate which is 15-20 per block. so may be 70-80M(close to 6M block now). but going forward it will be just more per block since they up the gas limit over time.

Shipwreck commented 6 years ago

So I am at about 8 hours syncing on 57 Mbps with 16GB DDR4 / SSD / 1080Ti / 8700K and geth --fast --cache=4024. My eth.syncing says:

  currentBlock: 4900069,
  highestBlock: 4900328,
  knownStates: 51148480,
  pulledStates: 51137757,
  startingBlock: 0

currentBlock hasn't moved for hours. 14 peers, eth.blockNumber 0, just cycling through new state entires:

INFO [01-13|10:00:32] Imported new state entries               count=803  elapsed=3.654ms   processed=51095193 pending=8217  retry=0   duplicate=4005 unexpected=12212
INFO [01-13|10:00:33] Imported new state entries               count=834  elapsed=1.759ms   processed=51096027 pending=13439 retry=0   duplicate=4005 unexpected=12212

Is this normal? Where can I find a breakdown of those values and their behavior? What's the point of 'pending' if it is constantly changing... ?

cecilia-to commented 6 years ago

it is normal and if it is constantly changing(processed=51096027 ), you are good. just wait it will finish then switched to normal mode

Shipwreck commented 6 years ago

Appreciate your time, thank you very much.

Do you recommend exploring Parity? I see it recommended over Geth but I've only personally been exposed through it through negative news from hacks and am wary.

cecilia-to commented 6 years ago

Parity the contracts they wrote have bugs, but Parity the program itself is fine. However, one thing I noticed is that it seems to suck up lots of CPU when in the initial sync phase. I don't know how it behave during normal stage. It does have advantage of constantly pruning thus keep the storage space checked. geth needs lots of space after it enter normal stage. about 100-200G a month at the current rate. I need to have a standby machine to do the 'fast' periodically. As fast is the only way to 'compress'

Shipwreck commented 6 years ago

I pulled the plug on my sync, going to look into Parity. Can't justify the space and effort to keep a real full node if this is what it looks like. The machine would have to be running constantly, right? Constantly syncing, and at some point probably not even being able to keep up? Are there known metrics for the network growing faster than D/L speeds can sync?

I thought I would have a HD that I booted to and got up to speed any time I wanted to work with ETH but it doesn't seem like that's the case with an actual full node without pruning or warp or some such optimisation.

Thanks again for your time, appreciate your info.

Shipwreck commented 6 years ago

I don't feel secure using MEW, my Ledger has more on it than I am comfortable having in one place and they are back-ordered for new units, so I thought having an official client would be the next best thing... since Mist doesn't seem to fit my needs, Parity is pretty close to being official so I guess I'm headed there.

Is my logic sound?

cecilia-to commented 6 years ago

if all that you care is the wallet address, you don't even need the node. just generate the wallet address, and send whatever coin to that address and be done with it. Basically treat this as 'I don't use it much' address. When you do need to pull things out, do it on an island machine(including a VM with no external network connection), sign the transaction the send the raw transaction using MEW or whatever to any node(infura whatever).

jalal1985 commented 6 years ago

Hi Guys,

i used this to check my current block which needs to sync

currentBlock: 4506167, highestBlock: 4934648, knownStates: 866589, pulledStates: 848856, startingBlock: 4426024 }

I use this to mine geth --datadir ./.ethereum/devnet/ --dev --mine --minerthreads 4 etherbase 0

I use this to connect the running client to the miner

eth --datadir ./.ethereum/devnet --dev attach ipc:./.ethereum/devnet/geth.ipc Welcome to the Geth JavaScript console!

instance: Geth/v1.7.2-stable-1db4ecdc/linux-amd64/go1.9 coinbase: 0x2........................ at block: 330038 (Fri, 19 Jan 2018 13:40:44 CET) datadir: /home/smartcontract/.ethereum/devnet modules: admin:1.0 debug:1.0 eth:1.0 miner:1.0 net:1.0 personal:1.0 rpc:1.0 shh:1.0 txpool:1.0 web3:1.0

web3.eth.syncing false web3.fromWei(eth.getBalance(eth.coinbase),"ether") 1445287.5 web3.eth.blockNumber 330039

When I want to send a transactions I have the following code in that console th.sendTransaction({from:eth.coinbase, to:eth.accounts[1], value: web3.toWei(0.05, "ether")}) Please unlock account d1ade25ccd3d550a7eb532ac759cac7be09c2719. Passphrase: Account is now unlocked for this session. '0xeeb66b211e7d9be55232ed70c2ebb1bcc5d5fd9ed01d876fac5cff45b5bf8bf4'.

At the end I do not see the tranasction on Etherscan nor in the wallet that I am sending to. Also balance remain the same. HOW CAN THIS BE HAPPENING OMG:)

background: I had a not synced chaindata, some did a removedb on geth then importing all the blocks again, since the database was corrupted with message such as "Failing peer messages"? Really ethereum still need to improve.

quantumproducer commented 6 years ago

I'm syncing because when I tried deploying with truffle, I got network state unknown. Reading around I found I needed to have eth.blockNumber be a positive integer. Currently it's 0 and my state is syncing.

> eth.syncing
{
  currentBlock: 5186010,
  highestBlock: 5186166,
  knownStates: 32389802,
  pulledStates: 32378516,
  startingBlock: 5185518

when can I expect this to finish? What are these states?

tinschel commented 6 years ago

At this point (9 March 2018) it takes almost 8 days to sync the Ethereum blockchain with a setup like so:

i7 processor, 8 cores, 64GB RAM, 100Mbps Internet connection, SSD drive - ideally with RAID

The fastest way to sync is to start clean by removing your existing database: geth removedb and then doing a fast sync with large cache size (i.e., 8GB if you have enough RAM, like 64GB of RAM): geth --syncmode "fast" --cache 8192 console

There are 3 distinct stages in the sync process:

  1. Importing blocks (see Etherchain.org, 5,269,000+, 10+ hours) After you get close to the current block, geth automatically switches to full mode and continues on. So there is no need to stop and restart.
  2. Importing state entries (96M+, 1+ days)
  3. Importing chain segments (same # as blocks, 6+ days), for example: INFO [03-10|14:07:44] Imported new chain segment blocks=139 txs=776 mgas=430.595 elapsed=8.039s mgasps=53.560 number=1854160 hash=9d134e…e0adc0 cache=15.85mB

Your chaindata folder will be 220+ GB after you have fully sync'ed.

You can tell that you are fully sync'ed by getting chain segment messages of only 1 block, which is identical to the current block number: INFO [03-16|21:23:04] Imported new chain segment blocks=1 txs=341 mgas=7.990 elapsed=435.942ms mgasps=18.329 number=5269405 hash=939ae8…96e825 cache=143.76mB

Good luck!

wtfiwtz commented 6 years ago

See this issue for a detailed description of what is going on under the hood - https://github.com/ethereum/go-ethereum/issues/15001#issuecomment-370732526

cies commented 6 years ago

@quantumproducer:

See @tinschel 's comment above and also see https://github.com/ethereum/go-ethereum/issues/16147#issuecomment-371878483

cies commented 6 years ago

@tinschel you said:

You can tell that you are fully sync'ed by getting chain segment messages of only 1 block, which is identical to the current block number

Wouldn't it be super nice if eth.syncing would return false only when this point is reached? And give some sort of human understandable numbers back detailing the progress it is making, until it gets there?

I see so many questions on this point, users are totally confused by eth.syncing's behaviour.

tinschel commented 6 years ago

it sure would be, @cies !

jel111 commented 6 years ago

This is the dumbest shit ever.

FreekPaans commented 6 years ago

I synced and took some measurements: http://www.freekpaans.nl/2018/04/anatomy-geth-fast-sync/

@tinschel I don't see a lot of time being taken by "Importing chain segments". In fact it only seems to be doing that for "new" blocks. Any idea?

wtfiwtz commented 6 years ago

That is awesome analysis @FreekPaans... I pondered back in December 2017 about whether it is to do with a particular method called requestTTL... https://github.com/ethereum/mist/issues/2749#issuecomment-354282608

Basically you can be stalled waiting for one of the peers to be giving you the information you need.

Also, parts of the network may be starved of blocks or the trie state that you are seeking. Effectively, if you are not connected to enough peers with the latest data, then you will waiting on the "network" to respond with the information you need in order to continue with the chain validation.

There was some good analysis I found here:

Hope this helps... I'm yet to figure out the exact reason why it stalls.

FreekPaans commented 6 years ago

Yes, I also have the feeling it's due to blocks/state trie data not being available at the peers I'm connected to, but no clue how I'd verify that. I'm doing a full sync now, has been fetching just the blocks for over 11hrs as we speak, still about 30% to go.

tinschel commented 6 years ago

@FreekPaans: I'm surprised your first single-block “Imported new chain segment” log message came about so fast. At what point in your analysis did you see the importing of chain segments starting? For me the importing of chain segments lasted 6 days before my eth.synching actually showed false.

Maybe your higher speed had to do with the increased number of peers (25) that you were seeing. I did not unblock port 30303 and although I also used --maxpeers 25 (which is the default) I only ever saw 8 peers max.

FreekPaans commented 6 years ago

@tinschel yes, with 30303 closed it stuck on about 8 peers with me as well. Not familiar with the P2P protocol so don't know why.

The first Imported new chain segment came when the state trie finished importing, and it only had 4 entries count > 1.

PhABC commented 6 years ago

Took me about 1-2 hours to fully sync Rinkeby using geth --rinkeby (2,057,556 blocks and about 10,760,209 state entries).

FreekPaans commented 6 years ago

I now also completed a geth full sync: http://www.freekpaans.nl/2018/04/anatomy-of-a-geth-full-sync/. tl;dr: took a little over 9 days, vs under 8 hours for fast sync.

tinschel commented 6 years ago

@FreekPaans, yes, the 9 days are more in line with my sync; I didn't realize that your original sync didn't go all the way; if you only do fast sync, others are not able to use you as a node for blockchain synchronization; so if everyone just used fast sync, the blockchain couldn't exist.

garyng2000 commented 6 years ago

@tinschel that sounds very bad for Ethereum. The size of it grows really fast(I think in the range of 100G a month) and not that many people have such space for full sync. How can it scale for the intended usage(rule the world) ?

tinschel commented 6 years ago

@garyng2000, that's a little bit of an exaggeration; I've been running the full sync now for a month and it has only grown from 220GB to 241GB today

garyng2000 commented 6 years ago

@tinschel would that be affected by when you started(recent price drop can have an effect on # of transactions) ? I remembered we had a 'fast sync' node that was growing really fast but I am not managing it so not sure how large it is now. But even using your figure, it is still growing at an alarming rate. Basically, not something for a typical 'personal' node and it basically break the intended large P2P nature. even for mining, we are seeing that most of them are done by very few pools, basically centralized in a sense.

holiman commented 6 years ago

if you only do fast sync, others are not able to use you as a node for blockchain synchronization; so if everyone just used fast sync, the blockchain couldn't exist.

Nope, that's incorrect. A fast-synced node helps out, it's got a lot of state others can download. A les-client otoh is maybe what you were thinking about.

tinschel commented 6 years ago

@garyng2000, no effect on the start date. it's possible that different months have more transactions and state and therefore the blockchain size grows more rapidly during those months. There is no difference between the block chain size in fast sync mode and full mode because after fast sync completes, it automatically switches to full mode. In other words, fast sync may get you to the end of the blocks very quickly, but you won't have the full blockchain with all state until you complete the full sync.

So fast sync is good if all you want to do is maintain a wallet or start mining. Full sync is necessary so that you can become a full node within the Ethereum blockchain.

garyng2000 commented 6 years ago

that is strange, I just asked our guy maintaining the node. The last fast sync(from scratch) was about a month ago and it ended for about 60G in size(all updated state downloaded) and now is already 140G. not sure what is going on there. Though from an operational perspective, I see no difference between full and fast(which is just a trimmed full). can still do all the operation, unlike light which is basically useless for our usage.

res-Q commented 6 years ago

I am experiencing the same issue when using geth --fast --cache 1048.

Imported new state entries

 eth.syncing
{
  currentBlock: 5535921,
  highestBlock: 5536021,
  knownStates: 274,
  pulledStates: 273,
  startingBlock: 5535921
}
bneiluj commented 6 years ago

This is driving me crazy. One week to sync! 😳

lk29 commented 6 years ago

Read, tried! And nothing helps

quantumproducer commented 6 years ago

If you use a hard disk geth will not work. You need SSD, or switch to parity for syncing.

TooBug commented 6 years ago

Just give some information:

I started the syncing from May 18, It just ended minutes ago.

BlockNumber: 5740903 pulledStates: 191247645

Othman21 commented 6 years ago

@TooBug Hello, Do you get "false" when you type this command : eth.syncing Can you give me the number of the KnowStates/pulledStates you at ?

TooBug commented 6 years ago

@Othman21 Oth

Yes, When it's finished, eth.syncing returns false.

The number is given above. KnownStates is quite similar to pulledStates.

Othman21 commented 6 years ago

@TooBug Can you tell me the exact processed number that you see right now ? for exemple i'm at processed=193996209

jdowning100 commented 6 years ago

FWIW I was able to get geth to fully sync by waiting until eth.blockNumber is near the numbers in eth.syncing and then restarting geth. I was able to do this at ~160m states. After restarting geth, it took about 20 min to catch up to the blockchain and now eth.syncing is false and the only output now is 'imported new chain segment' every time a new block is found.

tinschel commented 6 years ago

here is an output of mine taken on 16JUN2018 at 6:18am PTD:

>eth.syncing { currentBlock: 5799102, highestBlock: 5799188, knownStates: 96279752, pulledStates: 96279752, startingBlock: 5799001 }

Othman21 commented 6 years ago

@tinschel here is an output of mine taken on 19JUN2018 at 7:32am PTD: > eth.syncing { currentBlock: 5815191, highestBlock: 5815294, knownStates: 198143487, pulledStates: 198143486, startingBlock: 5815181 }

codepushr commented 6 years ago

Just to clarify... fastsync is now default... and I may quit and restart geth with fast enabled?

Anyway I'm currently at:

> eth.syncing
{
  currentBlock: 5827681,
  highestBlock: 5827747,
  knownStates: 96988858,
  pulledStates: 96988508,
  startingBlock: 5824114
}
> eth.blockNumber
0

@tinschel @Othman21 How is this possible? 100% more state entries in 3 days?

codepushr commented 6 years ago

@Othman21 This is nuts! 29 days and 200m state entries? Crazy...

Othman21 commented 6 years ago

@codepushr yes you can, i run this command : ./geth --cache=25000 --rpc --maxpeers 25 --fast

I have not finished syncing yet, today it will be 29 days

eth.syncing

{ currentBlock: 5829510, highestBlock: 5829582, knownStates: 203714648, pulledStates: 203714648, startingBlock: 5829510 }

eth.blockNumber 0

Othman21 commented 6 years ago

@codepushr i know I'm looking for someone who has finished syncing to tell me the current knownStates that he has to get an idea if I'm far or near.

codepushr commented 6 years ago

It's so bad that there is no mechanism to determine the absolute progress...