etclabscore / core-geth

A highly configurable Go implementation of the Ethereum protocol.
https://etclabscore.github.io/core-geth
GNU Lesser General Public License v3.0
276 stars 152 forks source link

v1.12.9+: RPC server shutting down (then node stalling after startup) #520

Closed meowsbits closed 1 year ago

meowsbits commented 1 year ago

If you run into an issue where

The issue is that core-geth v1.12.9 (following ethereum/go-ethereum v1.10.21 ) introduces flags for --authrpc which have defaults that will collide and tacitly cause the node to hang.

    --authrpc.addr value           (default: "localhost")
          Listening address for authenticated APIs
    --authrpc.jwtsecret value     
          Path to a JWT secret to use for authenticated RPC endpoints
    --authrpc.port value           (default: 8551)
          Listening port for authenticated APIs
    --authrpc.vhosts value         (default: "localhost")
          Ephemeral proof-of-authority network with a pre-funded developer account, mining
          Block period for proof-of-authority network to use in developer mode (0 = mine
          Görli network: pre-configured proof-of-authority test network
          Kotti network: cross-client proof-of-authority test network
          Rinkeby network: pre-configured proof-of-authority test network
          Password to authorize access to the database
          Token to authorize access to the database (v2 only)
          Username to authorize access to the database

Resolution

To fix this you need to configure a unique --authrpc.port value.


System information

./build/bin/geth version
CoreGeth
Version: 1.12.9-stable
Git Commit: c17c5ae18e393971d3f7910330305526d902e422
Architecture: amd64
Go Version: go1.19.2
Operating System: linux
GOPATH=/home/ia/go
GOROOT=/home/ia/go1.19.2.linux-amd64

OS & Version: Linux

Backtrace

Jan 24 09:35:41 ubp52 sh[78624]: INFO [01-24|09:35:41.708] Starting peer-to-peer node               instance=CoreGeth/v1.12.9-stable-c17c5ae1/linux-amd64/go1.19.2                                   
Jan 24 09:35:41 ubp52 sh[78624]: INFO [01-24|09:35:41.712] Resuming state snapshot generation       root=d7f897..0f0544 accounts=0 slots=0 storage=0.00B dangling=0 elapsed=21.622ms                 
Jan 24 09:35:41 ubp52 sh[78624]: DEBUG[01-24|09:35:41.756] UDP listener up                          addr=[::]:30362                                                                                  
Jan 24 09:35:41 ubp52 sh[78624]: INFO [01-24|09:35:41.757] New local node record                    seq=1,674,581,741,757 id=1ea46d376e5b0da6 ip=127.0.0.1 udp=30362 tcp=30362                       
Jan 24 09:35:41 ubp52 sh[78624]: DEBUG[01-24|09:35:41.758] IPCs registered                          namespaces=admin,debug,web3,eth,txpool,personal,ethash,miner,net,engine,trace                    
Jan 24 09:35:41 ubp52 sh[78624]: INFO [01-24|09:35:41.759] IPC endpoint opened                      url=/tmp/core-geth_classic_development2.ipc                                                      
Jan 24 09:35:41 ubp52 sh[78624]: INFO [01-24|09:35:41.759] Generated JWT secret                     path=/tmp/geth_dev/classic2/geth/jwtsecret                                                       
Jan 24 09:35:41 ubp52 sh[78624]: DEBUG[01-24|09:35:41.759] Allowed origin(s) for WS RPC interface [localhost]                                                                                        
Jan 24 09:35:41 ubp52 sh[78624]: INFO [01-24|09:35:41.759] HTTP server started                      endpoint=[::]:8062 auth=false prefix= cors=* vhosts=*                                            
Jan 24 09:35:41 ubp52 sh[78624]: DEBUG[01-24|09:35:41.768] TCP listener up                          addr=[::]:30362                                                                                  
Jan 24 09:35:41 ubp52 sh[78624]: INFO [01-24|09:35:41.804] Started P2P networking                   self=enode://65d5587e83e387571f95c93a4a6ffa302733f7bad0fdba648719aa8e6b8b8ba65cfbb293be85dc06fc9cd4101b25
4759fe8069aa79f92090b87868e4534ab43e@127.0.0.1:30362                                                                                                                                                         
Jan 24 09:35:41 ubp52 sh[78624]: DEBUG[01-24|09:35:41.804] RPC server shutting down                                                                                                                          
Jan 24 09:35:41 ubp52 sh[78624]: DEBUG[01-24|09:35:41.804] RPC server shutting down                                                                                                                          
Jan 24 09:35:41 ubp52 sh[78624]: DEBUG[01-24|09:35:41.804] RPC server shutting down                                                                                                                          
Jan 24 09:35:41 ubp52 sh[78624]: WARN [01-24|09:35:41.804] HTTP server graceful shutdown timed out                                                                                                           
Jan 24 09:35:41 ubp52 sh[78624]: INFO [01-24|09:35:41.805] HTTP server stopped                      endpoint=[::]:8062                                                                                       
Jan 24 09:35:41 ubp52 sh[78624]: DEBUG[01-24|09:35:41.805] RPC server shutting down                                                                                                                          
Jan 24 09:35:41 ubp52 sh[78624]: INFO [01-24|09:35:41.805] IPC endpoint closed                      url=/tmp/core-geth_classic_development2.ipc                                                              
Jan 24 09:35:41 ubp52 sh[78624]: DEBUG[01-24|09:35:41.805] RPC server shutting down                                                                                                                          
Jan 24 09:35:41 ubp52 sh[78624]: DEBUG[01-24|09:35:41.805] Read error                               err="accept tcp [::]:30362: use of closed network connection"                                            
Jan 24 09:35:41 ubp52 sh[78624]: DEBUG[01-24|09:35:41.805] UDP read error                           err="read udp [::]:30362: use of closed network connection"                                              
Jan 24 09:35:41 ubp52 sh[78624]: DEBUG[01-24|09:35:41.836] Journalled generator progress            progress=0x3d45dbfe8844979977e1967ae6e5223e5a82ce87b09cab51c2865987fa20ec91                              
Jan 24 09:35:41 ubp52 sh[78624]: DEBUG[01-24|09:35:41.899] Journalled generator progress            progress=0x7e3c9d2181192ecfdf638030d6fe66df68a2f678d3b8bedd77faacc1257cd013                              
Jan 24 09:35:41 ubp52 sh[78624]: DEBUG[01-24|09:35:41.951] Journalled generator progress            progress=0xbba51af3f5e64c8c1b0c3335acc4aa270172e67aa87924bbb06bffd08ef4be4b                      
Jan 24 09:35:41 ubp52 sh[78624]: DEBUG[01-24|09:35:41.972] Journalled generator progress            progress=0xfa63c2c56b30333c79307e088be6e27b37ea2b78c808724e15a8ff2d7b70caaf                              
Jan 24 09:35:41 ubp52 sh[78624]: DEBUG[01-24|09:35:41.976] Regenerated state range                  kind=account prefix=0x61 root=d7f897..0f0544 last=0x count=8893 created=8893 updated=0 untouched=0 delete
d=0                                                                                                                                                                                                          
Jan 24 09:35:41 ubp52 sh[78624]: DEBUG[01-24|09:35:41.976] Journalled generator progress            progress=done                                                                                    
Jan 24 09:35:41 ubp52 sh[78624]: INFO [01-24|09:35:41.979] Generated state snapshot                 accounts=8893 slots=0 storage=409.64KiB dangling=0 elapsed=288.678ms                             
Jan 24 09:35:43 ubp52 sh[78624]: DEBUG[01-24|09:35:43.932] Couldn't add port mapping                proto=udp extport=30362 intport=30362 interface="UPnP or NAT-PMP" err="no UPnP or NAT-PMP router discover
ed"                                                                                                                                                                                                          
Jan 24 09:35:43 ubp52 sh[78624]: DEBUG[01-24|09:35:43.932] Deleting port mapping                    proto=udp extport=30362 intport=30362 interface="UPnP or NAT-PMP"                                
Jan 24 09:35:43 ubp52 sh[78624]: DEBUG[01-24|09:35:43.932] Couldn't add port mapping                proto=tcp extport=30362 intport=30362 interface="UPnP or NAT-PMP" err="no UPnP or NAT-PMP router discover
ed"                                                                                                                                                                                                          
Jan 24 09:35:43 ubp52 sh[78624]: DEBUG[01-24|09:35:43.932] Deleting port mapping                    proto=tcp extport=30362 intport=30362 interface="UPnP or NAT-PMP"                                        
Jan 24 09:35:46 ubp52 sh[78624]: DEBUG[01-24|09:35:46.780] Error in DNS random node sync            tree=all.classic.blockd.info err="lookup all.classic.blockd.info on 127.0.0.53:53: dial udp 127.0.0.53:53
: operation was canceled"                                                                                                                                                                                    
Jan 24 09:35:46 ubp52 sh[78624]: DEBUG[01-24|09:35:46.780] Error in DNS random node sync            tree=all.classic.blockd.info err="lookup all.classic.blockd.info on 127.0.0.53:53: dial udp 127.0.0.53:53
: operation was canceled"                                                                                                                                                                                    
Jan 24 09:35:46 ubp52 sh[78624]: INFO [01-24|09:35:46.784] Stats daemon started                                                                                                                              
Jan 24 09:35:46 ubp52 sh[78624]: DEBUG[01-24|09:35:46.840] RPC connection read error                err=EOF                                                                                          
Jan 24 09:35:51 ubp52 sh[78624]: WARN [01-24|09:35:51.800] Stats server unreachable                 err="dial tcp 91.203.110.229:3000: i/o timeout"        

When submitting logs: please submit them as text and not screenshots.

meowsbits commented 1 year ago

As noted in the OP, this Issue has steps to resolution noted above, and this issue is now for documentation.