search

filecoin-project / lotus

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

Lotus daemon crashes due to unexpected fault address #2664

Closed coder-lb closed 2 years ago

coder-lb commented 4 years ago

Describe the bug Lotus daemon crashes due to unexpected fault address when running calibration network.

To Reproduce Running lotus daemon in calibration network.

Expected behavior Lotus daemon continues to run normally.

Version (run lotus version): v0.4.2
Commit: 477dd536b5b5824a411c24a710af8f8550eb8fdc

Additional context Call trace: 

2020-07-29T19:32:06.585+0800    ^[[34mINFO^[[0m pubsub  go-libp2p-pubsub@v0.3.2/comm.go:51      error reading rpc from 12D3KooWQ4Ub3Fueom8QQXcNmUCkriAAmWzp289WtjCMQt98hgbf: stream reset
unexpected fault address 0x7face6255fc3
fatal error: fault
[signal SIGBUS: bus error code=0x2 addr=0x7face6255fc3 pc=0xefaa65]

goroutine 4589806 [running]:
runtime.throw(0x2a117f2, 0x5)
       /usr/lib/go-1.14/src/runtime/panic.go:1112 +0x72 fp=0xc003a990b0 sp=0xc003a99080 pc=0x5693b2
runtime.sigpanic()
        /usr/lib/go-1.14/src/runtime/signal_unix.go:684 +0x443 fp=0xc003a990e0 sp=0xc003a990b0 pc=0x5802a3
github.com/dgraph-io/badger/v2.(*header).Decode(0xc003a991c0, 0x7face6255fc3, 0x61c, 0x71daa03b, 0x7face6255fc3)
        /home/filecoin/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200716180832-3ab515320794/structs.go:97 +0x35 fp=0xc003a99128 sp=0xc003a990e0 pc=0xefaa65
github.com/dgraph-io/badger/v2.(*valueLog).Read(0xc000228dd0, 0x61c00000001, 0xe255fc3, 0xc038906d00, 0xc03466592b, 0x541116, 0x37659ce, 0x182c8, 0x0, 0x0)
        /home/filecoin/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200716180832-3ab515320794/value.go:1560 +0x145 fp=0xc003a99270 sp=0xc003a99128 pc=0xf08955
github.com/dgraph-io/badger/v2.(*Item).yieldItemValue(0xc0258d0210, 0x37659ce, 0x182c8, 0x0, 0x0, 0xc, 0xc018399852)
        /home/filecoin/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200716180832-3ab515320794/iterator.go:170 +0x12e fp=0xc003a993e0 sp=0xc003a99270 pc=0xedc0fe
github.com/dgraph-io/badger/v2.(*Item).ValueCopy(0xc0258d0210, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
        /home/filecoin/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200716180832-3ab515320794/iterator.go:127 +0x179 fp=0xc003a99498 sp=0xc003a993e0 pc=0xedbde9
github.com/ipfs/go-ds-badger2.(*txn).get(0xc003a99550, 0xc0183996d0, 0x42, 0xc0183996d0, 0x42, 0xc01d425560, 0x58b719, 0x1627159bdcb2d6)
        /home/filecoin/go/pkg/mod/github.com/ipfs/go-ds-badger2@v0.1.1-0.20200708190120-187fc06f714e/datastore.go:512 +0xe1 fp=0xc003a99508 sp=0xc003a99498 pc=0xf1d961
github.com/ipfs/go-ds-badger2.(*Datastore).Get(0xc00042e720, 0xc0183996d0, 0x42, 0x0, 0x0, 0x0, 0x0, 0x0)
        /home/filecoin/go/pkg/mod/github.com/ipfs/go-ds-badger2@v0.1.1-0.20200708190120-187fc06f714e/datastore.go:302 +0x16e fp=0xc003a99598 sp=0xc003a99508 pc=0xf1bc8e
github.com/ipfs/go-ds-measure.(*measure).Get(0xc0001f2300, 0xc0183996d0, 0x42, 0x0, 0x0, 0x0, 0x0, 0x0)
        /home/filecoin/go/pkg/mod/github.com/ipfs/go-ds-measure@v0.1.0/measure.go:198 +0xf5 fp=0xc003a99620 sp=0xc003a99598 pc=0xf84925
github.com/ipfs/go-datastore/keytransform.(*Datastore).Get(0xc0003dae00, 0xc028fdc140, 0x3b, 0xc028fdc140, 0x3b, 0x0, 0x24, 0x20)
        /home/filecoin/go/pkg/mod/github.com/ipfs/go-datastore@v0.4.4/keytransform/keytransform.go:47 +0x76 fp=0xc003a99670 sp=0xc003a99620 pc=0xaa20c6
github.com/ipfs/go-ipfs-blockstore.(*blockstore).Get(0xc0003dae40, 0xc021f28d50, 0x26, 0x0, 0x0, 0x0, 0xc000797da0)
        /home/filecoin/go/pkg/mod/github.com/ipfs/go-ipfs-blockstore@v1.0.0/blockstore.go:122 +0xa5 fp=0xc003a99720 sp=0xc003a99670 pc=0xaa70f5
github.com/ipfs/go-ipfs-blockstore.(*idstore).Get(0xc00023e1f0, 0xc021f28d50, 0x26, 0xaa8a01, 0x5c8, 0xc01a57e501, 0x24)
        /home/filecoin/go/pkg/mod/github.com/ipfs/go-ipfs-blockstore@v1.0.0/idstore.go:57 +0xd7 fp=0xc003a99770 sp=0xc003a99720 pc=0xaa97c7
github.com/ipfs/go-ipfs-blockstore.(*arccache).Get(0xc000a0e640, 0xc021f28d50, 0x26, 0x0, 0xc018fa7dc0, 0x0, 0x0)
        /home/filecoin/go/pkg/mod/github.com/ipfs/go-ipfs-blockstore@v1.0.0/arc_cache.go:118 +0xad fp=0xc003a99800 sp=0xc003a99770 pc=0xaa64dd
github.com/ipfs/go-ipfs-blockstore.(*bloomcache).Get(0xc000797e00, 0xc021f28d50, 0x26, 0x0, 0x0, 0x0, 0xc01c3f6a20)
        /home/filecoin/go/pkg/mod/github.com/ipfs/go-ipfs-blockstore@v1.0.0/bloom_cache.go:159 +0x80 fp=0xc003a99848 sp=0xc003a99800 pc=0xaa8ca0
github.com/ipfs/go-ipfs-blockstore.(*idstore).Get(0xc00023e3b0, 0xc021f28d50, 0x26, 0xffffffffffffff00, 0x1, 0xc01d425960, 0x541116)
        /home/filecoin/go/pkg/mod/github.com/ipfs/go-ipfs-blockstore@v1.0.0/idstore.go:57 +0xd7 fp=0xc003a99898 sp=0xc003a99848 pc=0xaa97c7
github.com/ipfs/go-ipld-cbor.(*BasicIpldStore).Get(0xc038906ca0, 0x2e2b300, 0xc0000480c0, 0xc021f28d50, 0x26, 0x2987b00, 0xc018fa7d80, 0x53df01, 0xc018fa7d80)
        /home/filecoin/go/pkg/mod/github.com/ipfs/go-ipld-cbor@v0.0.5-0.20200428170625-a0bd04d3cbdf/store.go:44 +0x62 fp=0xc003a99948 sp=0xc003a99898 pc=0x773dd2
github.com/filecoin-project/specs-actors/actors/util/adt.(*wstore).Get(0xc038906cc0, 0x2e2b300, 0xc0000480c0, 0xc021f28d50, 0x26, 0x2987b00, 0xc018fa7d80, 0x27a95e0, 0x27b5b60)
        <autogenerated>:1 +0x87 fp=0xc003a999a0 sp=0xc003a99948 pc=0xa0a0e7
github.com/ipfs/go-hamt-ipld.LoadNode(0x2e2b300, 0xc0000480c0, 0x7fb52c36d820, 0xc038906cc0, 0xc021f28d50, 0x26, 0x5450b50, 0x2, 0x2, 0x20300e, ...)
        /home/filecoin/go/pkg/mod/github.com/ipfs/go-hamt-ipld@v0.1.1/hamt.go:166 +0x91 fp=0xc003a99a08 sp=0xc003a999a0 pc=0xa020d1
github.com/filecoin-project/specs-actors/actors/util/adt.AsMap(0x2e1dc00, 0xc038906cc0, 0xc021f28d50, 0x26, 0xc026e40578, 0x18, 0x18)                                                                                                         
        /home/filecoin/go/pkg/mod/github.com/filecoin-project/specs-actors@v0.8.1-0.20200728182452-1476088f645b/actors/util/adt/map.go:39 +0xf1 fp=0xc003a99aa0 sp=0xc003a99a08 pc=0xa074a1      
github.com/filecoin-project/lotus/chain/state.LoadStateTree(0x2e102c0, 0xc038906ca0, 0xc021f28d50, 0x26, 0xc00023e3b0, 0x1, 0x0)                                                                                                              
        /home/filecoin/interopnet/chain/state/statetree.go:128 +0xca fp=0xc003a99b68 sp=0xc003a99aa0 pc=0xc9659a                                                                                                                                  
github.com/filecoin-project/lotus/chain/store.(*ChainStore).Weight(0xc00012a400, 0x2e2b2c0, 0xc027e9d0c0, 0xc02bf74fc0, 0x26, 0xc0131ee430, 0x1)                                                                                              
        /home/filecoin/interopnet/chain/store/weight.go:32 +0x1ac fp=0xc003a99cf8 sp=0xc003a99b68 pc=0xcfb53c
github.com/filecoin-project/lotus/node/hello.(*Service).SayHello(0xc0113db860, 0x2e2b2c0, 0xc027e9d0c0, 0xc021597350, 0x26, 0xc027e9d0c0, 0x0)
        /home/filecoin/interopnet/node/hello/hello.go:133 +0x1c3 fp=0xc003a99e68 sp=0xc003a99cf8 pc=0x11ec553                                                                                                                                     
github.com/filecoin-project/lotus/node/modules.RunHello.func1.1(0xc0113db860, 0x7fb53c455d38, 0xc0000480a8, 0x2df47c0, 0xc00080cc80, 0xc021597350, 0x26, 0x2e4d280, 0xc01115bc80)                                                             
        /home/filecoin/interopnet/node/modules/services.go:43 +0xa9 fp=0xc003a99f98 sp=0xc003a99e68 pc=0x16ad189
ribasushi commented 4 years ago

This just happened on one of our slingshot nodes too :/

Vanilla 0.5.10+git.38cb260+api0.14.0

Box is a m5ad.2xlarge HMV-ed AMD EPYC 7571

Log of running up to the crash
``` 2020-09-04T19:42:01.898Z INFO chain chain/sync.go:661 block validation {"took": 0.321733564, "height": "31404", "age": 1.898528783} 2020-09-04T19:42:01.900Z WARN chainstore store/store.go:374 Reorg channel running behind, 1 reorgs buffered 2020-09-04T19:42:01.900Z INFO chainstore store/store.go:386 New heaviest tipset! [bafy2bzacearsqngpqih5ojirqzqftjkhbxeevcz5we7s4qtggovwlfo44nd44 bafy2bzacecrz4krda2dwjb75hgci6peymh3y5tvtwcrc2twbcplc6u5njdq7u bafy2bzacearw4i3rcbnslcaq5vetip3a6saexsgyvsltd6r3j7akpmnqd3l7i bafy2bzacebukbv46zgsdichf7g2bcy42ycofd7r4e5kfp2kxhlc3in3xk6nj2] (height=31404) 2020-09-04T19:42:02.669Z WARN pubsub go-libp2p-pubsub@v0.3.5/score.go:635 unexpected delivery trace: message from 12D3KooWNdiiYWcbtRE8xV4vk1TmUNwCNbpdjRSYUse6KrT5NHTx was first seen 2m2.66592006s ago and has delivery status 1 2020-09-04T19:42:02.670Z WARN chainstore store/store.go:221 head change sub is slow, has 1 buffered entries 2020-09-04T19:42:02.680Z WARN chainstore store/store.go:221 head change sub is slow, has 2 buffered entries 2020-09-04T19:42:06.007Z INFO drand drand/drand.go:136 start fetching randomness {"round": 112490} 2020-09-04T19:42:06.007Z INFO drand drand/drand.go:146 done fetching randomness {"round": 112490, "took": 0.000072291} 2020-09-04T19:42:06.010Z INFO drand drand/drand.go:136 start fetching randomness {"round": 112490} 2020-09-04T19:42:06.010Z INFO drand drand/drand.go:146 done fetching randomness {"round": 112490, "took": 0.000082151} 2020-09-04T19:42:06.010Z INFO drand drand/drand.go:136 start fetching randomness {"round": 112490} 2020-09-04T19:42:06.011Z INFO drand drand/drand.go:146 done fetching randomness {"round": 112490, "took": 0.000063861} 2020-09-04T19:42:06.013Z INFO drand drand/drand.go:136 start fetching randomness {"round": 112490} 2020-09-04T19:42:06.013Z INFO drand drand/drand.go:146 done fetching randomness {"round": 112490, "took": 0.00006842} 2020-09-04T19:42:06.164Z INFO drand drand/drand.go:136 start fetching randomness {"round": 112490} 2020-09-04T19:42:06.164Z INFO drand drand/drand.go:146 done fetching randomness {"round": 112490, "took": 0.000094871} 2020-09-04T19:42:06.167Z INFO drand drand/drand.go:136 start fetching randomness {"round": 112490} 2020-09-04T19:42:06.168Z INFO drand drand/drand.go:146 done fetching randomness {"round": 112490, "took": 0.000112021} 2020-09-04T19:42:06.246Z INFO drand drand/drand.go:136 start fetching randomness {"round": 112490} 2020-09-04T19:42:06.246Z INFO drand drand/drand.go:146 done fetching randomness {"round": 112490, "took": 0.000095461} 2020-09-04T19:42:06.250Z INFO drand drand/drand.go:136 start fetching randomness {"round": 112490} 2020-09-04T19:42:06.250Z INFO drand drand/drand.go:146 done fetching randomness {"round": 112490, "took": 0.000123381} 2020-09-04T19:42:06.342Z INFO drand drand/drand.go:136 start fetching randomness {"round": 112490} 2020-09-04T19:42:06.342Z INFO drand drand/drand.go:146 done fetching randomness {"round": 112490, "took": 0.000122621} 2020-09-04T19:42:06.345Z INFO drand drand/drand.go:136 start fetching randomness {"round": 112490} 2020-09-04T19:42:06.346Z INFO drand drand/drand.go:146 done fetching randomness {"round": 112490, "took": 0.000076031} 2020-09-04T19:42:07.026Z WARN pubsub go-libp2p-pubsub@v0.3.5/validation.go:203 message validation throttled: queue full; dropping message from 12D3KooWNYZAxCQwzBwXYPT8KQhrNXTSyZi6HbTFyky5iiemkyJC 2020-09-04T19:42:07.026Z WARN pubsub go-libp2p-pubsub@v0.3.5/validation.go:203 message validation throttled: queue full; dropping message from 12D3KooWNYZAxCQwzBwXYPT8KQhrNXTSyZi6HbTFyky5iiemkyJC 2020-09-04T19:42:07.026Z WARN pubsub go-libp2p-pubsub@v0.3.5/validation.go:203 message validation throttled: queue full; dropping message from 12D3KooWNYZAxCQwzBwXYPT8KQhrNXTSyZi6HbTFyky5iiemkyJC 2020-09-04T19:42:07.027Z WARN pubsub go-libp2p-pubsub@v0.3.5/validation.go:203 message validation throttled: queue full; dropping message from 12D3KooWNYZAxCQwzBwXYPT8KQhrNXTSyZi6HbTFyky5iiemkyJC 2020-09-04T19:42:07.027Z WARN pubsub go-libp2p-pubsub@v0.3.5/validation.go:203 message validation throttled: queue full; dropping message from 12D3KooWNYZAxCQwzBwXYPT8KQhrNXTSyZi6HbTFyky5iiemkyJC 2020-09-04T19:42:07.027Z WARN pubsub go-libp2p-pubsub@v0.3.5/validation.go:203 message validation throttled: queue full; dropping message from 12D3KooWNYZAxCQwzBwXYPT8KQhrNXTSyZi6HbTFyky5iiemkyJC 2020-09-04T19:42:07.027Z WARN pubsub go-libp2p-pubsub@v0.3.5/validation.go:203 message validation throttled: queue full; dropping message from 12D3KooWNYZAxCQwzBwXYPT8KQhrNXTSyZi6HbTFyky5iiemkyJC 2020-09-04T19:42:07.027Z WARN pubsub go-libp2p-pubsub@v0.3.5/validation.go:203 message validation throttled: queue full; dropping message from 12D3KooWNYZAxCQwzBwXYPT8KQhrNXTSyZi6HbTFyky5iiemkyJC 2020-09-04T19:42:07.027Z WARN pubsub go-libp2p-pubsub@v0.3.5/validation.go:203 message validation throttled: queue full; dropping message from 12D3KooWNYZAxCQwzBwXYPT8KQhrNXTSyZi6HbTFyky5iiemkyJC 2020-09-04T19:42:07.027Z WARN pubsub go-libp2p-pubsub@v0.3.5/validation.go:203 message validation throttled: queue full; dropping message from 12D3KooWNYZAxCQwzBwXYPT8KQhrNXTSyZi6HbTFyky5iiemkyJC 2020-09-04T19:42:07.027Z WARN pubsub go-libp2p-pubsub@v0.3.5/validation.go:203 message validation throttled: queue full; dropping message from 12D3KooWNYZAxCQwzBwXYPT8KQhrNXTSyZi6HbTFyky5iiemkyJC 2020-09-04T19:42:07.027Z WARN pubsub go-libp2p-pubsub@v0.3.5/validation.go:203 message validation throttled: queue full; dropping message from 12D3KooWNYZAxCQwzBwXYPT8KQhrNXTSyZi6HbTFyky5iiemkyJC 2020-09-04T19:42:07.027Z WARN pubsub go-libp2p-pubsub@v0.3.5/validation.go:203 message validation throttled: queue full; dropping message from 12D3KooWNYZAxCQwzBwXYPT8KQhrNXTSyZi6HbTFyky5iiemkyJC 2020-09-04T19:42:07.852Z INFO drand log/log.go:124 {"level": "info", "optimizing_client": "watching on client", "client": "HTTP(\"https://pl-sin.incentinet.drand.sh\").(+verifier)"} 2020-09-04T19:42:07.852Z INFO drand log/log.go:124 {"level": "info", "optimizing_client": "watch ended", "client": "HTTP(\"https://pl-us.incentinet.drand.sh\").(+verifier)"} 2020-09-04T19:42:10.444Z INFO hello hello/hello.go:117 Got new tipset through Hello: [bafy2bzacearsqngpqih5ojirqzqftjkhbxeevcz5we7s4qtggovwlfo44nd44 bafy2bzacecrz4krda2dwjb75hgci6peymh3y5tvtwcrc2twbcplc6u5njdq7u bafy2bzacearw4i3rcbnslcaq5vetip3a6saexsgyvsltd6r3j7akpmnqd3l7i bafy2bzacebukbv46zgsdichf7g2bcy42ycofd7r4e5kfp2kxhlc3in3xk6nj2] from 12D3KooWEHivedPqXYJ6u92AYpDgF6qyTPEDAN6Bo8zEpmRZ59Bk 2020-09-04T19:42:10.454Z INFO hello hello/hello.go:179 time offset {"offset": -0.002713641, "peerid": "12D3KooWEHivedPqXYJ6u92AYpDgF6qyTPEDAN6Bo8zEpmRZ59Bk"} unexpected fault address 0x488a458 fatal error: fault [signal SIGBUS: bus error code=0x2 addr=0x488a458 pc=0x10028ff] goroutine 444 [running]: fatal error: unexpected signal during runtime execution panic during panic [signal SIGBUS: bus error code=0x2 addr=0x463d411 pc=0x4170ee] runtime stack: fatal error: unexpected signal during runtime execution stack trace unavailable ```
ribasushi commented 3 years ago

Again, this time reproducible on @jnthnvctr's workstation ( ignore the _testnet suffix - this is stock lotus v1.4.0 )

Resources seem ok:

lotus_testnet@ip-172-31-15-90:~$ cat /proc/sys/kernel/pid_max
4194303
lotus_testnet@ip-172-31-15-90:~$ ulimit -a 
core file size          (blocks, -c) 0
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) 122382
max locked memory       (kbytes, -l) 65536
max memory size         (kbytes, -m) unlimited
open files                      (-n) 1048576
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) 819200
real-time priority              (-r) 0
stack size              (kbytes, -s) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) 122382
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited

Full backtrace:

2020-12-23T16:29:52.394Z        WARN    sub     sub/incoming.go:97      Slow msg fetch  {"cid": "bafy2bzacebqa55wtwxi7b524pdfyk4l4bvlitas5xezyetyqh3fl22qhph6pa", "source": "12D3KooWArriNNpTMihypacEu9BU3cUdd4gKiXP9dStjttftFZN7", "msgfetch": 22.030861626}
2020-12-23T16:29:52.395Z        WARN    sub     sub/incoming.go:104     Received block with large delay 22 from miner f02731
2020-12-23T16:29:52.396Z        WARN    sub     sub/incoming.go:97      Slow msg fetch  {"cid": "bafy2bzaceds7o7xdz3csx3ia76g7yxghadvxqepqtrb4o4b5dvmido3vqszv2", "source": "12D3KooWAZZyQ6vNMTf96d2AWmMZbV1n1yM98ra7ioUYajWF7ipn", "msgfetch": 22.016682873}
2020-12-23T16:29:52.397Z        WARN    sub     sub/incoming.go:104     Received block with large delay 22 from miner f086240
2020-12-23T16:29:53.561Z        WARN    chainxchg       exchange/client.go:119  could not send request to peer 12D3KooWPE6FvKjff21WAWvPdANdjchRqajgj4FGrsYumHSKeSXL: failed to read chainxchg response: wait time exceeded
2020-12-23T16:30:00.348Z        INFO    bs:sess session/session.go:459  No peers - broadcasting {"session": 215, "want-count": 64}
2020-12-23T16:30:00.445Z        INFO    bs:sess session/session.go:459  No peers - broadcasting {"session": 216, "want-count": 64}
2020-12-23T16:30:00.552Z        INFO    bs:sess session/session.go:459  No peers - broadcasting {"session": 217, "want-count": 64}
2020-12-23T16:30:02.055Z        WARN    chainxchg       exchange/client.go:119  could not send request to peer 12D3KooWAuZd55iYTRuL2zdSPc67XGMygB361zFonjBwia9WMccA: failed to read chainxchg response: failed to read cid field t.Messages: wait time exceeded
2020-12-23T16:30:04.024Z        INFO    bitswap_network network/ipfs_impl.go:208        failed to send message to 12D3KooWC327tpRFSfft17Srm559cDuBjT1kwzJhmJwfinN5gkgE: stream reset
2020-12-23T16:30:06.303Z        INFO    bs:sess session/sessionwantsender.go:458        peer 12D3KooWGF5Su3QcK6DjUoNEQvCxmCdxy6SrSaWoLqFTCMGakRYx sent too many dont haves, removing from session 217
2020-12-23T16:30:06.470Z        WARN    sub     sub/incoming.go:97      Slow msg fetch  {"cid": "bafy2bzacecfnleri6f5vbxbk65w53yajool6hwmryjbo6y7yz6r4azwioczw4", "source": "12D3KooWDhPnA9KCSfz21Y1You3DkBQbZXTqNvHuJccjdeNV4brM", "msgfetch": 5.929351653}
2020-12-23T16:30:06.471Z        WARN    sub     sub/incoming.go:104     Received block with large delay 6 from miner f089551
2020-12-23T16:30:06.510Z        WARN    sub     sub/incoming.go:97      Slow msg fetch  {"cid": "bafy2bzaceblxcednygvxeiv6q3ppbttygxes626rspkbtunzlyocv5p5qsqnw", "source": "12D3KooWHALBySzYLv4N5H7JwMdAi5aj1n8QAm5Px1YBYSvHqybm", "msgfetch": 6.184608754}
2020-12-23T16:30:06.512Z        WARN    sub     sub/incoming.go:104     Received block with large delay 6 from miner f024006
2020-12-23T16:30:06.523Z        WARN    sub     sub/incoming.go:97      Slow msg fetch  {"cid": "bafy2bzacedinwzitxfnpc6xb6kaapvk5wluxq7bum4gdcbgcc5qwbsjcf2ems", "source": "12D3KooWEPKq1R4MSPr9JNHCAYVALiLfnBvkoAnme5ie6Zz2oh56", "msgfetch": 6.095703614}
2020-12-23T16:30:06.524Z        WARN    sub     sub/incoming.go:104     Received block with large delay 6 from miner f02503
2020-12-23T16:30:07.060Z        INFO    bs:sess session/sessionwantsender.go:458        peer 12D3KooWGF5Su3QcK6DjUoNEQvCxmCdxy6SrSaWoLqFTCMGakRYx sent too many dont haves, removing from session 216
2020-12-23T16:30:10.548Z        WARN    chainxchg       exchange/client.go:119  could not send request to peer 12D3KooWBds2d2HPyRU7WKS5RrPQ1Nqm9evpUmroVWzFgUmq3mai: failed to read chainxchg response: wait time exceeded
2020-12-23T16:30:20.439Z        WARN    chainxchg       exchange/client.go:119  could not send request to peer 12D3KooWRd3dJvZJEJuVdYHd717KBWfCoewZ2YVeGHr8Bebr9xDR: failed to read chainxchg response: unmarshaling t.ElectionProof pointer: wait time exceeded
2020-12-23T16:30:22.313Z        ERROR   rpc     go-jsonrpc@v0.1.2/websocket.go:128      handle me:websocket: close sent
2020-12-23T16:30:29.941Z        WARN    chainxchg       exchange/client.go:119  could not send request to peer 12D3KooWJYenhyoSNxq9XPRiSpiGrMT5tKWWFECSE8MYQago6g9S: failed to read chainxchg response: wait time exceeded
2020-12-23T16:30:30.301Z        INFO    bs:sess session/session.go:459  No peers - broadcasting {"session": 218, "want-count": 64}
unexpected fault address 0x7fbbd1a7a247
fatal error: fault
[signal SIGBUS: bus error code=0x2 addr=0x7fbbd1a7a247 pc=0xfd6bd5]

goroutine 2668849 [running]:
runtime.throw(0x2e63125, 0x5)
        /usr/local/go/src/runtime/panic.go:1116 +0x72 fp=0xc024f34ea0 sp=0xc024f34e70 pc=0x56d7b2
runtime.sigpanic()
        /usr/local/go/src/runtime/signal_unix.go:739 +0x485 fp=0xc024f34ed0 sp=0xc024f34ea0 pc=0x5840a5
github.com/dgraph-io/badger/v2.(*header).Decode(0xc024f34fb0, 0x7fbbd1a7a247, 0x61c, 0x75e7469, 0x7fbbd1a7a247)
        /home/lotus_testnet/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.2007.2/structs.go:97 +0x35 fp=0xc024f34f18 sp=0xc024f34ed0 pc=0xfd6bd5
github.com/dgraph-io/badger/v2.(*valueLog).Read(0xc0005559d0, 0x61c00000063, 0x31107247, 0xc03afa69c0, 0xc03af62df0, 0x0, 0xc0131aac00, 0x0, 0x0, 0x0)
        /home/lotus_testnet/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.2007.2/value.go:1584 +0x145 fp=0xc024f35050 sp=0xc024f34f18 pc=0xfe5285
github.com/dgraph-io/badger/v2.(*Item).yieldItemValue(0xc01a8893f0, 0xc01a8893f0, 0xc024f35248, 0xfd7617, 0x42, 0x0, 0xc03af62de3)
        /home/lotus_testnet/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.2007.2/iterator.go:170 +0x135 fp=0xc024f351b8 sp=0xc024f35050 pc=0xfb7915
github.com/dgraph-io/badger/v2.(*Item).Value(0xc01a8893f0, 0xc03afa6960, 0x0, 0x0)
        /home/lotus_testnet/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.2007.2/iterator.go:105 +0xda fp=0xc024f35218 sp=0xc024f351b8 pc=0xfb737a
github.com/filecoin-project/lotus/lib/blockstore/badger.(*Blockstore).View.func1(0xc01838a240, 0x0, 0xc01838a240)
        /home/lotus_testnet/lotus/lib/blockstore/badger/blockstore.go:152 +0x165 fp=0xc024f35288 sp=0xc024f35218 pc=0x10066e5
github.com/dgraph-io/badger/v2.(*DB).View(0xc000555800, 0xc024f35308, 0x0, 0x0)
        /home/lotus_testnet/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.2007.2/txn.go:802 +0x95 fp=0xc024f352c8 sp=0xc024f35288 pc=0xfdadb5
github.com/filecoin-project/lotus/lib/blockstore/badger.(*Blockstore).View(0xc0215cd6c0, 0xc03a3aa420, 0x26, 0xc03afa6960, 0x0, 0x0)
        /home/lotus_testnet/lotus/lib/blockstore/badger/blockstore.go:149 +0x136 fp=0xc024f35368 sp=0xc024f352c8 pc=0x1004936
github.com/ipfs/go-ipfs-blockstore.(*idstore).View(0xc0002de960, 0xc03a3aa420, 0x26, 0xc03afa6960, 0xffffffffffffffff, 0xb11900)
        /home/lotus_testnet/go/pkg/mod/github.com/ipfs/go-ipfs-blockstore@v1.0.3/idstore.go:71 +0xca fp=0xc024f353b0 sp=0xc024f35368 pc=0xb11c8a
github.com/ipfs/go-ipfs-blockstore.(*arccache).View(0xc00032c5a0, 0xc03a3aa420, 0x26, 0xc03afa6960, 0x0, 0x0)
        /home/lotus_testnet/go/pkg/mod/github.com/ipfs/go-ipfs-blockstore@v1.0.3/arc_cache.go:113 +0xb0 fp=0xc024f35420 sp=0xc024f353b0 pc=0xb0e3f0
github.com/ipfs/go-ipfs-blockstore.(*idstore).View(0xc0002dec20, 0xc03a3aa420, 0x26, 0xc03afa6960, 0x7fd0f536f560, 0xc03a916b00)
        /home/lotus_testnet/go/pkg/mod/github.com/ipfs/go-ipfs-blockstore@v1.0.3/idstore.go:71 +0xca fp=0xc024f35468 sp=0xc024f35420 pc=0xb11c8a
github.com/ipfs/go-ipld-cbor.(*BasicIpldStore).Get(0xc042c68ba0, 0x32f0e00, 0xc000122008, 0xc03a3aa420, 0x26, 0x2dcd6a0, 0xc03a916b00, 0xc024f35501, 0xc03a916b00)
        /home/lotus_testnet/go/pkg/mod/github.com/ipfs/go-ipld-cbor@v0.0.5/store.go:58 +0xb9 fp=0xc024f354b8 sp=0xc024f35468 pc=0xadb8b9
github.com/filecoin-project/specs-actors/actors/util/adt.(*wstore).Get(0xc03afa6880, 0x32f0e00, 0xc000122008, 0xc03a3aa420, 0x26, 0x2dcd6a0, 0xc03a916b00, 0xebf2b689704214e, 0x2000000000000000)
        <autogenerated>:1 +0x87 fp=0xc024f35510 sp=0xc024f354b8 pc=0xbaed27
github.com/filecoin-project/go-hamt-ipld/v2.loadNode(0x32f0e00, 0xc000122008, 0x7fd0a41cba40, 0xc03afa6880, 0xc03a3aa420, 0x26, 0xc024f35600, 0x5, 0x30fb238, 0x0, ...)
        /home/lotus_testnet/go/pkg/mod/github.com/filecoin-project/go-hamt-ipld/v2@v2.0.0/hamt.go:349 +0xa8 fp=0xc024f355a0 sp=0xc024f35510 pc=0xd60d68
github.com/filecoin-project/go-hamt-ipld/v2.(*Pointer).loadChild(0xc042c68ff0, 0x32f0e00, 0xc000122008, 0x7fd0a41cba40, 0xc03afa6880, 0x5, 0x30fb238, 0xc03af62dd0, 0x4, 0x8)
        /home/lotus_testnet/go/pkg/mod/github.com/filecoin-project/go-hamt-ipld/v2@v2.0.0/hamt.go:312 +0xb0 fp=0xc024f35628 sp=0xc024f355a0 pc=0xd60c10
github.com/filecoin-project/go-hamt-ipld/v2.(*Node).getValue(0xc03a916a80, 0x32f0e00, 0xc000122008, 0xc024f35710, 0xc03af62dc8, 0x4, 0xc024f356f8, 0xc024f35710, 0x4)
        /home/lotus_testnet/go/pkg/mod/github.com/filecoin-project/go-hamt-ipld/v2@v2.0.0/hamt.go:285 +0x208 fp=0xc024f356b0 sp=0xc024f35628 pc=0xd60a48
github.com/filecoin-project/go-hamt-ipld/v2.(*Node).Find(0xc03a916a80, 0x32f0e00, 0xc000122008, 0xc03af62dc8, 0x4, 0x2b76b60, 0xc042c69320, 0x0, 0xc02ff86150)
        /home/lotus_testnet/go/pkg/mod/github.com/filecoin-project/go-hamt-ipld/v2@v2.0.0/hamt.go:214 +0x14a fp=0xc024f35740 sp=0xc024f356b0 pc=0xd604ea
github.com/filecoin-project/specs-actors/v2/actors/util/adt.(*Map).Get(0xc042c69290, 0x32b7980, 0xc03d79be20, 0x32b35e0, 0xc042c69320, 0x0, 0x0, 0x30)
        /home/lotus_testnet/go/pkg/mod/github.com/filecoin-project/specs-actors/v2@v2.3.3/actors/util/adt/map.go:86 +0xd7 fp=0xc024f357e0 sp=0xc024f35740 pc=0xd66ff7
github.com/filecoin-project/lotus/chain/state.(*StateTree).GetActor(0xc0377cea00, 0xc03af62690, 0x4, 0xc0377cea00, 0x0, 0x0)
        /home/lotus_testnet/lotus/chain/state/statetree.go:301 +0x2e7 fp=0xc024f358c0 sp=0xc024f357e0 pc=0x117ea87
github.com/filecoin-project/lotus/chain/stmgr.GetMinerWorkerRaw(0x32f0dc0, 0xc020ac5500, 0xc0001bab40, 0xc018e30ff0, 0x26, 0xc03af62690, 0x4, 0x26, 0x0, 0x0, ...)
        /home/lotus_testnet/lotus/chain/stmgr/utils.go:63 +0x145 fp=0xc024f35a70 sp=0xc024f358c0 pc=0x1227c25
github.com/filecoin-project/lotus/chain/sub.(*BlockValidator).checkPowerAndGetWorkerKey(0xc0133c8100, 0x32f0dc0, 0xc020ac5500, 0xc0391c60e0, 0x0, 0x0, 0x0, 0xc034d4f5b0)
        /home/lotus_testnet/lotus/chain/sub/incoming.go:449 +0x1d8 fp=0xc024f35b50 sp=0xc024f35a70 pc=0x197c258
github.com/filecoin-project/lotus/chain/sub.(*BlockValidator).Validate(0xc0133c8100, 0x32f0dc0, 0xc020ac5500, 0xc025a81b90, 0x26, 0xc03bfd81b0, 0x0)
        /home/lotus_testnet/lotus/chain/sub/incoming.go:303 +0x494 fp=0xc024f35c78 sp=0xc024f35b50 pc=0x197a974
github.com/filecoin-project/lotus/chain/sub.(*BlockValidator).Validate-fm(0x32f0dc0, 0xc020ac5500, 0xc025a81b90, 0x26, 0xc03bfd81b0, 0xc0140ab9d8)
        /home/lotus_testnet/lotus/chain/sub/incoming.go:263 +0x5c fp=0xc024f35cc0 sp=0xc024f35c78 pc=0x199455c
github.com/libp2p/go-libp2p-pubsub.(*topicVal).validateMsg(0xc01373de90, 0x32f0dc0, 0xc020ac5500, 0xc025a81b90, 0x26, 0xc03bfd81b0, 0x0)
        /home/lotus_testnet/go/pkg/mod/github.com/libp2p/go-libp2p-pubsub@v0.4.0/validation.go:426 +0xfc fp=0xc024f35d68 sp=0xc024f35cc0 pc=0xcd967c
github.com/libp2p/go-libp2p-pubsub.(*validation).validateSingleTopic(0xc0122be6c0, 0xc01373de90, 0xc025a81b90, 0x26, 0xc03bfd81b0, 0xc03a6e4a80)
        /home/lotus_testnet/go/pkg/mod/github.com/libp2p/go-libp2p-pubsub@v0.4.0/validation.go:404 +0xab fp=0xc024f35de8 sp=0xc024f35d68 pc=0xcd946b
github.com/libp2p/go-libp2p-pubsub.(*validation).validateTopic(0xc0122be6c0, 0xc02ff86038, 0x1, 0x1, 0xc025a81b90, 0x26, 0xc03bfd81b0, 0x0)
        /home/lotus_testnet/go/pkg/mod/github.com/libp2p/go-libp2p-pubsub@v0.4.0/validation.go:353 +0x3aa fp=0xc024f35eb0 sp=0xc024f35de8 pc=0xcd936a
github.com/libp2p/go-libp2p-pubsub.(*validation).doValidateTopic(0xc0122be6c0, 0xc02ff86038, 0x1, 0x1, 0xc025a81b90, 0x26, 0xc03bfd81b0, 0x0)
        /home/lotus_testnet/go/pkg/mod/github.com/libp2p/go-libp2p-pubsub@v0.4.0/validation.go:324 +0x8e fp=0xc024f35f60 sp=0xc024f35eb0 pc=0xcd8bce
github.com/libp2p/go-libp2p-pubsub.(*validation).validate.func1(0xc0122be6c0, 0xc03b0c8720, 0xc025a81b90, 0x26, 0xc03bfd81b0, 0xc03af62670)
        /home/lotus_testnet/go/pkg/mod/github.com/libp2p/go-libp2p-pubsub@v0.4.0/validation.go:294 +0x79 fp=0xc024f35fb0 sp=0xc024f35f60 pc=0xcdd9d9
runtime.goexit()
        /usr/local/go/src/runtime/asm_amd64.s:1374 +0x1 fp=0xc024f35fb8 sp=0xc024f35fb0 pc=0x5a6801
created by github.com/libp2p/go-libp2p-pubsub.(*validation).validate
        /home/lotus_testnet/go/pkg/mod/github.com/libp2p/go-libp2p-pubsub@v0.4.0/validation.go:293 +0x4a5

Tail of strace -fttty -s2048 lotus ... doesn't show anything specific


...
1353882 1608741030.549677 <... write resumed>) = 1443
1353882 1608741030.551080 write(285<socket:[166598612]>, "\5\241-\\P\207\16\262\256\225\340eoW\343\221.\2:\320\330\306k\343\202\266\374\364\326@\24\5\250\254\1\344\322\"s}\342\225\227g\376\0260\2625\337|\326|r\215\364*5\339/\246\247%\233\210Cn\209<\317\347\0C\263 \343(\357q=6\22y\177\246\307\210oz \315v\2\351\3y\364\f\7)\357\324\360\357S\202{`\267\f\217\230\365\332v\"Y\233\237\315\222g+4\nU\256\20\202}\321\331\373\22\302$\224\245gdL\227p\366\325\37]z\20\345.I\227\357VG3\27]\226\261\33\377\21\206\322\327\353\220\224\25v=\30\353\223Z!\325\375\235U2 \350Q\245.\232@\25\247\2s\245\302 N\356b\277\177\340\10\3069,\207U\352\"\304\377\333[X\320\261D\t:\236\25\321E$V\201\5a\351&rsA\303\205 \253\324\341\354W[\347\356\264^\202\2632\316\346\302\324\334\344\331\330\351\242\313\277N.\325\263\314\3V\260\vQ\333\10\253\202\202\301\37\371\253\344\213\270d\267\307=\1H\252s\354T\262\227\254\266\222\30}\251\f0`]\245h\375\357\314\300\351\245\341K(F\2\327\16\24\240\361\376\225\300Xd\324\262\236?\206\363\257}\340\37z+\210yiz\302H/\251a\334,\330\316E\227r\355\272}\0\202\267:m$\226D\273\313A\234-H\320\35$\377\310\232M\255t\3529g5\314+\313\345]Z\343\273\305DI/#1\323\317\5WQg\5cX\237\245\273\362\224\263\213\206oU\327\5\332\243\263\217\351\331\320e\322b(\223\367\373=~\217F52\345\23\320\252H\321\262\311\361{!Y\233\205r\321\307T\335Y\343\254+Q\247\302w}1\367\212n\344S\345\302\342\2057V\22KNO\16X8!2}\252\37\350M\212\331\374LJD\30\352\201\25\1\245\6\320\235\204\265\21\271\243-\246\300\nc\236J\314\327G\n\221't\v)E=t \302hqE\336\300\242\307p8(\r#R\377\374\n\257[\271\276\351\36\370\2;\326\231\372\326P\4z\274>[\363SDv\345\357\"a5\246\240\325\320\35.\322\367\364{4\361\307\205\37\257\353.\32m\0rw}&<\213\245\352\177\332\200A\237\232\265C\23v\4n/\34\241c\370\246\211/\270\0\274,Z\216\314\317\265.J\r\332#\263\2073\372\350\210\343\36\333\277a\215Y,8)VN\255\314\313$Ml\214'\t\301\300\333\317g\247'\276\352W\274\35g\10\177(\207\377zj\253\341\354\302\0035\211R\301\337\200\274\247\332~a\0\261\331#\342\300\324(M8RanR\245L\33\311;3oa\21\216\213\200\216\2159~\362\367\346\35\256\\\273Y\345\363\231\271s\360QK \201\331\220\24{.|\3557\303\222N\314G\341\210\247e>\37f\320\234\300;\374b\375\331\263\262\234h[\223Y\323r<\21\373\225z\317)\335\360\201\240`\2559\2609S\252\317\357\356%\272\365N\214\243\277\2\203\363P\312u\352]\372@\257\0P\223tz\211\r^l\355\360\222\262U\341Z\346\319\335\4\322 \375\343UPB\245\f1\340k d]Z\t\317\323\252\300\247'\"7-1\2\"1\230\334.\365\23GG\243\264\365t~\31$p\354\242\rx\331\235\222f\365\352.\374_O\26\311\344.F\364\272\333\250\274\202R\256\325\3113\324?\222=z\305\"6T\335\217\"t\224\34q\340\351<\364\263\320O\4\34}(\3676\352\\b\323\2,\331-)\20\305\\\08p\252\300e\356\330\25\23\330\v!\272\261\30H\375\16\330-\316K+*\326\266)B.\3378\201y\264\235\326\262#\316\376v&?|\v\361\302j\17\242N\317\273\245\345m\317<\271\300\376\213\352\10\5\317-\376\26\224\351\f\275\r\35=\262d\36\312\352)\351R@_0\244<\310C0Lu\375 \212\251=\355~\23\330\231\367D\33\277\33\26\301\230gqqD\370\277\212Y\356\302Q?\353\2559\325\0\357\204\f\251\273L\307\3136\232\304\233\350{\212(\30[\306\10K\3715\36\272\307\2060\332\221\372\fr\273\277gZ\227=f\244\220\213%q*\24\203\10\353\215\1\23\253\343Y\315f\303\211\312W\f\6\360\1770\364\30\3w\r5\365#\362N1\25|\25\344r\261]\\mG|r9-\242\341\235\241\26\300\\\355O\35A\320\324\2777\307\303,\232W\211\372\367\320\2\7\345_a<\304\305\10\233p\343\f\327\224\204\204\3040\374Z\316\16\231\214[N\325h\246\326\273T/m\300\336\200\310\272`7\230|Y\24\271r;\332\314\6<\"m [\356\315\r\263\246\265K'Qb+\272{\7\342\247\313ng='\333\21\301\352\367\201!\"\332v\312_\364\311a\230\345o\216\254P\215y\247\256\325\216\304\257u\246\252\350%{\246\221\214\214\374\34:9\251\\\331\3740X\324$}\221l\30\216\363\226\343\327\tr\217#\307\361cA\340\267\233\273\211\337\323\263ys]3p\261^$\370\343n\26e\200\0216\3450`\356Eb\252\357\21\252\206\224\212\2014)\203\326#\266\336\24\34!\3652;6\37\266P\341\335\207\205\241w\236\376\3628w\361\306\211\375\360(s\357#\273tS\326|", 1443 <unfinished ...>
1353882 1608741030.551199 <... write resumed>) = 1443
1353878 1608741030.551772 --- SIGBUS {si_signo=SIGBUS, si_code=BUS_ADRERR, si_addr=0x7fbbd1a7a247} ---
1353652 1608741030.551780 <... nanosleep resumed>NULL) = 0
1353878 1608741030.551801 rt_sigreturn({mask=[]} <unfinished ...>
1353878 1608741030.551869 <... rt_sigreturn resumed>) = 140444653036103
1353878 1608741030.551936 --- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=1353649, si_uid=1001} ---
1353878 1608741030.551975 rt_sigreturn({mask=[]} <unfinished ...>
1353878 1608741030.552000 <... rt_sigreturn resumed>) = 140444653036103
1353652 1608741030.552283 epoll_pwait(3<anon_inode:[eventpoll]>,  <unfinished ...>
...
Reiers commented 2 years ago

I had the daemon running for 48/h on calibration net. Just to make sure. This issue is outdated and solved.

Closing ticket.