RPC timeout on client start

[dszlachta]

System information

Geth version: shisui version 1.14.9-unstable
CL client & version: none
OS & Version: OSX
Commit hash :

Expected behaviour

Client connects to peers when started

Actual behaviour

RPC timeout errors are printed, no sign that the client makes any peer connection.

Steps to reproduce the behaviour

Clone the repository, build Shisui with make shisui and run it with ./build/bin/shisui

Log

./build/bin/shisui 
INFO [09-23|11:55:41.073] New local node record                    seq=2 id=9bb2a0b66e3ed486 ip=127.0.0.1 udp=0 tcp=0
INFO [09-23|11:55:41.075] New local node record                    seq=3 id=9bb2a0b66e3ed486 ip=127.0.0.1 udp=9009 tcp=0
ERROR[09-23|11:55:47.075] failed to send find nodes request        protocol=history ip=194.xx.yy.zzz port=9101 err="RPC timeout"
ERROR[09-23|11:55:47.075] failed to send find nodes request        protocol=history ip=194.xx.yy.zzz port=9101 err="RPC timeout"
ERROR[09-23|11:55:47.076] failed to send find nodes request        protocol=history ip=164.xx.yy.zzz port=5002 err="RPC timeout"
ERROR[09-23|11:55:50.076] failed to send find nodes request        protocol=history ip=194.xx.yy.zzz  port=9102 err="RPC timeout"
ERROR[09-23|11:55:50.395] failed to send find nodes request        protocol=history ip=164.xx.yy.zzz port=5002 err="RPC timeout"
ERROR[09-23|11:55:53.076] failed to send find nodes request        protocol=history ip=164.xx.yy.zzz port=5001 err="RPC timeout"
ERROR[09-23|11:55:53.447] failed to send find nodes request        protocol=history ip=157.xx.yy.zzz  port=9000 err="RPC timeout"
ERROR[09-23|11:55:56.077] failed to send find nodes request        protocol=history ip=194.xx.yy.zzz  port=9102 err="RPC timeout"
ERROR[09-23|11:55:56.486] failed to send find nodes request        protocol=history ip=161.xx.yy.zzz  port=9000 err="RPC timeout"
ERROR[09-23|11:55:58.415] failed to send find nodes request        protocol=history ip=164.xx.yy.zzz port=5001 err="RPC timeout"

[GrapeBaBa]

@dszlachta Could you enable Loglevel DEBUG, and check if there is an error below.

[dszlachta]

Yes, it's there:

DEBUG[09-23|15:48:20.825] Couldn't add port mapping                proto=UDP extport=9009 intport=9009 interface="UPnP or NAT-PMP" err="no UPnP or NAT-PMP router discovered"
DEBUG[09-23|15:48:20.825] Couldn't get external IP                 err="no UPnP or NAT-PMP router discovered" interface="UPnP or NAT-PMP"

[r4f4ss]

with --nat pmp:<internal-IP>

TRACE[09-23|10:46:20.001] Attempting port mapping                  proto=UDP extport=9009 intport=9009 interface=NAT-PMP(<internal-IP>)
DEBUG[09-23|10:46:20.001] Couldn't add port mapping                proto=UDP extport=9009 intport=9009 interface=NAT-PMP(<internal-IP>) err="read udp <internal-IP>:37887-><internal-IP>:5351: recvfrom: connection refused"
DEBUG[09-23|10:46:20.001] Couldn't get external IP                 err="read udp <internal-IP>:41751-><internal-IP>:5351: recvfrom: connection refused" interface=NAT-PMP(<internal-IP>)
DEBUG[09-23|10:46:20.001] set static ip in nat                     protocol=history ip=127.0.0.1

Same here, I noted the problem in the las 2 days, tried to set git HEAD to 21cfff5 (day 16 sep was working for sure). But still not working with old code, this let me believe it is external to Shisui. Investigating...

[GrapeBaBa]

with --nat pmp:<internal-IP>

TRACE[09-23|10:46:20.001] Attempting port mapping                  proto=UDP extport=9009 intport=9009 interface=NAT-PMP(<internal-IP>)
DEBUG[09-23|10:46:20.001] Couldn't add port mapping                proto=UDP extport=9009 intport=9009 interface=NAT-PMP(<internal-IP>) err="read udp <internal-IP>:37887-><internal-IP>:5351: recvfrom: connection refused"
DEBUG[09-23|10:46:20.001] Couldn't get external IP                 err="read udp <internal-IP>:41751-><internal-IP>:5351: recvfrom: connection refused" interface=NAT-PMP(<internal-IP>)
DEBUG[09-23|10:46:20.001] set static ip in nat                     protocol=history ip=127.0.0.1

Same here, I noted the problem in the las 2 days, tried to set git HEAD to 21cfff5 (day 16 sep was working for sure). But still not working with old code, this let me believe it is external to Shisui. Investigating...

Oh, thanks, we also met this problem. Right now we can only run the shisui with --nat "extip:xxx.xxx.xxx.xxx". It is strange the old version code also not working.

[dszlachta]

It is strange the old version code also not working.

Indeed. I think the last commit to p2p directory that changed code was this one: 064a3cf#diff-92c5e13d0f2918dc6e128ec3759e82e9b3e3a20049e388865d1a0a3da1b424feL176

I reverted it locally and when I run Shisui, it fails with bad bootstrap node "enr:-Jy4QIs2pCyiKna9YWnAF0zgf7bT0GzlAGoF8MEKFJOExmtofBIqzm71zDvmzRiiLkxaEJcs_Amr7XIhLI74k1rtlXICY5Z0IDAuMS4xLWFscGhhLjEtMTEwZjUwgmlkgnY0gmlwhKEjVaWJc2VjcDI1NmsxoQLSC_nhF1iRwsCw0n3J4jRjqoaRxtKgsEe5a-Dz7y0JloN1ZHCCIyg": missing IP address.

If you add code to print something if valid4 and valid6 are false, you we'll see that at least some ENRs are invalid.
It might not be the cause of the issue, but I think it's worth investigating.

[r4f4ss]

Sorry @GrapeBaBa I make a mistake, with --nat extip:xxx.xxx.xxx.xxx works in commit b061173 but not in portal branch head, probably some recent commit broke

[fearlessfe]

@dszlachta The default value of nat in erigon is none. you should add --nat none to run shisui.

But if you are behind a NAT, none means you don't have a public IP in p2p, so you cannot connect to other p2p node.

I run Erigon with default setting, It also have the same issue

[GrapeBaBa]

It is strange the old version code also not working.

Indeed. I think the last commit to p2p directory that changed code was this one: 064a3cf#diff-92c5e13d0f2918dc6e128ec3759e82e9b3e3a20049e388865d1a0a3da1b424feL176

I reverted it locally and when I run Shisui, it fails with bad bootstrap node "enr:-Jy4QIs2pCyiKna9YWnAF0zgf7bT0GzlAGoF8MEKFJOExmtofBIqzm71zDvmzRiiLkxaEJcs_Amr7XIhLI74k1rtlXICY5Z0IDAuMS4xLWFscGhhLjEtMTEwZjUwgmlkgnY0gmlwhKEjVaWJc2VjcDI1NmsxoQLSC_nhF1iRwsCw0n3J4jRjqoaRxtKgsEe5a-Dz7y0JloN1ZHCCIyg": missing IP address.

If you add code to print something if valid4 and valid6 are false, you we'll see that at least some ENRs are invalid. It might not be the cause of the issue, but I think it's worth investigating.

Thanks for investigating, we will check this.

[GrapeBaBa]

It is strange the old version code also not working.

Indeed. I think the last commit to p2p directory that changed code was this one: 064a3cf#diff-92c5e13d0f2918dc6e128ec3759e82e9b3e3a20049e388865d1a0a3da1b424feL176
I reverted it locally and when I run Shisui, it fails with bad bootstrap node "enr:-Jy4QIs2pCyiKna9YWnAF0zgf7bT0GzlAGoF8MEKFJOExmtofBIqzm71zDvmzRiiLkxaEJcs_Amr7XIhLI74k1rtlXICY5Z0IDAuMS4xLWFscGhhLjEtMTEwZjUwgmlkgnY0gmlwhKEjVaWJc2VjcDI1NmsxoQLSC_nhF1iRwsCw0n3J4jRjqoaRxtKgsEe5a-Dz7y0JloN1ZHCCIyg": missing IP address.
If you add code to print something if valid4 and valid6 are false, you we'll see that at least some ENRs are invalid. It might not be the cause of the issue, but I think it's worth investigating.

Thanks for investigating, we will check this.

And could you provide your erigon starting command, and what is the nat config for erigon?

[GrapeBaBa]

It seems nat not works perfect in geth code, but it does not effect their p2p. However in shisui we only use discv5, after discussion we may need add stun feature such as erigon and trin does.

[dszlachta]

And could you provide your erigon starting command, and what is the nat config for erigon?

I use DAppNode defaults: --http.api=engine,eth,erigon,web3,net,debug,trace,txpool --db.size.limit=8TB

[GrapeBaBa]

@dszlachta Right now you need --nat extip:xxx.xxx.xxx.xxx to run shisui, we will support no external ip once #176 finished.

[GrapeBaBa]

@dszlachta Can you use latest code to try using --nat stun?

[GrapeBaBa]

This should be fixed