ethereum / aleth

Aleth – Ethereum C++ client, tools and libraries
GNU General Public License v3.0
3.96k stars 2.17k forks source link

Snapshot download can fail because of exception #5869

Open chfast opened 4 years ago

chfast commented 4 years ago
TRACE 12-10 20:20:59 p2p  rlpx   ingress Frame header contents validated (##00000000…@15.164.211.134:50392)                                                   [390/1813]
TRACE 12-10 20:20:59 p2p  rlpx   ingress Frame body from (##00000000…@15.164.211.134:50392)                                                                             
TRACE 12-10 20:20:59 p2p  rlpx   ingress Hello verified. Starting session with (##00000000…@15.164.211.134:50392)                                                       
DEBUG 12-10 20:20:59 p2p  net    Starting peer session with Parity-Ethereum/v2.6.6-beta-5162bc2-20191205/x86_64-linux-gnu/rustc1.39.0 (protocol: V5) ##46b73c82… capabi$
ities: (par,1) port: 30303                                                                                                                                              
DEBUG 12-10 20:20:59 p2p  net    New session for capability par; idOffset: 16 with ##46b73c82…@15.164.211.134:50392                                                     
TRACE 12-10 20:20:59 p2p  net    WarpStatus to (##46b73c82…@15.164.211.134:50392)                                                                                       
TRACE 12-10 20:20:59 p2p  p2pcap Ping to (##46b73c82…@15.164.211.134:50392)                                                                                             
TRACE 12-10 20:20:59 p2p  net    Ping to (##46b73c82…@15.164.211.134:50392)                                                                                             
DEBUG 12-10 20:20:59 p2p  net    Peer connection successfully established with ##46b73c82…@15.164.211.134:50392                                                         
DEBUG 12-10 20:20:59 p2p  discov Pong from ##d2d3c7a4…@206.189.72.17:32800                                                                                              
DEBUG 12-10 20:20:59 p2p  discov Active node ##d2d3c7a4…@206.189.72.17:32800                                                                                            
DEBUG 12-10 20:20:59 p2p  discov Evicting node ##ef6a1058…@88.198.52.248:57955                                                                                          
DEBUG 12-10 20:20:59 p2p  discov Ping to ##ef6a1058…@88.198.52.248:57955                                                                                                
DEBUG 12-10 20:20:59 p2p  discov Ping from ##d2d3c7a4…@206.189.72.17:32800                                                                                              
DEBUG 12-10 20:20:59 p2p  discov Adding node ##d2d3c7a4…@206.189.72.17:32800                                                                                            
DEBUG 12-10 20:20:59 p2p  discov Pending ##d2d3c7a4…@206.189.72.17:32800                                                                                                
DEBUG 12-10 20:20:59 p2p  discov Pong to ##d2d3c7a4…@206.189.72.17:32800                                                                                                
DEBUG 12-10 20:20:59 p2p  discov Ping to ##d2d3c7a4…@206.189.72.17:32800                                                                                                
DEBUG 12-10 20:20:59 p2p  discov Pong from ##d2d3c7a4…@206.189.72.17:32800                                                                                              
DEBUG 12-10 20:20:59 p2p  discov Active node ##d2d3c7a4…@206.189.72.17:32800                                                                                            
DEBUG 12-10 20:20:59 p2p  discov Evicting node ##ef6a1058…@88.198.52.248:57955                                                                                          
DEBUG 12-10 20:20:59 p2p  discov Ignoring request to ping ##ef6a1058…@88.198.52.248:57955, because it's already pinged                                                  
DEBUG 12-10 20:20:59 p2p  discov Ping from ##d2d3c7a4…@206.189.72.17:32800                                                                                              
DEBUG 12-10 20:20:59 p2p  discov Adding node ##d2d3c7a4…@206.189.72.17:32800                                                                                            
DEBUG 12-10 20:20:59 p2p  discov Pending ##d2d3c7a4…@206.189.72.17:32800                                                                                                
DEBUG 12-10 20:20:59 p2p  discov Pong to ##d2d3c7a4…@206.189.72.17:32800                                                                                                
DEBUG 12-10 20:20:59 p2p  discov Ping to ##d2d3c7a4…@206.189.72.17:32800
DEBUG 12-10 20:20:59 p2p  discov Pong from ##ef6a1058…@88.198.52.248:57955
DEBUG 12-10 20:20:59 p2p  discov Active node ##ef6a1058…@88.198.52.248:57955
DEBUG 12-10 20:20:59 p2p  discov Ping from ##ef6a1058…@88.198.52.248:57955
DEBUG 12-10 20:20:59 p2p  discov Adding node ##ef6a1058…@88.198.52.248:57955
DEBUG 12-10 20:20:59 p2p  discov Pong to ##ef6a1058…@88.198.52.248:57955
DEBUG 12-10 20:20:59 p2p  discov Active node ##ef6a1058…@88.198.52.248:57955
  what():  The future has already been retrieved from the promise or packaged_task.
TRACE 12-10 20:20:59 p2p  net    Received Ping (2) from (##46b73c82…@15.164.211.134:50392)
TRACE 12-10 20:20:59 p2p  p2pcap Ping from (##46b73c82…@15.164.211.134:50392)
TRACE 12-10 20:20:59 p2p  p2pcap Pong to (##46b73c82…@15.164.211.134:50392)
TRACE 12-10 20:20:59 p2p  net    Pong to (##46b73c82…@15.164.211.134:50392)
Aborted (core dumped)
chfast commented 4 years ago

The same failure without -v 9.

INFO  12-11 09:25:03 p2p  snap   Saved chunk #132728bf… Chunks left: 3882 (peer: ##a344dec7…)
INFO  12-11 09:25:03 p2p  snap   Requested chunk #a4e11bdb… from ##a344dec7…
INFO  12-11 09:25:05 p2p  snap   Saved chunk #a4e11bdb… Chunks left: 3881 (peer: ##a344dec7…)
INFO  12-11 09:25:05 p2p  snap   Requested chunk #b88adcf8… from ##a344dec7…
INFO  12-11 09:25:30 p2p  net    Active peer count: 18
INFO  12-11 09:25:30 p2p  net    Looking for peers...
INFO  12-11 09:26:00 p2p  net    Active peer count: 17
INFO  12-11 09:26:00 p2p  net    Looking for peers...
ERROR 12-11 09:26:28 p2p  discov Invalid packet (bad hash) from 220.200.166.197:49683
INFO  12-11 09:26:30 p2p  net    Active peer count: 18
INFO  12-11 09:26:30 p2p  net    Looking for peers...
INFO  12-11 09:26:42 p2p  snap   Requested chunk #10d4a472… from ##a344dec7…
INFO  12-11 09:26:42 p2p  snap   Saved chunk #10d4a472… Chunks left: 3880 (peer: ##a344dec7…)
INFO  12-11 09:26:42 p2p  snap   Requested chunk #7fb74470… from ##a344dec7…
INFO  12-11 09:26:43 p2p  snap   Saved chunk #7fb74470… Chunks left: 3879 (peer: ##a344dec7…)
INFO  12-11 09:26:43 p2p  snap   Requested chunk #15ee49c6… from ##a344dec7…
INFO  12-11 09:26:44 p2p  snap   Saved chunk #15ee49c6… Chunks left: 3878 (peer: ##a344dec7…)
INFO  12-11 09:26:44 p2p  snap   Requested chunk #5fe14652… from ##a344dec7…
INFO  12-11 09:26:45 p2p  snap   Saved chunk #5fe14652… Chunks left: 3877 (peer: ##a344dec7…)
INFO  12-11 09:26:45 p2p  snap   Requested chunk #925043e4… from ##a344dec7…
ERROR 12-11 09:26:53 p2p  discov Invalid packet (bad hash) from 82.196.0.91:30305
INFO  12-11 09:27:00 p2p  net    Active peer count: 15
INFO  12-11 09:27:00 p2p  net    Looking for peers...
INFO  12-11 09:27:30 p2p  net    Active peer count: 15
INFO  12-11 09:27:30 p2p  net    Looking for peers...
INFO  12-11 09:28:00 p2p  net    Active peer count: 14
INFO  12-11 09:28:00 p2p  net    Looking for peers...
INFO  12-11 09:28:30 p2p  net    Active peer count: 14
INFO  12-11 09:28:30 p2p  net    Looking for peers...
INFO  12-11 09:28:56 p2p  snap   Requested chunk #48f6cbd9… from ##a344dec7…
INFO  12-11 09:28:57 p2p  snap   Saved chunk #48f6cbd9… Chunks left: 3876 (peer: ##a344dec7…)
INFO  12-11 09:28:57 p2p  snap   Requested chunk #97558094… from ##a344dec7…
INFO  12-11 09:28:58 p2p  snap   Saved chunk #97558094… Chunks left: 3875 (peer: ##a344dec7…)
INFO  12-11 09:28:58 p2p  snap   Requested chunk #6dc0ebac… from ##a344dec7…
INFO  12-11 09:28:59 p2p  snap   Saved chunk #6dc0ebac… Chunks left: 3874 (peer: ##a344dec7…)
INFO  12-11 09:28:59 p2p  snap   Requested chunk #61dcc2f3… from ##a344dec7…
INFO  12-11 09:29:00 p2p  net    Active peer count: 16
INFO  12-11 09:29:00 p2p  net    Looking for peers...
terminate called after throwing an instance of 'boost::fibers::future_already_retrieved'
  what():  The future has already been retrieved from the promise or packaged_task.
Aborted (core dumped)
chfast commented 4 years ago

Full log from start to failure:

aleth, a C++ Ethereum client
INFO  12-11 14:01:44 aleth net    Id: ##0c61fc7f…
INFO  12-11 14:01:44 aleth net    ENR: [ seq=2 id=v4 key=020c61fc… ip=3.132.57.159 tcp=30303 udp=30303 ]
aleth 1.8.0-alpha.1
INFO  12-11 14:01:46 p2p  info   UPnP device not found.
INFO  12-11 14:01:46 p2p  net    Active peer count: 0
INFO  12-11 14:01:46 p2p  net    Looking for peers...
Node ID: enode://0c61fc7fd20b3a5cabe69a37011b271b61fc405a74dabe44f7ab4ea32791b64e7745be2e247b7c7f9150636a9afbbf74aff285381e5478b919bcb5c76c193dec@127.0.0.1:30303
INFO  12-11 14:01:46 aleth rpc    JSON-RPC socket path: /home/ubuntu/.ethereum/geth.ipc
JSONRPC Admin Session Key: hRsHJUBQT8w=
INFO  12-11 14:01:58 p2p  snap   MANIFEST: version 2 state root #f7cebfda… block number 9060000 block hash #59b6d825…
INFO  12-11 14:01:58 p2p  snap   Requested chunk #a52d9043… from ##90ac12ff…
INFO  12-11 14:02:03 p2p  snap   Requested chunk #cb5a8c33… from ##ce67ef51…
INFO  12-11 14:02:06 p2p  snap   Saved chunk #cb5a8c33… Chunks left: 3963 (peer: ##ce67ef51…)
INFO  12-11 14:02:06 p2p  snap   Requested chunk #1661dd7e… from ##ce67ef51…
INFO  12-11 14:02:16 p2p  net    Active peer count: 1
INFO  12-11 14:02:16 p2p  net    Looking for peers...
INFO  12-11 14:02:46 p2p  net    Active peer count: 1
INFO  12-11 14:02:46 p2p  net    Looking for peers...
INFO  12-11 14:03:00 p2p  snap   Saved chunk #a52d9043… Chunks left: 3963 (peer: ##90ac12ff…)
INFO  12-11 14:03:00 p2p  snap   Requested chunk #f82895d2… from ##90ac12ff…
INFO  12-11 14:03:04 p2p  snap   Requested chunk #5c94e2bb… from ##90ac12ff…
INFO  12-11 14:03:08 p2p  snap   Saved chunk #5c94e2bb… Chunks left: 3962 (peer: ##90ac12ff…)
INFO  12-11 14:03:08 p2p  snap   Requested chunk #2ddc74bd… from ##90ac12ff…
INFO  12-11 14:03:11 p2p  snap   Requested chunk #8d19e559… from ##90ac12ff…
INFO  12-11 14:03:16 p2p  net    Active peer count: 5
INFO  12-11 14:03:16 p2p  net    Looking for peers...
INFO  12-11 14:03:31 p2p  snap   Requested chunk #fd8e0d02… from ##90ac12ff…
INFO  12-11 14:03:35 p2p  snap   Saved chunk #fd8e0d02… Chunks left: 3961 (peer: ##90ac12ff…)
INFO  12-11 14:03:35 p2p  snap   Requested chunk #2b74c230… from ##90ac12ff…
INFO  12-11 14:03:46 p2p  net    Active peer count: 5
INFO  12-11 14:03:46 p2p  net    Looking for peers...
INFO  12-11 14:04:02 p2p  snap   Requested chunk #cbed8fe0… from ##ce67ef51…
INFO  12-11 14:04:04 p2p  snap   Requested chunk #c196a0ea… from ##ae1df229…
INFO  12-11 14:04:16 p2p  net    Active peer count: 4
INFO  12-11 14:04:16 p2p  net    Looking for peers...
INFO  12-11 14:04:29 p2p  snap   Requested chunk #ab93e831… from ##90ac12ff…
INFO  12-11 14:04:33 p2p  snap   Saved chunk #ab93e831… Chunks left: 3959 (peer: ##90ac12ff…)
INFO  12-11 14:04:33 p2p  snap   Requested chunk #93a16a23… from ##90ac12ff…
INFO  12-11 14:04:35 p2p  snap   Requested chunk #e40bc2ff… from ##90ac12ff…
INFO  12-11 14:04:42 p2p  snap   Saved chunk #e40bc2ff… Chunks left: 3958 (peer: ##90ac12ff…)
INFO  12-11 14:04:42 p2p  snap   Requested chunk #b2bb50e1… from ##90ac12ff…
INFO  12-11 14:04:46 p2p  net    Active peer count: 5
INFO  12-11 14:04:46 p2p  net    Looking for peers...
INFO  12-11 14:04:54 p2p  snap   Requested chunk #7d89c925… from ##0b6de411…
INFO  12-11 14:05:08 p2p  snap   Saved chunk #7d89c925… Chunks left: 3957 (peer: ##0b6de411…)
INFO  12-11 14:05:08 p2p  snap   Requested chunk #f93fa39f… from ##0b6de411…
INFO  12-11 14:05:16 p2p  net    Active peer count: 5
INFO  12-11 14:05:16 p2p  net    Looking for peers...
INFO  12-11 14:05:33 p2p  snap   Requested chunk #3ee6c691… from ##90ac12ff…
INFO  12-11 14:05:38 p2p  snap   Saved chunk #3ee6c691… Chunks left: 3956 (peer: ##90ac12ff…)
INFO  12-11 14:05:38 p2p  snap   Requested chunk #94f6f2f7… from ##90ac12ff…
INFO  12-11 14:05:40 p2p  snap   Requested chunk #4fe9bbd8… from ##ce67ef51…
INFO  12-11 14:05:42 p2p  snap   Saved chunk #4fe9bbd8… Chunks left: 3955 (peer: ##ce67ef51…)
INFO  12-11 14:05:42 p2p  snap   Requested chunk #f30334ce… from ##ce67ef51…
INFO  12-11 14:05:43 p2p  snap   Saved chunk #f30334ce… Chunks left: 3954 (peer: ##ce67ef51…)
INFO  12-11 14:05:43 p2p  snap   Requested chunk #0a87b30e… from ##ce67ef51…
INFO  12-11 14:05:46 p2p  net    Active peer count: 8
INFO  12-11 14:05:46 p2p  net    Looking for peers...
INFO  12-11 14:05:46 p2p  snap   Requested chunk #a38c6e15… from ##ce67ef51…
INFO  12-11 14:05:49 p2p  snap   Saved chunk #a38c6e15… Chunks left: 3953 (peer: ##ce67ef51…)
INFO  12-11 14:05:49 p2p  snap   Requested chunk #6ea0af5a… from ##ce67ef51…
INFO  12-11 14:05:58 p2p  snap   Requested chunk #1389b391… from ##ce67ef51…
INFO  12-11 14:06:00 p2p  snap   Requested chunk #4ed1b8a3… from ##ce67ef51…
INFO  12-11 14:06:02 p2p  snap   Saved chunk #4ed1b8a3… Chunks left: 3952 (peer: ##ce67ef51…)
INFO  12-11 14:06:02 p2p  snap   Requested chunk #ce0ba574… from ##ce67ef51…
INFO  12-11 14:06:06 p2p  snap   Saved chunk #ce0ba574… Chunks left: 3951 (peer: ##ce67ef51…)
INFO  12-11 14:06:06 p2p  snap   Requested chunk #b3722043… from ##ce67ef51…
INFO  12-11 14:06:16 p2p  net    Active peer count: 7
INFO  12-11 14:06:16 p2p  net    Looking for peers...
INFO  12-11 14:06:43 p2p  snap   Requested chunk #c89eebb8… from ##90ac12ff…
INFO  12-11 14:06:46 p2p  net    Active peer count: 8
INFO  12-11 14:06:46 p2p  net    Looking for peers...
INFO  12-11 14:06:51 p2p  snap   Saved chunk #c89eebb8… Chunks left: 3950 (peer: ##90ac12ff…)
INFO  12-11 14:06:51 p2p  snap   Requested chunk #751c8d3e… from ##90ac12ff…
ERROR 12-11 14:07:01 p2p  discov Invalid packet (bad hash) from 82.196.0.91:30305
INFO  12-11 14:07:16 p2p  net    Active peer count: 7
INFO  12-11 14:07:16 p2p  net    Looking for peers...
terminate called after throwing an instance of 'boost::fibers::future_already_retrieved'
  what():  The future has already been retrieved from the promise or packaged_task.