Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Issue while calling Filecoin.EthGetLogs method #12555

Closed
6 of 11 tasks
elmattic opened this issue Oct 4, 2024 · 2 comments
Closed
6 of 11 tasks

Issue while calling Filecoin.EthGetLogs method #12555

elmattic opened this issue Oct 4, 2024 · 2 comments
Labels
kind/bug Kind: Bug

Comments

@elmattic
Copy link

elmattic commented Oct 4, 2024 •
edited
Loading

Checklist

  • This is not a security-related bug/issue. If it is, please follow please follow the security policy.
  • I have searched on the issue tracker and the lotus forum, and there is no existing related issue or discussion.
  • I am running the Latest release, the most recent RC(release canadiate) for the upcoming release or the dev branch(master), or have an issue updating to any of these.
  • I did not make any code changes to lotus.

Lotus component

  • lotus daemon - chain sync
  • lotus fvm/fevm - Lotus FVM and FEVM interactions
  • lotus miner/worker - sealing
  • lotus miner - proving(WindowPoSt/WinningPoSt)
  • lotus JSON-RPC API
  • lotus message management (mpool)
  • Other

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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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      [email protected]/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        [email protected]/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        [email protected]/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        [email protected]/levels.go:183      All 12 tables opened in 39ms

2024-10-04T16:09:05.213+0200    INFO     badgerbs        [email protected]/value.go:1158      Replaying file id: 8 at offset: 300574039

2024-10-04T16:09:05.213+0200    INFO     badgerbs        [email protected]/value.go:1178      Replay took: 2.042µs

2024-10-04T16:09:05.254+0200    INFO     badgerbs        [email protected]/levels.go:183      All 12 tables opened in 39ms

2024-10-04T16:09:05.260+0200    INFO     badgerbs        [email protected]/value.go:1158      Replaying file id: 8 at offset: 170366225

2024-10-04T16:09:05.260+0200    INFO     badgerbs        [email protected]/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      [email protected]/f3.go:249  starting f3 reconfiguration
2024-10-04T16:09:05.320+0200    INFO     f3      [email protected]/f3.go:299  stopping F3 internals
2024-10-04T16:09:05.320+0200    INFO     f3      [email protected]/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     [email protected]/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  [email protected]/pubsub.go:671  pubsub processloop shutting down
2024-10-04T16:09:30.751+0200    INFO     badgerbs        [email protected]/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        [email protected]/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        [email protected]/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        [email protected]/levels.go:1010     [Compactor: 173] Compaction for level: 0 DONE
2024-10-04T16:09:31.446+0200    INFO     badgerbs        [email protected]/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
@elmattic elmattic added the kind/bug Kind: Bug label Oct 4, 2024
@github-project-automation github-project-automation bot moved this to 📌 Triage in FilOz Oct 4, 2024
@rvagg
Copy link
Member

rvagg commented Oct 31, 2024

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 #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 #12655 already does that, we should test and confirm and fix if not.

@rvagg rvagg mentioned this issue Nov 20, 2024
Open
@rvagg
Copy link
Member

rvagg commented Nov 20, 2024

This issue is fixed now by ChainIndexer which is going out with Lotus 1.31.

  1. You can now backfill into a snapshot even though it doesn't have receipts, it'll re-execute tipsets for you. So, optionally, after you import a snapshot, you can request a backfill all the way back to the beginning of the snapshot: https://github.com/filecoin-project/lotus/blob/master/documentation/en/chain-indexer-overview-for-operators.md#upgrade-when-importing-chain-state-from-a-snapshot
  2. When asking for an epoch that isn't indexed, you'll get an error now

But .. when you ask for a range of epochs, it won't error, we need to fix that. Issue opened for that specifically @ #12709

@rvagg rvagg closed this as completed Nov 20, 2024
@github-project-automation github-project-automation bot moved this from 📌 Triage to 🎉 Done in FilOz Nov 20, 2024
@elmattic elmattic mentioned this issue Nov 22, 2024
Merged
4 tasks
@rjan90 rjan90 moved this from 🎉 Done to ☑️ Done (Archive) in FilOz Nov 26, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
kind/bug Kind: Bug
Projects
FilOz
Status: ☑️ Done (Archive)
Milestone
No milestone
Development

No branches or pull requests
2 participants
@rvagg @elmattic