2

I'm running geth rinkeby at my Macbook. My geth version is like this.

Geth
Version: 1.10.3-stable
Architecture: amd64
Go Version: go1.16.3
Operating System: darwin

It finished syncing and ran fine with receiving blocks. It ran well almost 2 months. But it's stuck now and I don't know why it's suddenly stucked. I ran geth rinkeby with below command.

geth --rinkeby --http --http.addr 0.0.0.0 --http.api eth,net,web3,personal,txpool,admin --ws --ws.addr 0.0.0.0 --ws.origins="*" --ws.api personal,admin,eth,net,web3,txpool,debug --allow-insecure-unlock --syncmode fast --cache 2048 --maxpeers 100 2>> ./logs/geth.log

And my geth log looks like below.

INFO [07-08|10:27:18.158] Imported new chain segment               blocks=1     txs=13   mgas=0.874   elapsed=15.973ms    mgasps=54.718   number=8,897,987 hash=d2df74..48ba4e dirty=496.76MiB
INFO [07-08|10:27:18.160] Unindexed transactions                   blocks=1     txs=6    tail=6,547,988 elapsed=2.467ms
INFO [07-08|10:27:21.284] Looking for peers                        peercount=1 tried=5  static=1
INFO [07-08|10:27:31.286] Looking for peers                        peercount=1 tried=5  static=1
INFO [07-08|10:27:41.286] Looking for peers                        peercount=0 tried=8  static=1
INFO [07-08|10:27:51.287] Looking for peers                        peercount=1 tried=5  static=1
INFO [07-08|10:27:55.181] Deep froze chain segment                 blocks=2     elapsed=133.622ms   number=8,807,987 hash=23cfa7..830fa8
INFO [07-08|10:28:01.288] Looking for peers                        peercount=1 tried=7  static=1
INFO [07-08|10:28:11.288] Looking for peers                        peercount=1 tried=7  static=1
INFO [07-08|10:28:21.289] Looking for peers                        peercount=1 tried=6  static=1
INFO [07-08|10:28:31.292] Looking for peers                        peercount=1 tried=6  static=1
INFO [07-08|10:28:41.293] Looking for peers                        peercount=1 tried=5  static=1
INFO [07-08|10:28:51.294] Looking for peers                        peercount=2 tried=8  static=1
INFO [07-08|10:29:01.295] Looking for peers                        peercount=2 tried=4  static=1
INFO [07-08|10:29:11.294] Looking for peers                        peercount=2 tried=6  static=1
INFO [07-08|10:29:21.296] Looking for peers                        peercount=2 tried=6  static=1
INFO [07-08|10:29:31.296] Looking for peers                        peercount=2 tried=6  static=1
INFO [07-08|10:29:41.302] Looking for peers                        peercount=2 tried=5  static=1
INFO [07-08|10:29:51.304] Looking for peers                        peercount=2 tried=6  static=1
INFO [07-08|10:30:01.307] Looking for peers                        peercount=2 tried=7  static=1
INFO [07-08|10:30:11.309] Looking for peers                        peercount=2 tried=5  static=1
INFO [07-08|10:30:21.311] Looking for peers                        peercount=2 tried=6  static=1
INFO [07-08|10:30:31.311] Looking for peers                        peercount=2 tried=5  static=1
INFO [07-08|10:30:41.311] Looking for peers                        peercount=2 tried=6  static=1
INFO [07-08|10:30:51.313] Looking for peers                        peercount=2 tried=8  static=1
INFO [07-08|10:31:01.314] Looking for peers                        peercount=2 tried=6  static=1
INFO [07-08|11:13:29.673] Writing clean trie cache to disk         path=/Users/user/Library/Ethereum/rinkeby/geth/triecache threads=1
INFO [07-08|11:13:29.675] Regenerated local transaction journal    transactions=0 accounts=0
INFO [07-08|11:13:32.926] Persisted the clean trie cache           path=/Users/user/Library/Ethereum/rinkeby/geth/triecache elapsed=3.251s
INFO [07-08|12:13:29.760] Writing clean trie cache to disk         path=/Users/user/Library/Ethereum/rinkeby/geth/triecache threads=1
INFO [07-08|12:13:29.763] Regenerated local transaction journal    transactions=0 accounts=0
INFO [07-08|12:13:32.399] Persisted the clean trie cache           path=/Users/user/Library/Ethereum/rinkeby/geth/triecache elapsed=2.635s
INFO [07-08|13:13:29.731] Writing clean trie cache to disk         path=/Users/user/Library/Ethereum/rinkeby/geth/triecache threads=1
INFO [07-08|13:13:29.735] Regenerated local transaction journal    transactions=0 accounts=0
INFO [07-08|13:13:31.269] Persisted the clean trie cache           path=/Users/user/Library/Ethereum/rinkeby/geth/triecache elapsed=1.538s
INFO [07-08|14:13:29.835] Writing clean trie cache to disk         path=/Users/user/Library/Ethereum/rinkeby/geth/triecache threads=1
INFO [07-08|14:13:29.853] Regenerated local transaction journal    transactions=0 accounts=0
INFO [07-08|14:13:33.823] Persisted the clean trie cache           path=/Users/user/Library/Ethereum/rinkeby/geth/triecache elapsed=3.980s
INFO [07-08|15:13:29.795] Writing clean trie cache to disk         path=/Users/user/Library/Ethereum/rinkeby/geth/triecache threads=1
INFO [07-08|15:13:29.799] Regenerated local transaction journal    transactions=0 accounts=0
INFO [07-08|15:13:32.508] Persisted the clean trie cache           path=/Users/user/Library/Ethereum/rinkeby/geth/triecache elapsed=2.712s
INFO [07-08|16:13:29.927] Writing clean trie cache to disk         path=/Users/user/Library/Ethereum/rinkeby/geth/triecache threads=1
INFO [07-08|16:13:29.928] Regenerated local transaction journal    transactions=0 accounts=0
INFO [07-08|16:13:32.662] Persisted the clean trie cache           path=/Users/user/Library/Ethereum/rinkeby/geth/triecache elapsed=2.734s

As the log says, it worked fine, but suddenly it stopped receiving blocks from other peers, and stuck with Looking for peers. And then, following three logs were repeating.

INFO [07-08|11:13:29.673] Writing clean trie cache to disk         path=/Users/user/Library/Ethereum/rinkeby/geth/triecache threads=1
INFO [07-08|11:13:29.675] Regenerated local transaction journal    transactions=0 accounts=0
INFO [07-08|11:13:32.926] Persisted the clean trie cache           path=/Users/user/Library/Ethereum/rinkeby/geth/triecache elapsed=3.251s

So I tried restarting Geth. (I just killed the process and entered the geth command as above.) But then, it didn't get syncing or receiving blocks again. The log just shows Looking for peers permanently. The node already had peers but not syncing. The log looks like below.

...
INFO [07-08|16:38:37.212] IPC endpoint opened                      url=/Users/user/Library/Ethereum/rinkeby/geth.ipc
INFO [07-08|16:38:37.213] HTTP server started                      endpoint=[::]:8545 prefix= cors= vhosts=localhost
INFO [07-08|16:38:37.213] WebSocket enabled                        url=ws://[::]:8546
INFO [07-08|16:38:48.095] New local node record                    seq=287 id=9f26334289445bf1 ip=<my ipaddress> udp=30303 tcp=30303
INFO [07-08|16:38:48.216] Looking for peers                        peercount=0 tried=34 static=0
INFO [07-08|16:38:58.218] Looking for peers                        peercount=0 tried=30 static=0
INFO [07-08|16:39:08.286] Looking for peers                        peercount=0 tried=35 static=0
INFO [07-08|16:39:18.546] Looking for peers                        peercount=1 tried=27 static=0
INFO [07-08|16:39:28.552] Looking for peers                        peercount=1 tried=36 static=1
INFO [07-08|16:39:38.557] Looking for peers                        peercount=1 tried=33 static=1
INFO [07-08|16:39:48.879] Looking for peers                        peercount=1 tried=25 static=1
INFO [07-08|16:39:59.144] Looking for peers                        peercount=1 tried=33 static=1
INFO [07-08|16:40:09.211] Looking for peers                        peercount=1 tried=35 static=1
INFO [07-08|16:40:19.214] Looking for peers                        peercount=1 tried=31 static=1
INFO [07-08|16:40:29.531] Looking for peers                        peercount=1 tried=22 static=1
INFO [07-08|16:40:39.547] Looking for peers                        peercount=1 tried=33 static=1
INFO [07-08|16:40:49.878] Looking for peers                        peercount=1 tried=27 static=1
INFO [07-08|16:41:00.212] Looking for peers                        peercount=1 tried=37 static=1
INFO [07-08|16:41:10.215] Looking for peers                        peercount=1 tried=25 static=1
INFO [07-08|16:41:20.216] Looking for peers                        peercount=1 tried=20 static=1
...

So here is my questions.

  1. Why Geth has stucked suddenly?
  2. Why Geth doesn't work after restarting it?
  3. Is there a way to restart Geth gracefully? I just killed process and started Geth again with the command I used, but I always had to erase leveldb when restarting Geth like this way.

Thank you.

UPDATE

I restarted Geth with verbosity 4 (DEBUG mode), and attached the logs between INFO Looking for peers logs. DEBUG logs looks like below.

...
DEBUG[07-15|09:48:23.173] Revalidated node                         b=4  id=9f2cb42ade264eea checks=1
DEBUG[07-15|09:48:23.178] Adding p2p peer                          peercount=3 id=8391c2401d336e64 conn=dyndial    addr=112.194.96.138:8502   name=OpenEthereum/v3.2.6-...
DEBUG[07-15|09:48:23.306] Ethereum handshake failed                id=7b3f212e39a05d39 conn=dyndial    err="fork ID rejected: remote needs update"
DEBUG[07-15|09:48:23.306] Removing p2p peer                        peercount=2 id=7b3f212e39a05d39 duration=147.554ms   req=true  err="subprotocol error"
DEBUG[07-15|09:48:23.335] Adding p2p peer                          peercount=3 id=84e07faffaf52840 conn=dyndial    addr=52.169.42.101:30303   name=Geth/v1.10.5-unstabl...
DEBUG[07-15|09:48:23.563] Ethereum handshake failed                id=84e07faffaf52840 conn=dyndial    err=EOF
DEBUG[07-15|09:48:23.563] Message handling failed in `snap`        peer=84e07faf err=EOF
DEBUG[07-15|09:48:23.563] Removing p2p peer                        peercount=2 id=84e07faffaf52840 duration=227.601ms   req=true  err="subprotocol error"
DEBUG[07-15|09:48:23.827] Recalculated downloader QoS values       rtt=20s confidence=1.000 ttl=1m0s
DEBUG[07-15|09:48:24.441] Adding p2p peer                          peercount=3 id=8ecc16f9400d6fc4 conn=dyndial    addr=63.34.52.202:33333    name=Geth/v1.9.24-stable-...
DEBUG[07-15|09:48:24.720] Ethereum handshake failed                id=8ecc16f9400d6fc4 conn=dyndial    err="network ID mismatch: 219913 (!= 4)"
DEBUG[07-15|09:48:24.721] Removing p2p peer                        peercount=2 id=8ecc16f9400d6fc4 duration=280.038ms   req=false err="network ID mismatch: 219913 (!= 4)"
DEBUG[07-15|09:48:25.729] Revalidated node                         b=7  id=9f4e2c6ea7153f79 checks=1
DEBUG[07-15|09:48:25.764] Adding p2p peer                          peercount=3 id=0e10a37bbbc33e44 conn=dyndial    addr=15.236.32.166:30303   name=Geth/v1.10.5-unstabl...
DEBUG[07-15|09:48:26.039] Ethereum handshake failed                id=0e10a37bbbc33e44 conn=dyndial    err="fork ID rejected: local incompatible or needs update"
DEBUG[07-15|09:48:26.039] Message handling failed in `snap`        peer=0e10a37b err=EOF
DEBUG[07-15|09:48:26.039] Removing p2p peer                        peercount=2 id=0e10a37bbbc33e44 duration=275.341ms   req=true  err="subprotocol error"
DEBUG[07-15|09:48:26.612] Adding p2p peer                          peercount=3 id=8ec7352b8985509b conn=dyndial    addr=159.65.254.146:30303  name=bor/v1.10.1-stable-1...
DEBUG[07-15|09:48:26.811] Ethereum handshake failed                id=8ec7352b8985509b conn=dyndial    err="network ID mismatch: 137 (!= 4)"
DEBUG[07-15|09:48:26.811] Removing p2p peer                        peercount=2 id=8ec7352b8985509b duration=198.985ms   req=false err="network ID mismatch: 137 (!= 4)"
DEBUG[07-15|09:48:27.843] Adding p2p peer                          peercount=3 id=8ec75fa18296fa0c conn=dyndial    addr=104.209.34.240:30306  name=Geth/validator4/v1.9...
DEBUG[07-15|09:48:27.975] Ethereum handshake failed                id=8ec75fa18296fa0c conn=dyndial    err="network ID mismatch: 1337 (!= 4)"
DEBUG[07-15|09:48:27.975] Removing p2p peer                        peercount=2 id=8ec75fa18296fa0c duration=132.793ms   req=false err="network ID mismatch: 1337 (!= 4)"
DEBUG[07-15|09:48:28.179] Ethereum handshake failed                id=8391c2401d336e64 conn=dyndial    err="read timeout"
DEBUG[07-15|09:48:28.179] Removing p2p peer                        peercount=1 id=8391c2401d336e64 duration=5.000s      req=false err="read timeout"
DEBUG[07-15|09:48:31.793] Adding p2p peer                          peercount=2 id=8ed611401e2afc34 conn=dyndial    addr=34.195.70.235:30303   name=besu/v21.1.7/linux-x...
DEBUG[07-15|09:48:31.793] Ethereum handshake failed                id=8ed611401e2afc34 conn=dyndial    err="network ID mismatch: 11297108109 (!= 4)"
DEBUG[07-15|09:48:31.793] Removing p2p peer                        peercount=1 id=8ed611401e2afc34 duration="406.245µs" req=false err="network ID mismatch: 11297108109 (!= 4)"
...

The logs say Ethereum handshake failed. How could I fix this issue? Is Geth has to be turned on always after first time syncing? Why restarting Geth destroys Ethereum handshake?

Improve this question
3
  • add verbosity 8 flag and come back with more logs. looks like network issue, firewall or something, but could be that you have got a wrong head block and nobody links to you because you are in a wrong chain. more verbose log would show it
    – Nulik
    Commented Jul 9, 2021 at 10:59
  • if you are using geth from master branch on github you can killl geth with -9 with no problem. they just fixed a nasty bug (issue 22728 on github) that corrupted the chain, a few weeks ago, but this is only available on master branch
    – Nulik
    Commented Jul 9, 2021 at 11:01
  • @Nulik I've erased leveldb and restarted geth, it was fine at first time. But when my Macbook turned off because of out of battery (I was outside for a while) so when I turned it on after few hours later and restarted geth, geth works weird like my question again. So I restarted geth with verbosity 4 (DEBUG logs, when I looked at man page, verbosity was up to 5 and 5 was TRACE mode and it's logs were too many, so I used 4 mode), and updated my question with the logs between INFO Looking for peers logs. Could you see it again please? Thank you.
    – Jung Chun
    Commented Jul 15, 2021 at 0:50

1 Answer 1

Reset to default
2

I found what was the reason for this issue for my case. I was using Geth version 1.10.3-stable. So I looked for the new releases at go-ethereum github page that if new versions solving the issue like this. And there were two new stable releases. And 1.10.4-stable version said that

Geth v1.10.4 is a feature release and adds compatibility with the upcoming London hard fork.

So there was a hard fork after 1.10.3-stable version released. And at Additional notes about the London changes section, it said

This release contains testnet activation block numbers for the London hard fork. The numbers are: Ropsten - 10499401, Goerli - 5062605, Rinkeby - 8897988. (#23041)

So I looked at my DEBUG logs. At some DEBUG logs, I've found this log.

DEBUG[07-15|10:49:42.932] Ancient blocks frozen already            number=8,897,987 hash=d2df74..48ba4e frozen=8,807,988

It looked like my Geth node got stuck because it reached the last block right before the hard fork. So I updated Geth to 1.10.5-stable and restarted Geth. And now Geth is importing new blocks fine now.

Conclusion

My case was because of the hard fork. When I upgraded Geth to newly released version, now it's receiving blocks fine which created after the hard fork.

Improve this answer

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.