filecoin-project / lotus

Reference implementation of the Filecoin protocol, written in Go
https://lotus.filecoin.io/
Other
2.83k stars 1.25k forks source link

can not sync node #8199

Closed yoberry closed 2 years ago

yoberry commented 2 years ago

Checklist

Lotus component

Lotus Version

Daemon:  1.14.2+mainnet+git.a65386b49+api1.5.0
Local: lotus version 1.14.2+mainnet+git.a65386b49

Describe the Bug

Lotus Daemon does not sync with the chain, it runs in error state seconds after imported the snapshot.

Sync Wait Worker: 51; Base: 1587120; Target: 1587994 (diff: 874) State: error; Current Epoch: 0; Todo: 1587994 Validated 336 messages (0 per second)

Sync Status sync status: worker 14: Base: [bafy2bzacedjanyfwi7aihcwosaok7ip6cycfy7hhkdvs4mbxe2vsb4iyjplh6 bafy2bzacebyaegnbnhvyyycy6u7mcbjzzkmy4kcz2pz7f73qyhagpr6ybwk6a bafy2bzacebfbof67ypezudftqeajldkrwa67t4r4amrazm4n6n3wpbiwxyguw bafy2bzacedycr5dutubx7b5nuwxgaoazkg6wrgly26c4gpjghplopghineviw bafy2bzaceamkbfb4mfsrvxcfkddcepwstgrk35jra4zenkolujlv6wd3hvu5k bafy2bzacedmwdkomstgaapuqsigm73lxk3jh3xtm7d6fbqvoqgquhmrqmduj6 bafy2bzaceblw67mvh7dnmjxqwm5nsicm7ac5qofqkxmhm67kzdxc3rzzc2hna] Target: [bafy2bzacebg367ckoi3ek7ahurx3uhe34dmd6e2pglcwtjppmadqhijbbvg52] (1587987) Height diff: 867 Stage: error Height: 0 Elapsed: 34.149µs Error: chain linked to block marked previously as bad ([bafy2bzacebg367ckoi3ek7ahurx3uhe34dmd6e2pglcwtjppmadqhijbbvg52], bafy2bzaceda727doizagf7x3hi3sfpyevykofus37czkqjjlxnp3gpbtss37e) (reason: linked to bafy2bzaceblf3a2iqiuvzdcrvkmsjauybq4swaxbeqtbgevzx463ddcf6x4do caused by: [bafy2bzacebin72qk7gwkgwjznxl3shw6lghnlpjulpm66bhqea7u72zsx5q3y] 2 errors occurred:

Daemon 2022-02-27T15:15:30.490+0800 INFO chain chain/sync_manager.go:232 selected sync target: [bafy2bzacecaa3ilwb2l44jlkka3g7y2b6hlazrklyrk2jm2yjisbcle7xt6hy] 2022-02-27T15:15:30.490+0800 INFO chain chain/sync_manager.go:314 worker 38 syncing in [bafy2bzacecaa3ilwb2l44jlkka3g7y2b6hlazrklyrk2jm2yjisbcle7xt6hy] 2022-02-27T15:15:30.490+0800 INFO chain chain/sync_manager.go:322 worker 38 done; took 36.188µs 2022-02-27T15:15:30.490+0800 ERROR chain chain/sync_manager.go:253 error during sync in [bafy2bzacecaa3ilwb2l44jlkka3g7y2b6hlazrklyrk2jm2yjisbcle7xt6hy]: collectChain failed: chain linked to block marked previously as bad ([bafy2bzacecaa3ilwb2l44jlkka3g7y2b6hlazrklyrk2jm2yjisbcle7xt6hy], bafy2bzacea7gon6ay7bsxlwvc2uvyvbufwfb5dqnouvy4iic3ovkdhveox2n2) (reason: linked to bafy2bzacedxotnbem3pugoe7wjzc7cfstpummhn4tyorc5kqa3u7ch3llj5we caused by: [bafy2bzacebin72qk7gwkgwjznxl3shw6lghnlpjulpm66bhqea7u72zsx5q3y] 2 errors occurred:

Logging Information

2022-02-27T15:26:20.684+0800    WARN    chain   chain/sync.go:217   InformNewHead called on block marked as bad: bafy2bzacecfm7h3xcj2auombjrjyp5vuccyrwlep5a364b6mqfx7lcgbclfay (reason: linked to bafy2bzacechuv62a6a2ehirw6sd6eqolyjj4sekts6hnwxdnqy7htx32ak5tm caused by: [bafy2bzacebin72qk7gwkgwjznxl3shw6lghnlpjulpm66bhqea7u72zsx5q3y] 2 errors occurred:
    * invalid election post:
    github.com/filecoin-project/lotus/chain/consensus/filcns.(*FilecoinEC).ValidateBlock.func9
        /home/jeff/lotus/chain/consensus/filcns/filecoin.go:302
  - failed to verify election post:
    github.com/filecoin-project/lotus/chain/consensus/filcns.(*FilecoinEC).VerifyWinningPoStProof
        /home/jeff/lotus/chain/consensus/filcns/filecoin.go:424
  - Rust panic: Once instance has previously been poisoned
    github.com/filecoin-project/filecoin-ffi.VerifyWinningPoSt
        /home/jeff/lotus/extern/filecoin-ffi/proofs.go:148
    github.com/filecoin-project/lotus/extern/sector-storage/ffiwrapper.proofVerifier.VerifyWinningPoSt
        /home/jeff/lotus/extern/sector-storage/ffiwrapper/verifier_cgo.go:156
    github.com/filecoin-project/lotus/chain/consensus/filcns.(*FilecoinEC).VerifyWinningPoStProof
        /home/jeff/lotus/chain/consensus/filcns/filecoin.go:417
    github.com/filecoin-project/lotus/chain/consensus/filcns.(*FilecoinEC).ValidateBlock.func9
        /home/jeff/lotus/chain/consensus/filcns/filecoin.go:301
    github.com/filecoin-project/lotus/lib/async.Err.func1
        /home/jeff/lotus/lib/async/error.go:40
    runtime.goexit
        /usr/local/go/src/runtime/asm_amd64.s:1581
    * parent state root did not match computed state (bafy2bzacea76jyykxrqwuijgmcih3mgbozrlyuhdeiryvn6xf7elsjojkl4dg != bafy2bzaceaksid6shvacwbkrq4dobdxbeklhhlogqxhp4mtbgo55hlylholnk):
    github.com/filecoin-project/lotus/chain/consensus/filcns.(*FilecoinEC).ValidateBlock.func4
        /home/jeff/lotus/chain/consensus/filcns/filecoin.go:185

)
2022-02-27T15:26:20.850+0800    DEBUG   pubsub  go-libp2p-pubsub@v0.5.6/gossipsub.go:807    GRAFT: add mesh link from 12D3KooWJYXCFUc8vVBMueirZYy1f3b8nBwbhPiZ9q7LNUtR1Gmy in /fil/blocks/testnetnet
2022-02-27T15:26:20.990+0800    DEBUG   stream-upgrader go-libp2p-transport-upgrader@v0.4.6/listener.go:97  listener <stream.Listener[TCP] /ip4/0.0.0.0/tcp/20015> got connection: /ip4/192.168.10.67/tcp/20015 <---> /ip4/202.111.192.174/tcp/55276
2022-02-27T15:26:20.994+0800    DEBUG   stream-upgrader go-libp2p-transport-upgrader@v0.4.6/listener.go:97  listener <stream.Listener[TCP] /ip4/0.0.0.0/tcp/20015> got connection: /ip4/192.168.10.67/tcp/20015 <---> /ip4/202.111.192.174/tcp/55274
2022-02-27T15:26:21.025+0800    DEBUG   stream-upgrader go-libp2p-transport-upgrader@v0.4.6/listener.go:120 listener <stream.Listener[TCP] /ip4/0.0.0.0/tcp/20015> accepted connection: <stream.Conn[TCP] /ip4/192.168.10.67/tcp/20015 (12D3KooWRLfek643ZUYsbnGR1xUTmQJxtdyf5Tx868SSYProM8Hx) <-> /ip4/202.111.192.174/tcp/55276 (12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32)>
2022-02-27T15:26:21.025+0800    DEBUG   swarm2  go-libp2p-swarm@v0.5.3/swarm_listen.go:103  swarm listener accepted connection: <stream.Conn[TCP] /ip4/192.168.10.67/tcp/20015 (12D3KooWRLfek643ZUYsbnGR1xUTmQJxtdyf5Tx868SSYProM8Hx) <-> /ip4/202.111.192.174/tcp/55276 (12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32)>
2022-02-27T15:26:21.025+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:21.025+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:21.025+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]
2022-02-27T15:26:21.025+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:109 ResolveUnspecifiedAddresses:[/ip4/0.0.0.0/tcp/20015 /ip6/::/tcp/33143] [/ip4/192.168.10.67 /ip4/127.0.0.1 /ip6/::1] [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015 /ip6/::1/tcp/33143]
2022-02-27T15:26:21.025+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:21.025+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/127.0.0.1/tcp/20015 /ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:21.025+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]
2022-02-27T15:26:21.025+0800    DEBUG   swarm2  go-libp2p-swarm@v0.5.3/swarm.go:334 [12D3KooWRLfek643ZUYsbnGR1xUTmQJxtdyf5Tx868SSYProM8Hx] opening stream to peer [12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32]
2022-02-27T15:26:21.026+0800    DEBUG   stream-upgrader go-libp2p-transport-upgrader@v0.4.6/listener.go:120 listener <stream.Listener[TCP] /ip4/0.0.0.0/tcp/20015> accepted connection: <stream.Conn[TCP] /ip4/192.168.10.67/tcp/20015 (12D3KooWRLfek643ZUYsbnGR1xUTmQJxtdyf5Tx868SSYProM8Hx) <-> /ip4/202.111.192.174/tcp/55274 (12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32)>
2022-02-27T15:26:21.026+0800    DEBUG   swarm2  go-libp2p-swarm@v0.5.3/swarm_listen.go:103  swarm listener accepted connection: <stream.Conn[TCP] /ip4/192.168.10.67/tcp/20015 (12D3KooWRLfek643ZUYsbnGR1xUTmQJxtdyf5Tx868SSYProM8Hx) <-> /ip4/202.111.192.174/tcp/55274 (12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32)>
2022-02-27T15:26:21.026+0800    DEBUG   pubsub  go-libp2p-pubsub@v0.5.6/pubsub.go:650   already have connection to peer: 12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32
2022-02-27T15:26:21.026+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:21.026+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:21.026+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]
2022-02-27T15:26:21.026+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:109 ResolveUnspecifiedAddresses:[/ip4/0.0.0.0/tcp/20015 /ip6/::/tcp/33143] [/ip4/192.168.10.67 /ip4/127.0.0.1 /ip6/::1] [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015 /ip6/::1/tcp/33143]
2022-02-27T15:26:21.026+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:21.026+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/127.0.0.1/tcp/20015 /ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:21.026+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]
2022-02-27T15:26:21.040+0800    DEBUG   basichost   basic/basic_host.go:370 protocol negotiation took 263.063µs
2022-02-27T15:26:21.040+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:21.040+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:21.041+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]
2022-02-27T15:26:21.041+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:109 ResolveUnspecifiedAddresses:[/ip4/0.0.0.0/tcp/20015 /ip6/::/tcp/33143] [/ip4/192.168.10.67 /ip4/127.0.0.1 /ip6/::1] [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015 /ip6/::1/tcp/33143]
2022-02-27T15:26:21.041+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:21.041+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/127.0.0.1/tcp/20015 /ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:21.041+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]
2022-02-27T15:26:21.041+0800    DEBUG   net/identify    identify/id.go:416  /ipfs/id/1.0.0 sent message to 12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32 /ip4/202.111.192.174/tcp/55276
2022-02-27T15:26:21.041+0800    INFO    net/identify    identify/id.go:372  failed negotiate identify protocol with peer    {"peer": "12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32", "error": "stream reset"}
2022-02-27T15:26:21.041+0800    DEBUG   net/identify    identify/id.go:435  /ipfs/id/1.0.0 received message from 12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32 /ip4/202.111.192.174/tcp/55276
2022-02-27T15:26:21.041+0800    DEBUG   net/identify    identify/id.go:631  12D3KooWRLfek643ZUYsbnGR1xUTmQJxtdyf5Tx868SSYProM8Hx received listen addrs for 12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32: [/ip4/192.168.2.103/tcp/41641 /ip4/202.111.192.174/tcp/41641 /ip4/202.111.192.174/tcp/17201 /ip4/202.111.192.174/tcp/30155]
2022-02-27T15:26:21.041+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:21.041+0800    DEBUG   swarm2  go-libp2p-swarm@v0.5.3/swarm.go:334 [12D3KooWRLfek643ZUYsbnGR1xUTmQJxtdyf5Tx868SSYProM8Hx] opening stream to peer [12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32]
2022-02-27T15:26:21.041+0800    DEBUG   dht go-libp2p-kad-dht@v0.13.0/dht.go:629    peer found  {"peer": "12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32"}
2022-02-27T15:26:21.041+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:21.041+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]
2022-02-27T15:26:21.041+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:109 ResolveUnspecifiedAddresses:[/ip4/0.0.0.0/tcp/20015 /ip6/::/tcp/33143] [/ip4/192.168.10.67 /ip4/127.0.0.1 /ip6/::1] [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015 /ip6/::1/tcp/33143]
2022-02-27T15:26:21.041+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:21.041+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/127.0.0.1/tcp/20015 /ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:21.041+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]
2022-02-27T15:26:21.041+0800    DEBUG   pubsub  go-libp2p-pubsub@v0.5.6/gossipsub.go:511    PEERUP: Add new peer 12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32 using /meshsub/1.1.0
2022-02-27T15:26:21.041+0800    DEBUG   net/identify    identify/obsaddr.go:402 added own observed listen addr  {"observed": "/ip4/58.41.19.37/tcp/20015"}
2022-02-27T15:26:21.042+0800    DEBUG   hello   hello/hello.go:155  Sending hello message: [bafy2bzacedjanyfwi7aihcwosaok7ip6cycfy7hhkdvs4mbxe2vsb4iyjplh6 bafy2bzacebyaegnbnhvyyycy6u7mcbjzzkmy4kcz2pz7f73qyhagpr6ybwk6a bafy2bzacebfbof67ypezudftqeajldkrwa67t4r4amrazm4n6n3wpbiwxyguw bafy2bzacedycr5dutubx7b5nuwxgaoazkg6wrgly26c4gpjghplopghineviw bafy2bzaceamkbfb4mfsrvxcfkddcepwstgrk35jra4zenkolujlv6wd3hvu5k bafy2bzacedmwdkomstgaapuqsigm73lxk3jh3xtm7d6fbqvoqgquhmrqmduj6 bafy2bzaceblw67mvh7dnmjxqwm5nsicm7ac5qofqkxmhm67kzdxc3rzzc2hna] 1587120 bafy2bzacecnamqgqmifpluoeldx7zzglxcljo6oja4vrmtj7432rphldpdmm2
2022-02-27T15:26:21.058+0800    DEBUG   basichost   basic/basic_host.go:370 protocol negotiation took 17.204205ms
2022-02-27T15:26:21.058+0800    DEBUG   basichost   basic/basic_host.go:370 protocol negotiation took 118.956µs
2022-02-27T15:26:21.058+0800    DEBUG   dht go-libp2p-kad-dht@v0.13.0/dht.go:629    peer found  {"peer": "12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32"}
2022-02-27T15:26:21.058+0800    DEBUG   dht go-libp2p-kad-dht@v0.13.0/dht_net.go:116    handling message    {"from": "12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32", "type": 4, "key": "EiAAAAtAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=="}
2022-02-27T15:26:21.058+0800    DEBUG   dht go-libp2p-kad-dht@v0.13.0/dht_net.go:133    handled message {"from": "12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32", "type": 4, "key": "EiAAAAtAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA==", "time": 0.000089557}
2022-02-27T15:26:21.058+0800    DEBUG   dht go-libp2p-kad-dht@v0.13.0/dht_net.go:159    responded to message    {"from": "12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32", "type": 4, "key": "EiAAAAtAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA==", "time": 0.00010347}
2022-02-27T15:26:21.059+0800    DEBUG   basichost   basic/basic_host.go:370 protocol negotiation took 1.110415ms
2022-02-27T15:26:21.059+0800    DEBUG   hello   hello/hello.go:80   genesis from hello  {"tipset": [{"/":"bafy2bzacecfm7h3xcj2auombjrjyp5vuccyrwlep5a364b6mqfx7lcgbclfay"},{"/":"bafy2bzacecaax5npyeibmqbog6sjwu3vkzw7ipwek7fvqlv3ri75euelnohau"}], "peer": "12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32", "hash": "bafy2bzacecnamqgqmifpluoeldx7zzglxcljo6oja4vrmtj7432rphldpdmm2"}
2022-02-27T15:26:21.061+0800    DEBUG   hello   hello/hello.go:127  Got new tipset through Hello: [bafy2bzacecfm7h3xcj2auombjrjyp5vuccyrwlep5a364b6mqfx7lcgbclfay bafy2bzacecaax5npyeibmqbog6sjwu3vkzw7ipwek7fvqlv3ri75euelnohau] from 12D3KooWB9xsEFqmKzMws5MafSZbFoDGXoKvu8R7PdEyt9WZ1o32
2022-02-27T15:26:21.061+0800    WARN    chain   chain/sync.go:217   InformNewHead called on block marked as bad: bafy2bzacecfm7h3xcj2auombjrjyp5vuccyrwlep5a364b6mqfx7lcgbclfay (reason: linked to bafy2bzacechuv62a6a2ehirw6sd6eqolyjj4sekts6hnwxdnqy7htx32ak5tm caused by: [bafy2bzacebin72qk7gwkgwjznxl3shw6lghnlpjulpm66bhqea7u72zsx5q3y] 2 errors occurred:
    * invalid election post:
    github.com/filecoin-project/lotus/chain/consensus/filcns.(*FilecoinEC).ValidateBlock.func9
        /home/jeff/lotus/chain/consensus/filcns/filecoin.go:302
  - failed to verify election post:
    github.com/filecoin-project/lotus/chain/consensus/filcns.(*FilecoinEC).VerifyWinningPoStProof
        /home/jeff/lotus/chain/consensus/filcns/filecoin.go:424
  - Rust panic: Once instance has previously been poisoned
    github.com/filecoin-project/filecoin-ffi.VerifyWinningPoSt
        /home/jeff/lotus/extern/filecoin-ffi/proofs.go:148
    github.com/filecoin-project/lotus/extern/sector-storage/ffiwrapper.proofVerifier.VerifyWinningPoSt
        /home/jeff/lotus/extern/sector-storage/ffiwrapper/verifier_cgo.go:156
    github.com/filecoin-project/lotus/chain/consensus/filcns.(*FilecoinEC).VerifyWinningPoStProof
        /home/jeff/lotus/chain/consensus/filcns/filecoin.go:417
    github.com/filecoin-project/lotus/chain/consensus/filcns.(*FilecoinEC).ValidateBlock.func9
        /home/jeff/lotus/chain/consensus/filcns/filecoin.go:301
    github.com/filecoin-project/lotus/lib/async.Err.func1
        /home/jeff/lotus/lib/async/error.go:40
    runtime.goexit
        /usr/local/go/src/runtime/asm_amd64.s:1581
    * parent state root did not match computed state (bafy2bzacea76jyykxrqwuijgmcih3mgbozrlyuhdeiryvn6xf7elsjojkl4dg != bafy2bzaceaksid6shvacwbkrq4dobdxbeklhhlogqxhp4mtbgo55hlylholnk):
    github.com/filecoin-project/lotus/chain/consensus/filcns.(*FilecoinEC).ValidateBlock.func4
        /home/jeff/lotus/chain/consensus/filcns/filecoin.go:185

)
2022-02-27T15:26:21.287+0800    DEBUG   gs-notifications    notifications/publisher.go:219  added notification command  {"cmd": {}, "queue len": 1}
2022-02-27T15:26:21.287+0800    DEBUG   gs-notifications    notifications/publisher.go:233  processing notification command {"cmd": {}, "remaining in queue": 0}
2022-02-27T15:26:21.411+0800    DEBUG   dht go-libp2p-kad-dht@v0.13.0/dht.go:629    peer found  {"peer": "12D3KooWP7qpi7ayNLiMd4ftpu1QQ5QpBQJjDvKmB8nRqqRMyucL"}
2022-02-27T15:26:21.411+0800    DEBUG   dht go-libp2p-kad-dht@v0.13.0/dht_net.go:116    handling message    {"from": "12D3KooWP7qpi7ayNLiMd4ftpu1QQ5QpBQJjDvKmB8nRqqRMyucL", "type": 4, "key": "EiAAAbToAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=="}
2022-02-27T15:26:21.411+0800    DEBUG   dht go-libp2p-kad-dht@v0.13.0/dht_net.go:133    handled message {"from": "12D3KooWP7qpi7ayNLiMd4ftpu1QQ5QpBQJjDvKmB8nRqqRMyucL", "type": 4, "key": "EiAAAbToAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA==", "time": 0.000113568}
2022-02-27T15:26:21.411+0800    DEBUG   dht go-libp2p-kad-dht@v0.13.0/dht_net.go:159    responded to message    {"from": "12D3KooWP7qpi7ayNLiMd4ftpu1QQ5QpBQJjDvKmB8nRqqRMyucL", "type": 4, "key": "EiAAAbToAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA==", "time": 0.000130189}
2022-02-27T15:26:21.862+0800    DEBUG   badgerbs    v2@v2.2007.2/db.go:774  writeRequests called. Writing to value log
2022-02-27T15:26:21.885+0800    DEBUG   badgerbs    v2@v2.2007.2/value.go:1451  Flushing buffer of size 33700513 to vlog
2022-02-27T15:26:21.958+0800    DEBUG   badgerbs    v2@v2.2007.2/value.go:1459  Done
2022-02-27T15:26:21.958+0800    DEBUG   badgerbs    v2@v2.2007.2/db.go:781  Sending updates to subscribers
2022-02-27T15:26:21.958+0800    DEBUG   badgerbs    v2@v2.2007.2/db.go:783  Writing to memtable
2022-02-27T15:26:21.979+0800    DEBUG   badgerbs    v2@v2.2007.2/db.go:814  16385 entries written
2022-02-27T15:26:23.031+0800    DEBUG   basichost   basic/basic_host.go:275 failed to fetch local IPv6 address  {"error": "no route found for ::"}
2022-02-27T15:26:23.031+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:23.031+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:23.031+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]
2022-02-27T15:26:23.031+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:109 ResolveUnspecifiedAddresses:[/ip4/0.0.0.0/tcp/20015 /ip6/::/tcp/33143] [/ip4/192.168.10.67 /ip4/127.0.0.1 /ip6/::1] [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015 /ip6/::1/tcp/33143]
2022-02-27T15:26:23.031+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:23.031+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/127.0.0.1/tcp/20015 /ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:23.032+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]
2022-02-27T15:26:23.164+0800    DEBUG   basichost   basic/basic_host.go:370 protocol negotiation took 22.580426937s
2022-02-27T15:26:23.191+0800    DEBUG   badgerbs    v2@v2.2007.2/db.go:774  writeRequests called. Writing to value log
2022-02-27T15:26:23.207+0800    DEBUG   badgerbs    v2@v2.2007.2/value.go:1451  Flushing buffer of size 25686626 to vlog
2022-02-27T15:26:23.262+0800    DEBUG   badgerbs    v2@v2.2007.2/value.go:1459  Done
2022-02-27T15:26:23.262+0800    DEBUG   badgerbs    v2@v2.2007.2/db.go:781  Sending updates to subscribers
2022-02-27T15:26:23.263+0800    DEBUG   badgerbs    v2@v2.2007.2/db.go:783  Writing to memtable
2022-02-27T15:26:23.290+0800    DEBUG   badgerbs    v2@v2.2007.2/db.go:814  16385 entries written
2022-02-27T15:26:23.583+0800    DEBUG   peermgr peermgr/peermgr.go:169  peer count about threshold: 102 > 32
2022-02-27T15:26:23.679+0800    DEBUG   nat go-libp2p-nat@v0.0.6/nat.go:172 Attempting port map: tcp/20015
2022-02-27T15:26:23.679+0800    DEBUG   nat go-libp2p-nat@v0.0.6/nat.go:172 Attempting port map: tcp/33143
2022-02-27T15:26:23.681+0800    DEBUG   nat go-libp2p-nat@v0.0.6/nat.go:193 NAT Mapping: 60293 --> 20015 (tcp)
2022-02-27T15:26:23.691+0800    DEBUG   nat go-libp2p-nat@v0.0.6/nat.go:193 NAT Mapping: 58883 --> 33143 (tcp)
2022-02-27T15:26:24.637+0800    DEBUG   dht go-libp2p-kad-dht@v0.13.0/dht.go:629    peer found  {"peer": "12D3KooWQtjXi4t4zoYq1BGmdvSv25ocXLdjpgyQhEE4m39irzCh"}
2022-02-27T15:26:24.637+0800    DEBUG   dht go-libp2p-kad-dht@v0.13.0/dht_net.go:116    handling message    {"from": "12D3KooWQtjXi4t4zoYq1BGmdvSv25ocXLdjpgyQhEE4m39irzCh", "type": 4, "key": "EiAAABSlAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=="}
2022-02-27T15:26:24.637+0800    DEBUG   dht go-libp2p-kad-dht@v0.13.0/dht_net.go:133    handled message {"from": "12D3KooWQtjXi4t4zoYq1BGmdvSv25ocXLdjpgyQhEE4m39irzCh", "type": 4, "key": "EiAAABSlAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA==", "time": 0.000103276}
2022-02-27T15:26:24.637+0800    DEBUG   dht go-libp2p-kad-dht@v0.13.0/dht_net.go:159    responded to message    {"from": "12D3KooWQtjXi4t4zoYq1BGmdvSv25ocXLdjpgyQhEE4m39irzCh", "type": 4, "key": "EiAAABSlAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA==", "time": 0.000123077}
2022-02-27T15:26:24.690+0800    DEBUG   badgerbs    v2@v2.2007.2/db.go:774  writeRequests called. Writing to value log
2022-02-27T15:26:24.708+0800    DEBUG   badgerbs    v2@v2.2007.2/value.go:1451  Flushing buffer of size 30931711 to vlog
2022-02-27T15:26:24.778+0800    DEBUG   badgerbs    v2@v2.2007.2/value.go:1459  Done
2022-02-27T15:26:24.779+0800    DEBUG   badgerbs    v2@v2.2007.2/db.go:781  Sending updates to subscribers
2022-02-27T15:26:24.779+0800    DEBUG   badgerbs    v2@v2.2007.2/db.go:783  Writing to memtable
2022-02-27T15:26:24.808+0800    DEBUG   badgerbs    v2@v2.2007.2/db.go:814  16385 entries written
2022-02-27T15:26:24.836+0800    DEBUG   stream-upgrader go-libp2p-transport-upgrader@v0.4.6/listener.go:97  listener <stream.Listener[TCP] /ip4/0.0.0.0/tcp/20015> got connection: /ip4/192.168.10.67/tcp/20015 <---> /ip4/183.178.77.23/tcp/39738
2022-02-27T15:26:24.906+0800    DEBUG   stream-upgrader go-libp2p-transport-upgrader@v0.4.6/listener.go:120 listener <stream.Listener[TCP] /ip4/0.0.0.0/tcp/20015> accepted connection: <stream.Conn[TCP] /ip4/192.168.10.67/tcp/20015 (12D3KooWRLfek643ZUYsbnGR1xUTmQJxtdyf5Tx868SSYProM8Hx) <-> /ip4/183.178.77.23/tcp/39738 (12D3KooWH1v6Km9qWi482rHDT9FZs7u62UydB2QwiUaxWQTqvFCr)>
2022-02-27T15:26:24.906+0800    DEBUG   swarm2  go-libp2p-swarm@v0.5.3/swarm_listen.go:103  swarm listener accepted connection: <stream.Conn[TCP] /ip4/192.168.10.67/tcp/20015 (12D3KooWRLfek643ZUYsbnGR1xUTmQJxtdyf5Tx868SSYProM8Hx) <-> /ip4/183.178.77.23/tcp/39738 (12D3KooWH1v6Km9qWi482rHDT9FZs7u62UydB2QwiUaxWQTqvFCr)>
2022-02-27T15:26:24.906+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:24.906+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:24.906+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]
2022-02-27T15:26:24.906+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:109 ResolveUnspecifiedAddresses:[/ip4/0.0.0.0/tcp/20015 /ip6/::/tcp/33143] [/ip4/192.168.10.67 /ip4/127.0.0.1 /ip6/::1] [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015 /ip6/::1/tcp/33143]
2022-02-27T15:26:24.906+0800    DEBUG   swarm2  go-libp2p-swarm@v0.5.3/swarm.go:334 [12D3KooWRLfek643ZUYsbnGR1xUTmQJxtdyf5Tx868SSYProM8Hx] opening stream to peer [12D3KooWH1v6Km9qWi482rHDT9FZs7u62UydB2QwiUaxWQTqvFCr]
2022-02-27T15:26:24.906+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:24.906+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/127.0.0.1/tcp/20015 /ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:24.906+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]
2022-02-27T15:26:24.940+0800    DEBUG   basichost   basic/basic_host.go:370 protocol negotiation took 30.877µs
2022-02-27T15:26:24.940+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:24.940+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:24.940+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]
2022-02-27T15:26:24.940+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:109 ResolveUnspecifiedAddresses:[/ip4/0.0.0.0/tcp/20015 /ip6/::/tcp/33143] [/ip4/192.168.10.67 /ip4/127.0.0.1 /ip6/::1] [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015 /ip6/::1/tcp/33143]
2022-02-27T15:26:24.940+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:24.940+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/127.0.0.1/tcp/20015 /ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:24.940+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]
2022-02-27T15:26:24.940+0800    DEBUG   net/identify    identify/id.go:416  /ipfs/id/1.0.0 sent message to 12D3KooWH1v6Km9qWi482rHDT9FZs7u62UydB2QwiUaxWQTqvFCr /ip4/183.178.77.23/tcp/39738
2022-02-27T15:26:24.973+0800    DEBUG   net/identify    identify/id.go:435  /ipfs/id/1.0.0 received message from 12D3KooWH1v6Km9qWi482rHDT9FZs7u62UydB2QwiUaxWQTqvFCr /ip4/183.178.77.23/tcp/39738
2022-02-27T15:26:24.974+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:24.974+0800    DEBUG   net/identify    identify/id.go:631  12D3KooWRLfek643ZUYsbnGR1xUTmQJxtdyf5Tx868SSYProM8Hx received listen addrs for 12D3KooWH1v6Km9qWi482rHDT9FZs7u62UydB2QwiUaxWQTqvFCr: [/ip4/10.62.88.35/tcp/31799]
2022-02-27T15:26:24.974+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:24.974+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]
2022-02-27T15:26:24.974+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:109 ResolveUnspecifiedAddresses:[/ip4/0.0.0.0/tcp/20015 /ip6/::/tcp/33143] [/ip4/192.168.10.67 /ip4/127.0.0.1 /ip6/::1] [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015 /ip6/::1/tcp/33143]
2022-02-27T15:26:24.974+0800    DEBUG   swarm2  go-libp2p-swarm@v0.5.3/swarm.go:334 [12D3KooWRLfek643ZUYsbnGR1xUTmQJxtdyf5Tx868SSYProM8Hx] opening stream to peer [12D3KooWH1v6Km9qWi482rHDT9FZs7u62UydB2QwiUaxWQTqvFCr]
2022-02-27T15:26:24.974+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:24.974+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/127.0.0.1/tcp/20015 /ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:24.974+0800    DEBUG   dht go-libp2p-kad-dht@v0.13.0/dht.go:646    peer stopped dht    {"peer": "12D3KooWH1v6Km9qWi482rHDT9FZs7u62UydB2QwiUaxWQTqvFCr"}
2022-02-27T15:26:24.974+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]
2022-02-27T15:26:24.974+0800    DEBUG   net/identify    identify/obsaddr.go:402 added own observed listen addr  {"observed": "/ip4/58.41.19.37/tcp/60293"}
2022-02-27T15:26:24.975+0800    DEBUG   basichost   basic/basic_host.go:370 protocol negotiation took 34.987748ms
2022-02-27T15:26:24.975+0800    DEBUG   dht go-libp2p-kad-dht@v0.13.0/dht.go:629    peer found  {"peer": "12D3KooWH1v6Km9qWi482rHDT9FZs7u62UydB2QwiUaxWQTqvFCr"}
2022-02-27T15:26:24.975+0800    DEBUG   dht go-libp2p-kad-dht@v0.13.0/dht_net.go:116    handling message    {"from": "12D3KooWH1v6Km9qWi482rHDT9FZs7u62UydB2QwiUaxWQTqvFCr", "type": 4, "key": "EiAAArt3AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=="}
2022-02-27T15:26:24.975+0800    DEBUG   dht go-libp2p-kad-dht@v0.13.0/dht_net.go:133    handled message {"from": "12D3KooWH1v6Km9qWi482rHDT9FZs7u62UydB2QwiUaxWQTqvFCr", "type": 4, "key": "EiAAArt3AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA==", "time": 0.000087434}
2022-02-27T15:26:24.975+0800    DEBUG   dht go-libp2p-kad-dht@v0.13.0/dht_net.go:159    responded to message    {"from": "12D3KooWH1v6Km9qWi482rHDT9FZs7u62UydB2QwiUaxWQTqvFCr", "type": 4, "key": "EiAAArt3AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA==", "time": 0.000103667}
2022-02-27T15:26:25.008+0800    DEBUG   modules modules/services.go:76  failed to say hello {"error": "error opening stream: protocol not supported", "errorVerbose": "error opening stream:\n    github.com/filecoin-project/lotus/node/hello.(*Service).SayHello\n        /home/jeff/lotus/node/hello/hello.go:135\n  - protocol not supported", "peer": "12D3KooWH1v6Km9qWi482rHDT9FZs7u62UydB2QwiUaxWQTqvFCr", "supported": ["/fil/storage/ask/1.1.0", "/fil/storage/ask/1.0.1", "/fil/storage/mk/1.1.0", "/ipfs/id/1.0.0", "/ipfs/id/push/1.0.0", "/fil/storage/status/1.1.0", "/fil/retrieval/qry/1.0.0", "/ipfs/ping/1.0.0", "/fil/storage/mk/1.0.1", "/ipfs/graphsync/1.0.0", "/fil/datatransfer/1.1.0", "/fil/datatransfer/1.0.0", "/fil/storage/status/1.0.1", "/fil/retrieval/qry/0.0.1", "/p2p/id/delta/1.0.0", "/libp2p/autonat/1.0.0"], "agent": "lotus-1.12.0+mainnet"}
2022-02-27T15:26:25.072+0800    DEBUG   pubsub  go-libp2p-pubsub@v0.5.6/comm.go:106 opening new stream to peer: protocol not supported12D3KooWH1v6Km9qWi482rHDT9FZs7u62UydB2QwiUaxWQTqvFCr
2022-02-27T15:26:25.127+0800    DEBUG   stream-upgrader go-libp2p-transport-upgrader@v0.4.6/listener.go:97  listener <stream.Listener[TCP] /ip4/0.0.0.0/tcp/20015> got connection: /ip4/192.168.10.67/tcp/20015 <---> /ip4/103.1.35.18/tcp/2054
2022-02-27T15:26:25.438+0800    DEBUG   stream-upgrader go-libp2p-transport-upgrader@v0.4.6/listener.go:120 listener <stream.Listener[TCP] /ip4/0.0.0.0/tcp/20015> accepted connection: <stream.Conn[TCP] /ip4/192.168.10.67/tcp/20015 (12D3KooWRLfek643ZUYsbnGR1xUTmQJxtdyf5Tx868SSYProM8Hx) <-> /ip4/103.1.35.18/tcp/2054 (12D3KooWK5p9L9RTcJGnRr7ZksANVbWbRu2DDpgaVrPZEr3QB2oZ)>
2022-02-27T15:26:25.438+0800    DEBUG   swarm2  go-libp2p-swarm@v0.5.3/swarm_listen.go:103  swarm listener accepted connection: <stream.Conn[TCP] /ip4/192.168.10.67/tcp/20015 (12D3KooWRLfek643ZUYsbnGR1xUTmQJxtdyf5Tx868SSYProM8Hx) <-> /ip4/103.1.35.18/tcp/2054 (12D3KooWK5p9L9RTcJGnRr7ZksANVbWbRu2DDpgaVrPZEr3QB2oZ)>
2022-02-27T15:26:25.438+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:25.438+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:25.438+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]
2022-02-27T15:26:25.438+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:109 ResolveUnspecifiedAddresses:[/ip4/0.0.0.0/tcp/20015 /ip6/::/tcp/33143] [/ip4/192.168.10.67 /ip4/127.0.0.1 /ip6/::1] [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015 /ip6/::1/tcp/33143]
2022-02-27T15:26:25.438+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:25.438+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/127.0.0.1/tcp/20015 /ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:25.438+0800    DEBUG   swarm2  go-libp2p-swarm@v0.5.3/swarm.go:334 [12D3KooWRLfek643ZUYsbnGR1xUTmQJxtdyf5Tx868SSYProM8Hx] opening stream to peer [12D3KooWK5p9L9RTcJGnRr7ZksANVbWbRu2DDpgaVrPZEr3QB2oZ]
2022-02-27T15:26:25.438+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]
2022-02-27T15:26:25.594+0800    DEBUG   basichost   basic/basic_host.go:370 protocol negotiation took 140.04µs
2022-02-27T15:26:25.594+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/192.168.10.67/tcp/20015 [/ip4/192.168.10.67/tcp/20015]
2022-02-27T15:26:25.594+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip4/0.0.0.0/tcp/20015 /ip4/127.0.0.1/tcp/20015 [/ip4/192.168.10.67/tcp/20015 /ip4/127.0.0.1/tcp/20015]
2022-02-27T15:26:25.594+0800    DEBUG   addrutil    go-addr-util@v0.1.0/addr.go:64  adding resolved addr:/ip6/::/tcp/33143 /ip6/::1/tcp/33143 [/ip6/::1/tcp/33143]

Repo Steps

  1. Run '...'
  2. Do '...'
  3. See error '...' ...
Reiers commented 2 years ago

Hi @yoberry

With no repro steps. My suggestion is that you re-import a snapshot and try to sync again. Remember to upgrade your node to our latest tag (v1.14.3).

1.aria2c -x5 https://fil-chain-snapshots-fallback.s3.amazonaws.com/mainnet/minimal_finality_stateroots_latest.car 2.lotus daemon --import-snapshot <the file you downloaded> --halt-after-import Wait until the process is done, and halted.

  1. lotus daemon
  2. open a second terminal lotus sync wait

https://lotus.filecoin.io/docs/set-up/chain-management/

Thanks for issue ticket - sending to Discussions for further troubleshooting and help!