search

filecoin-project / lotus

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

Issue while calling `Filecoin.EthGetLogs` method #12555

Open elmattic opened 1 month ago

elmattic commented 1 month ago

Checklist

Lotus component

Lotus Version

Daemon: 1.29.2-rc1+calibnet+git.4004ca691

Repro Steps

  1. Erase database and init lotus with a calibnet snapshot
rm -Rf $HOME/.lotus

./lotus daemon --import-snapshot forest_snapshot_calibnet_2024-10-04_height_2023775.forest.car.zst --halt-after-import
  1. Run lotus daemon with EthRPC enabled:

LOTUS_FEVM_ENABLEETHRPC=1 ./lotus daemon

  1. Run following command:
curl -X POST 'http://127.0.0.1:1234/rpc/v1' \
    -H 'Content-Type: application/json' \
    --data '{"jsonrpc":"2.0","id":1,"method":"Filecoin.EthGetLogs","params":[{"fromBlock": "0x1ee13f", "toBlock": "0x1ee13f", "address": [], "topics": null }]}'
  1. You should see an empty list in the response.

{"id":1,"jsonrpc":"2.0","result":[]}

Describe the Bug

According to Filecoin explorers (filfox or filutils), we should obtain five logs for this block number:

https://calibration.filutils.com/en/message/0xb3d54c1a06a9b6f6e752d5621a086f140d7e322512e05a270fccb439c47cf9da https://calibration.filutils.com/en/message/0xb17fc66619ba84c74d0b0c7be8e8acf56ffaa9248845730ade6ee16f10d9cd1c

Note that for some epochs, I do see logs, but for some, I don't see them and have an empty list as a result.

Logging Information

$ LOTUS_FEVM_ENABLEETHRPC=1 ./lotus daemon
2024-10-04T16:09:04.632+0200    INFO     main    lotus/daemon.go:230     lotus repo: /Users/guillaume/.lotus
2024-10-04T16:09:04.632+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-0-0-5294475db5237a2e83c3e52fd6c2b03859a1831d45ed08c4f35dbf9a803165a9.vk is ok
2024-10-04T16:09:04.632+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-0-0-0170db1f394b35d995252228ee359194b13199d259380541dc529fb0099096b0.vk is ok
2024-10-04T16:09:04.633+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-stacked-proof-of-replication-merkletree-poseidon_hasher-8-8-0-sha256_hasher-82a357d2f2ca81dc61bb45f4a762807aedee1b0a53fd6c4e77b46a01bfef7820.vk is ok
2024-10-04T16:09:04.633+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-empty-sector-update-merkletree-poseidon_hasher-8-0-0-fb9e095bebdd77511c0269b967b4d87ba8b8a525edaa0e165de23ba454510194.vk is ok
2024-10-04T16:09:04.633+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-stacked-proof-of-replication-merkletree-poseidon_hasher-8-0-0-sha256_hasher-6babf46ce344ae495d558e7770a585b2382d54f225af8ed0397b8be7c3fcd472.vk is ok
2024-10-04T16:09:04.633+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-empty-sector-update-merkletree-poseidon_hasher-8-8-0-3b7f44a9362e3985369454947bc94022e118211e49fd672d52bec1cbfd599d18.vk is ok
2024-10-04T16:09:04.633+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-stacked-proof-of-replication-merkletree-poseidon_hasher-8-0-0-sha256_hasher-ecd683648512ab1765faa2a5f14bab48f676e633467f0aa8aad4b55dcb0652bb.vk is ok
2024-10-04T16:09:04.633+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-0-0-3ea05428c9d11689f23529cde32fd30aabd50f7d2c93657c1d3650bca3e8ea9e.vk is ok
2024-10-04T16:09:04.633+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-8-0-559e581f022bb4e4ec6e719e563bf0e026ad6de42e56c18714a2c692b1b88d7e.vk is ok
2024-10-04T16:09:04.633+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-0-0-50c7368dea9593ed0989e70974d28024efa9d156d585b7eea1be22b2e753f331.vk is ok
2024-10-04T16:09:04.633+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-8-2-b62098629d07946e9028127e70295ed996fe3ed25b0f9f88eb610a0ab4385a3c.vk is ok
2024-10-04T16:09:04.633+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-empty-sector-update-merkletree-poseidon_hasher-8-0-0-61fa69f38b9cc771ba27b670124714b4ea77fbeae05e377fb859c4a43b73a30c.vk is ok
2024-10-04T16:09:04.633+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-0-0-7d739b8cf60f1b0709eeebee7730e297683552e4b69cab6984ec0285663c5781.vk is ok
2024-10-04T16:09:04.633+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-0-0-0cfb4f178bbb71cf2ecfcd42accce558b27199ab4fb59cb78f2483fe21ef36d9.vk is ok
2024-10-04T16:09:04.633+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-empty-sector-update-merkletree-poseidon_hasher-8-8-2-102e1444a7e9a97ebf1e3d6855dcc77e66c011ea66f936d9b2c508f87f2f83a7.vk is ok
2024-10-04T16:09:04.633+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-stacked-proof-of-replication-merkletree-poseidon_hasher-8-8-2-sha256_hasher-96f1b4a04c5c51e4759bbf224bbc2ef5a42c7100f16ec0637123f16a845ddfb2.vk is ok
2024-10-04T16:09:04.633+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-empty-sector-update-merkletree-poseidon_hasher-8-0-0-92180959e1918d26350b8e6cfe217bbdd0a2d8de51ebec269078b364b715ad63.vk is ok
2024-10-04T16:09:04.633+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-stacked-proof-of-replication-merkletree-poseidon_hasher-8-0-0-sha256_hasher-032d3138d22506ec0082ed72b2dcba18df18477904e35bafee82b3793b06832f.vk is ok
2024-10-04T16:09:04.639+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-8-0-0377ded656c6f524f1618760bffe4e0a1c51d5a70c4509eedae8a27555733edc.vk is ok
2024-10-04T16:09:04.639+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-8-2-2627e4006b67f99cef990c0a47d5426cb7ab0a0ad58fc1061547bf2d28b09def.vk is ok
2024-10-04T16:09:05.118+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:209  Parameter file /var/tmp/filecoin-proof-parameters/v28-fil-inner-product-v1.srs is ok
2024-10-04T16:09:05.118+0200    INFO     paramfetch      go-paramfetch@v0.0.4/paramfetch.go:233  parameter and key-fetching complete
2024-10-04T16:09:05.124+0200    INFO     modules modules/core.go:63      memory limits initialized       {"max_mem_heap": 0, "total_system_mem": 17179869184, "effective_mem_limit": 17179869184}
2024-10-04T16:09:05.124+0200    WARN     modules modules/core.go:123     failed to initialize cgroup-driven watchdog; err: cgroups-driven watchdog: watchdog run mode not supported
2024-10-04T16:09:05.124+0200    WARN     modules modules/core.go:124     trying a system-driven watchdog
2024-10-04T16:09:05.124+0200    INFO     watchdog        go-watchdog@v1.3.0/watermarks.go:16     initialized watermark watchdog policy; watermarks: []; thresholds: [8589934592 10307921510 12025908428 14602888806 15461882265 15891378995 16320875724]
2024-10-04T16:09:05.124+0200    INFO     watchdog        go-watchdog@v1.3.0/watchdog.go:472      initialized heap profile capture; threshold: 0.900000; max captures: 10; dir: /Users/guillaume/.lotus/heapprof
2024-10-04T16:09:05.124+0200    INFO     modules modules/core.go:129     initialized system-driven watchdog
2024-10-04T16:09:05.125+0200    ERROR    alerting        alerting/alerts.go:106  alert raised    {"type": {"System":"process","Subsystem":"udp-buffer-size"}, "message": {"error":"dial udp 127.0.0.1:0: connect: can't assign requested address","message":"Failed to create UDP connection"}}
2024-10-04T16:09:05.153+0200    INFO     p2pnode lp2p/rcmgr.go:42        libp2p resource manager is enabled
2024-10-04T16:09:05.153+0200    INFO     p2pnode lp2p/rcmgr.go:90        adjusted default resource manager limits
2024-10-04T16:09:05.153+0200    DEBUG    rcmgr   resource-manager/limit.go:84    initializing new limiter with config    {"limits": {}}
2024-10-04T16:09:05.206+0200    INFO     badgerbs        v2@v2.2007.4/levels.go:183      All 12 tables opened in 39ms

2024-10-04T16:09:05.213+0200    INFO     badgerbs        v2@v2.2007.4/value.go:1158      Replaying file id: 8 at offset: 300574039

2024-10-04T16:09:05.213+0200    INFO     badgerbs        v2@v2.2007.4/value.go:1178      Replay took: 2.042µs

2024-10-04T16:09:05.254+0200    INFO     badgerbs        v2@v2.2007.4/levels.go:183      All 12 tables opened in 39ms

2024-10-04T16:09:05.260+0200    INFO     badgerbs        v2@v2.2007.4/value.go:1158      Replaying file id: 8 at offset: 170366225

2024-10-04T16:09:05.260+0200    INFO     badgerbs        v2@v2.2007.4/value.go:1178      Replay took: 1.917µs

2024-10-04T16:09:05.269+0200    INFO     p2pnode lp2p/addrs.go:101       Swarm listening at: [/ip4/127.0.0.1/udp/65223/quic-v1/webtransport/certhash/uEiA3OlJX41OxK2zABe-PQYmi1f7NAfWgkghiYLcF5M0RBw/certhash/uEiC_P7Sz9Q36TCk9nY_LhviRm-EVHHWKA6YSSE-gHJeTmA /ip4/192.168.1.68/udp/65223/quic-v1/webtransport/certhash/uEiA3OlJX41OxK2zABe-PQYmi1f7NAfWgkghiYLcF5M0RBw/certhash/uEiC_P7Sz9Q36TCk9nY_LhviRm-EVHHWKA6YSSE-gHJeTmA /ip6/::1/udp/55086/quic-v1/webtransport/certhash/uEiA3OlJX41OxK2zABe-PQYmi1f7NAfWgkghiYLcF5M0RBw/certhash/uEiC_P7Sz9Q36TCk9nY_LhviRm-EVHHWKA6YSSE-gHJeTmA /ip6/2a01:e0a:176:47f0:876:e7ca:6f9f:9d8f/udp/55086/quic-v1/webtransport/certhash/uEiA3OlJX41OxK2zABe-PQYmi1f7NAfWgkghiYLcF5M0RBw/certhash/uEiC_P7Sz9Q36TCk9nY_LhviRm-EVHHWKA6YSSE-gHJeTmA /ip6/2a01:e0a:176:47f0:71ff:1cb9:2b60:6697/udp/55086/quic-v1/webtransport/certhash/uEiA3OlJX41OxK2zABe-PQYmi1f7NAfWgkghiYLcF5M0RBw/certhash/uEiC_P7Sz9Q36TCk9nY_LhviRm-EVHHWKA6YSSE-gHJeTmA /ip6/2a01:e0a:176:47f0:3ca2:44ed:bd4b:38ec/udp/55086/quic-v1/webtransport/certhash/uEiA3OlJX41OxK2zABe-PQYmi1f7NAfWgkghiYLcF5M0RBw/certhash/uEiC_P7Sz9Q36TCk9nY_LhviRm-EVHHWKA6YSSE-gHJeTmA /ip4/127.0.0.1/tcp/56229 /ip4/192.168.1.68/tcp/56229 /ip6/::1/tcp/56230 /ip6/2a01:e0a:176:47f0:876:e7ca:6f9f:9d8f/tcp/56230 /ip6/2a01:e0a:176:47f0:71ff:1cb9:2b60:6697/tcp/56230 /ip6/2a01:e0a:176:47f0:3ca2:44ed:bd4b:38ec/tcp/56230 /ip4/127.0.0.1/udp/55535/quic-v1 /ip4/192.168.1.68/udp/55535/quic-v1 /ip6/::1/udp/58037/quic-v1 /ip6/2a01:e0a:176:47f0:876:e7ca:6f9f:9d8f/udp/58037/quic-v1 /ip6/2a01:e0a:176:47f0:71ff:1cb9:2b60:6697/udp/58037/quic-v1 /ip6/2a01:e0a:176:47f0:3ca2:44ed:bd4b:38ec/udp/58037/quic-v1]
2024-10-04T16:09:05.317+0200    INFO     modules modules/services.go:153 subscribing to pubsub topic /fil/blocks/calibrationnet
2024-10-04T16:09:05.317+0200    INFO     modules modules/services.go:173 subscribing to pubsub topic /fil/msgs/calibrationnet
2024-10-04T16:09:05.318+0200    INFO     messagepool     messagepool/messagepool.go:447  mpool ready
2024-10-04T16:09:05.318+0200    INFO     modules modules/services.go:218 relaying messages for pubsub topic /indexer/ingest/calibrationnet
2024-10-04T16:09:05.320+0200    INFO     modules modules/ethmodule.go:69 Start prefilling GetTipsetByHeight cache
2024-10-04T16:09:05.320+0200    INFO     splitstore      splitstore/splitstore.go:792    starting splitstore     {"baseEpoch": "2023775", "warmupEpoch": 2023775}
2024-10-04T16:09:05.320+0200    INFO     f3/dynamic-manifest     manifest/dynamic_manifest_provider.go:97        starting a dynamic manifest provider    {"manifestServerID": "12D3KooWS9vD9uwm8u2uPyJV32QBAhKAmPYwmziAgr3Xzk2FU1Mr"}
2024-10-04T16:09:05.320+0200    INFO     f3      go-f3@v0.2.0/f3.go:249  starting f3 reconfiguration
2024-10-04T16:09:05.320+0200    INFO     f3      go-f3@v0.2.0/f3.go:299  stopping F3 internals
2024-10-04T16:09:05.320+0200    INFO     f3      go-f3@v0.2.0/f3.go:190  F3 is starting  {"initialDelay": 0, "hasPendingManifest": false, "NetworkName": "calibrationnet"}
2024-10-04T16:09:05.323+0200    INFO     healthcheck     node/health.go:57       waiting 1s before starting ChainNotify channel
2024-10-04T16:09:06.323+0200    INFO     healthcheck     node/health.go:70       started ChainNotify channel
2024-10-04T16:09:10.317+0200    INFO     peermgr peermgr/peermgr.go:209  connecting to bootstrap peers
2024-10-04T16:09:10.464+0200    WARN     net/identify    identify/id.go:434      failed to identify 12D3KooWDcNfB5teBxbavGjXs5KCV9DvH8eTGtCMXFLJsKPvo5bk: Application error 0x0 (remote)
2024-10-04T16:09:10.645+0200    INFO     chain   chain/sync.go:214       received block outside of consensus range at height 1830231
2024-10-04T16:09:10.675+0200    INFO     chain   chain/sync_manager.go:222       selected initial sync target: [bafy2bzacedpw57jjxc4ijhuzkaho26ykbh3nlfs6dyccks222bg2x7cdorlxg bafy2bzaceavu64q4wme7jsivcj6sqcrmlvr5mhovgyjre3k2oy2efzcodlfpm]
2024-10-04T16:09:10.675+0200    INFO     chain   chain/sync_manager.go:318       worker 0 syncing in [bafy2bzacedpw57jjxc4ijhuzkaho26ykbh3nlfs6dyccks222bg2x7cdorlxg bafy2bzaceavu64q4wme7jsivcj6sqcrmlvr5mhovgyjre3k2oy2efzcodlfpm]
2024-10-04T16:09:10.675+0200    INFO     chain   chain/sync_manager.go:326       worker 0 done; took 1.333µs
2024-10-04T16:09:11.222+0200    INFO     chain   chain/sync.go:214       received block outside of consensus range at height 1972587
2024-10-04T16:09:11.266+0200    WARN     hello   hello/hello.go:117      other peer hasnt completed libp2p identify, waiting a bit
2024-10-04T16:09:15.805+0200    DEBUG    rpc     go-jsonrpc@v0.6.0/websocket.go:781      websocket error {"error": "websocket: close 1000 (normal)", "lastAction": "incoming", "time": 0.001005}
2024-10-04T16:09:19.819+0200    INFO     chain   chain/sync.go:214       received block outside of consensus range at height 1972587
2024-10-04T16:09:20.586+0200    INFO     chain   chain/sync.go:214       received block outside of consensus range at height 2011764
2024-10-04T16:09:20.715+0200    INFO     chain   chain/sync.go:214       received block outside of consensus range at height 1112264
2024-10-04T16:09:21.218+0200    INFO     canonical-log   noise/transport.go:60   CANONICAL_PEER_STATUS: peer= addr=/ip4/40.143.96.116/tcp/47568 sample_rate=100 handshake_failure="noise" err="error reading handshake message: read tcp4 192.168.1.68:56229->40.143.96.116:47568: read: connection reset by peer"
2024-10-04T16:09:22.977+0200    INFO     chain   chain/sync.go:214       received block outside of consensus range at height 1830231
2024-10-04T16:09:24.918+0200    INFO     chain   chain/sync.go:214       received block outside of consensus range at height 1830231
2024-10-04T16:09:25.636+0200    INFO     canonical-log   swarm/swarm_listen.go:136       CANONICAL_PEER_STATUS: peer=12D3KooWHPQHYBEHJ7vdb3X8DTaxcHAZNsTFBXFNczNdKa1DTeF2 addr=/ip4/94.230.184.190/tcp/41363 sample_rate=100 connection_status="established" dir="inbound"
2024-10-04T16:09:27.305+0200    INFO     chain   chain/sync.go:214       received block outside of consensus range at height 1972587
2024-10-04T16:09:28.080+0200    INFO     chain   chain/sync.go:214       received block outside of consensus range at height 1972587
2024-10-04T16:09:29.541+0200    INFO     chain   chain/sync_manager.go:236       selected sync target: [bafy2bzaced3yqj6vo4bvim6f3cly5jcfb7l3ahzx4dzk3xitgm7xvuixewnni]
2024-10-04T16:09:29.541+0200    INFO     chain   chain/sync_manager.go:318       worker 1 syncing in [bafy2bzaced3yqj6vo4bvim6f3cly5jcfb7l3ahzx4dzk3xitgm7xvuixewnni]
2024-10-04T16:09:29.542+0200    WARN     fil-consensus   filcns/filecoin.go:154  Got block from the future, but within threshold (1728050970 > 1728050969)
2024-10-04T16:09:30.035+0200    INFO     bs:sess session/session.go:462  No peers - broadcasting {"session": 2, "want-count": 1}
2024-10-04T16:09:30.042+0200    INFO     bs:sess session/session.go:462  No peers - broadcasting {"session": 3, "want-count": 1}
2024-10-04T16:09:30.063+0200    INFO     chain   chain/sync_manager.go:236       selected sync target: [bafy2bzacebyj52iyeqef5yxnkanz77o5i3mms6ifgu7a7idg6rowv6nnmz3xu]
2024-10-04T16:09:30.063+0200    INFO     chain   chain/sync_manager.go:318       worker 2 syncing in [bafy2bzacebyj52iyeqef5yxnkanz77o5i3mms6ifgu7a7idg6rowv6nnmz3xu]
2024-10-04T16:09:30.063+0200    INFO     chain   chain/sync_manager.go:236       selected sync target: [bafy2bzacecvjyvndwsig324euw3nypj5cj3rqy2srynwaq7f3xg5l53d4su2m]
2024-10-04T16:09:30.063+0200    INFO     chain   chain/sync_manager.go:318       worker 3 syncing in [bafy2bzacecvjyvndwsig324euw3nypj5cj3rqy2srynwaq7f3xg5l53d4su2m]
2024-10-04T16:09:30.070+0200    INFO     chain   chain/sync_manager.go:236       selected sync target: [bafy2bzacedfltqn3i2m6kcggujfrkyxwzfdx7mrs4ys3v62ueu7lnyij56ixw]
2024-10-04T16:09:30.071+0200    INFO     chain   chain/sync_manager.go:318       worker 4 syncing in [bafy2bzacedfltqn3i2m6kcggujfrkyxwzfdx7mrs4ys3v62ueu7lnyij56ixw]
^C2024-10-04T16:09:30.742+0200  WARN     builder node/shutdown.go:31     received shutdown       {"signal": "interrupt"}
2024-10-04T16:09:30.742+0200    WARN     builder node/shutdown.go:36     Shutting down...
2024-10-04T16:09:30.742+0200    INFO     builder node/shutdown.go:44     rpc server shut down successfully 
2024-10-04T16:09:30.742+0200    WARN     events  events/observer.go:61   listenHeadChanges quit
2024-10-04T16:09:30.742+0200    WARN     events  events/observer.go:66   not restarting listenHeadChanges: context error: context canceled
2024-10-04T16:09:30.743+0200    WARN     sub     sub/incoming.go:453     error from message subscription: context canceled
2024-10-04T16:09:30.743+0200    WARN     sub     sub/incoming.go:455     quitting HandleIncomingMessages loop
2024-10-04T16:09:30.743+0200    WARN     sub     sub/incoming.go:57      quitting HandleIncomingBlocks loop
2024-10-04T16:09:30.743+0200    WARN     events  events/observer.go:61   listenHeadChanges quit
2024-10-04T16:09:30.743+0200    WARN     events  events/observer.go:66   not restarting listenHeadChanges: context error: context canceled
2024-10-04T16:09:30.743+0200    WARN     events  events/observer.go:61   listenHeadChanges quit
2024-10-04T16:09:30.743+0200    WARN     events  events/observer.go:66   not restarting listenHeadChanges: context error: context canceled
2024-10-04T16:09:30.743+0200    WARN     events  events/observer.go:61   listenHeadChanges quit
2024-10-04T16:09:30.743+0200    WARN     events  events/observer.go:66   not restarting listenHeadChanges: context error: context canceled
2024-10-04T16:09:30.745+0200    WARN     peermgr peermgr/peermgr.go:154  closing peermgr done
2024-10-04T16:09:30.745+0200    INFO     chain   chain/sync.go:627       block validation        {"took": 1.203161042, "height": "2024153", "age": 0.74512}
2024-10-04T16:09:30.745+0200    ERROR    chain   chain/sync.go:980       failed to validate tipset: context canceled
2024-10-04T16:09:30.745+0200    ERROR    chain   chain/sync.go:980       failed to validate tipset: context canceled
2024-10-04T16:09:30.745+0200    INFO     chain   chain/sync_manager.go:326       worker 4 done; took 674.160167ms
2024-10-04T16:09:30.745+0200    INFO     chain   chain/sync.go:627       block validation        {"took": 0.68152325, "height": "2024153", "age": 0.745217}
2024-10-04T16:09:30.745+0200    INFO     chain   chain/sync.go:627       block validation        {"took": 0.681419084, "height": "2024153", "age": 0.745253}
2024-10-04T16:09:30.745+0200    ERROR    chain   chain/sync.go:980       failed to validate tipset: context canceled
2024-10-04T16:09:30.745+0200    ERROR    chain   chain/sync.go:980       failed to validate tipset: context canceled
2024-10-04T16:09:30.745+0200    INFO     chain   chain/sync_manager.go:326       worker 2 done; took 681.914542ms
2024-10-04T16:09:30.745+0200    WARN     peermgr peermgr/peermgr.go:172  exiting peermgr run
2024-10-04T16:09:30.745+0200    INFO     chain   chain/sync_manager.go:326       worker 3 done; took 681.511042ms
2024-10-04T16:09:30.745+0200    INFO     chain   chain/sync_manager.go:326       worker 1 done; took 1.203460417s
2024-10-04T16:09:30.745+0200    INFO     chain   chain/sync.go:627       block validation        {"took": 0.673955917, "height": "2024153", "age": 0.745166}
2024-10-04T16:09:30.746+0200    WARN     chainstore      store/store.go:670      reorgWorker quit
2024-10-04T16:09:30.746+0200    WARN     modules modules/ethmodule.go:72 error when prefilling GetTipsetByHeight cache: %!w(*xerrors.wrapError=&{failed to fill cache 0x14013b8ac40 {[4339549824 4354791288 4354855688]}})
2024-10-04T16:09:30.746+0200    INFO     modules modules/ethmodule.go:74 Prefilling GetTipsetByHeight done in 25.42678325s
2024-10-04T16:09:30.746+0200    INFO     pubsub  go-libp2p-pubsub@v0.11.0/pubsub.go:671  pubsub processloop shutting down
2024-10-04T16:09:30.751+0200    INFO     badgerbs        v2@v2.2007.4/db.go:1027 Storing value log head: {Fid:8 Len:32 Offset:170372878}

2024-10-04T16:09:30.762+0200    INFO     bitswap-client  client/client.go:439    blockstore.Has error: badger blockstore closed
2024-10-04T16:09:30.762+0200    WARN     bitswap-client  client/client.go:389    ReceiveMessage recvBlockFrom error: bitswap is closed
2024-10-04T16:09:30.763+0200    INFO     badgerbs        v2@v2.2007.4/levels.go:1000     [Compactor: 173] Running compaction: {level:0 score:1.73 dropPrefixes:[]} for level: 0

2024-10-04T16:09:30.831+0200    ERROR    statetree       state/statetree.go:294  failed to load state tree: failed to load hamt node: badger blockstore closed
2024-10-04T16:09:30.831+0200    ERROR    statetree       state/statetree.go:294  failed to load state tree: failed to load hamt node: badger blockstore closed
2024-10-04T16:09:30.873+0200    INFO     chain   chain/sync.go:214       received block outside of consensus range at height 1972587
2024-10-04T16:09:30.958+0200    WARN     modules modules/services.go:79  failed to say hello     {"error": "error opening stream: failed to open stream: context canceled", "errorVerbose": "error opening stream:\n    github.com/filecoin-project/lotus/node/hello.(*Service).SayHello\n        /Users/guillaume/Code/lotus/node/hello/hello.go:149\n  - failed to open stream: context canceled", "peer": "12D3KooWL9ReEGK6DWCGpCyyYdt7WgTmygxgi3tYhkZwYuq41W2y", "supported": ["/ipfs/id/push/1.0.0","/ipfs/ping/1.0.0","/meshsub/1.0.0","/meshsub/1.1.0","/chain/ipfs/bitswap/1.0.0","/chain/ipfs/bitswap/1.2.0","/fil/chain/xchg/0.0.1","/fil/hello/1.0.0","/floodsub/1.0.0","/ipfs/id/1.0.0","/chain/ipfs/bitswap","/chain/ipfs/bitswap/1.1.0"], "agent": "lotus-1.28.3+calibnet+git.d27b9a4a9.dirty"}
2024-10-04T16:09:31.217+0200    WARN     chainxchg       exchange/peer_tracker.go:162    log success called on peer not in tracker       {"peerid": "12D3KooWL9ReEGK6DWCGpCyyYdt7WgTmygxgi3tYhkZwYuq41W2y"}
2024-10-04T16:09:31.217+0200    WARN     chain   chain/sync.go:220       InformNewHead called on block marked as bad: bafy2bzacebyj52iyeqef5yxnkanz77o5i3mms6ifgu7a7idg6rowv6nnmz3xu (reason: 3 errors occurred:
        * context canceled
        * context canceled
        * context canceled

)
2024-10-04T16:09:31.366+0200    INFO     bitswap-client  client/client.go:439    blockstore.Has error: badger blockstore closed
2024-10-04T16:09:31.366+0200    WARN     bitswap-client  client/client.go:389    ReceiveMessage recvBlockFrom error: bitswap is closed
2024-10-04T16:09:31.446+0200    INFO     badgerbs        v2@v2.2007.4/levels.go:962      LOG Compact 0->1, del 5 tables, add 4 tables, took 682.926916ms

2024-10-04T16:09:31.446+0200    INFO     badgerbs        v2@v2.2007.4/levels.go:1010     [Compactor: 173] Compaction for level: 0 DONE
2024-10-04T16:09:31.446+0200    INFO     badgerbs        v2@v2.2007.4/db.go:550  Force compaction on level 0 done
2024-10-04T16:09:31.464+0200    INFO     builder node/shutdown.go:44     node shut down successfully 
2024-10-04T16:09:31.464+0200    WARN     builder node/shutdown.go:47     Graceful shutdown successful
rvagg commented 6 days ago

This issue exists because the snapshots don't contain receipts, nor, therefore, event data. If you did this and requested later than 2023775 it should be fine. But requesting 0x1ee13f / 2023743 is within the snapshot. With https://github.com/filecoin-project/lotus/pull/12655 it'll be easier to backfill after importing a snapshot but still not something we're enabling by default because it's quite expensive since the tipsets all need to be re-executed again to get their data.

The thing that does concern me about this is the fact that it doesn't return an error. I'd like the resolution to this issue to be that we error when we haven't indexed that tipset. But it could be that https://github.com/filecoin-project/lotus/pull/12655 already does that, we should test and confirm and fix if not.