forest icon indicating copy to clipboard operation
forest copied to clipboard
verified publisher icon ChainSafe

Forest Node Cannot Sync with Latest Block in Local Development Filecoin Network When Apply Random Network Packets Drop

Open frystal opened this issue 1 year ago • 0 comments

Describe the bug

While running the local Filecoin network following the instructions from https://lotus.filecoin.io/lotus/developers/local-network/, I let Forest join the local Filecoin network. After applying the network chaos method random drop 10 packets for 1 minute to the Forest node, the Forest node's sync process got stuck, although it could still receive the latest block.

To reproduce

  1. Follow the instructions from Lotus to set up a local Filecoin network with 1 Lotus miner and 3 Lotus nodes.
  2. Start the Forest daemon with the following command: "./target/debug/forest --genesis ./devgen.car --config ./forest_config.toml --save-token ./token"
  3. Wait 30 seconds until the Forest node is synced with the latest block.
  4. Apply random drop 10 network packets for 1 minute to the Forest node.
  5. Observe that the Forest node cannot get the latest head and is stuck.

Log output

Forest node sync status 
root@forest-node-1:~/forest# ./target/debug/forest-cli net peers  
12D3KooWAXW6FZQPyN2PTZAfsgJC1XnCkJKReCBWFHd5bVYwY5Ab, [/ip4/10.244.0.200/tcp/4000]
12D3KooWHm5aBpFWeXQ8C7i6tCfbxCuKHHakgqTQrvqff7xRovhV, [/ip4/10.244.0.197/tcp/4000]
12D3KooWDSuGek2QNMzbuDFZp2Ne5UeXLYnnBgGWkZE5TPvqXWbb, [/ip4/10.244.0.198/tcp/4000]
12D3KooWJvFPsEPy4SNjBWCR5v9fXazQLBmYdXfuq37rube7FwzH, [/ip4/10.244.0.199/tcp/4000]
root@forest-node-1:~/forest# ./target/debug/forest-cli chain head
bafy2bzaceaef5itmdfo5w7cksoothdaetvhakfj2mbzgxb3yqlq7svjwyr4dw
root@forest-node-1:~/forest# ./target/debug/forest-cli sync status
sync status:
Base:   [bafy2bzaceaef5itmdfo5w7cksoothdaetvhakfj2mbzgxb3yqlq7svjwyr4dw]
Target: [bafy2bzacecpvxlc3w4fypijc65yipm52s3hwogco5kmkhp3au4coyjtlz56oo] (1554)
Height diff:    1533
Stage:  header sync
Height: 21
Elapsed time:   0s
Lotus node sync status 
root@lotus-node-2:~/lotus-local-net# ./lotus chain head  
bafy2bzacecz6xgpxuqexjwv54uh7s45ei6wb6xou3dyz6lnxczl2suixk6vf6
root@lotus-node-2:~/lotus-local-net# ./lotus sync status
sync status:
worker 1219:
      Base:   [bafy2bzaceabkb4d3urlrd2xygu25bbb4eqg22lwlzk7uogrdefqa4e7etltko]
      Target: [bafy2bzacecv37zz2ozgadwekigfhwyqt6d2unnwwt2tpxczckxm2rqx563il4] (1242)
      Height diff:    1
      Stage: complete
      Height: 1242
      Elapsed: 12.846459ms
worker 1220:
      Base:   [bafy2bzacecv37zz2ozgadwekigfhwyqt6d2unnwwt2tpxczckxm2rqx563il4]
      Target: [bafy2bzaced5qyjypwyhgu5y56ux4rnnmra7kt6woyk7vfyq2ze6s2fsfcclzq] (1243)
      Height diff:    1
      Stage: complete
      Height: 1243
      Elapsed: 12.713135ms
worker 1221:
      Base:   [bafy2bzaced5qyjypwyhgu5y56ux4rnnmra7kt6woyk7vfyq2ze6s2fsfcclzq]
      Target: [bafy2bzacedap6nugtjr3pt6vwm3genq7esjroslu5zsu64sgazdy57o3b4736] (1244)
      Height diff:    1
      Stage: complete
      Height: 1244
      Elapsed: 10.023687ms
Forest daemon log 
2024-05-18T15:21:57.459562Z  INFO forest_filecoin::chain_sync::chain_muxer: Local node is behind the network, starting BOOTSTRAP from LOCAL_HEAD = 21 -> NETWORK_HEAD = 1686
2024-05-18T15:21:57.938825Z  INFO forest_filecoin::chain_sync::tipset_syncer: Validating tipset: EPOCH = 21, N blocks = 1
2024-05-18T15:21:57.939379Z  INFO forest_filecoin::chain_sync::tipset_syncer: Validating tipset: EPOCH = 22, N blocks = 1
2024-05-18T15:21:57.941933Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration: Running Dragon migration at epoch 20
2024-05-18T15:21:57.946761Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration::common::state_migration: Processing deferred migrations
2024-05-18T15:21:57.948035Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration: Running Dragon migration at epoch 20
2024-05-18T15:21:57.952137Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration::common::state_migration: Processing deferred migrations
2024-05-18T15:21:57.955559Z  WARN forest_filecoin::chain_sync::tipset_syncer: Validating block [CID = bafy2bzacedqbhvm7ipszg6gmenxtusx7jcgpo3nyzjez3qa7oav7vb6y43jbq] in EPOCH = 22 failed: Validation error: Processing error: Could not update state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: "tuple", expect: 12, value: 13 }, Processing error: Failed to calculate state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: "tuple", expect: 12, value: 13 }
2024-05-18T15:21:57.955879Z ERROR forest_filecoin::chain_sync::tipset_syncer: Sync messages check state failed for tipset range
2024-05-18T15:21:57.955991Z ERROR forest_filecoin::chain_sync::chain_muxer: Bootstrapping failed, re-evaluating the network head to retry the bootstrap. Error = TipsetRangeSyncer(Validation("Processing error: Could not update state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: \"tuple\", expect: 12, value: 13 }, Processing error: Failed to calculate state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: \"tuple\", expect: 12, value: 13 }"))
2024-05-18T15:21:57.956027Z  INFO forest_filecoin::chain_sync::chain_muxer: Evaluating network head...
2024-05-18T15:21:57.956138Z  INFO forest_filecoin::chain_sync::chain_muxer: local head is behind the network, local_epoch: 21, now_epoch: 22191
2024-05-18T15:22:04.495012Z  INFO forest_filecoin::chain_sync::chain_muxer: Local node is behind the network, starting BOOTSTRAP from LOCAL_HEAD = 21 -> NETWORK_HEAD = 1687
2024-05-18T15:22:04.970546Z  INFO forest_filecoin::chain_sync::tipset_syncer: Validating tipset: EPOCH = 21, N blocks = 1
2024-05-18T15:22:04.971132Z  INFO forest_filecoin::chain_sync::tipset_syncer: Validating tipset: EPOCH = 22, N blocks = 1
2024-05-18T15:22:04.976337Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration: Running Dragon migration at epoch 20
2024-05-18T15:22:04.981205Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration::common::state_migration: Processing deferred migrations
2024-05-18T15:22:04.983781Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration: Running Dragon migration at epoch 20
2024-05-18T15:22:04.988933Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration::common::state_migration: Processing deferred migrations
2024-05-18T15:22:04.990677Z  WARN forest_filecoin::chain_sync::tipset_syncer: Validating block [CID = bafy2bzacedqbhvm7ipszg6gmenxtusx7jcgpo3nyzjez3qa7oav7vb6y43jbq] in EPOCH = 22 failed: Validation error: Processing error: Could not update state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: "tuple", expect: 12, value: 13 }, Processing error: Failed to calculate state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: "tuple", expect: 12, value: 13 }
2024-05-18T15:22:04.991037Z ERROR forest_filecoin::chain_sync::tipset_syncer: Sync messages check state failed for tipset range
2024-05-18T15:22:04.991186Z ERROR forest_filecoin::chain_sync::chain_muxer: Bootstrapping failed, re-evaluating the network head to retry the bootstrap. Error = TipsetRangeSyncer(Validation("Processing error: Could not update state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: \"tuple\", expect: 12, value: 13 }, Processing error: Failed to calculate state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: \"tuple\", expect: 12, value: 13 }"))
2024-05-18T15:22:04.991231Z  INFO forest_filecoin::chain_sync::chain_muxer: Evaluating network head...
2024-05-18T15:22:04.991411Z  INFO forest_filecoin::chain_sync::chain_muxer: local head is behind the network, local_epoch: 21, now_epoch: 22193
2024-05-18T15:22:12.005661Z  INFO forest_filecoin::chain_sync::chain_muxer: Local node is behind the network, starting BOOTSTRAP from LOCAL_HEAD = 21 -> NETWORK_HEAD = 1688
2024-05-18T15:22:12.469477Z  INFO forest_filecoin::chain_sync::tipset_syncer: Validating tipset: EPOCH = 21, N blocks = 1
2024-05-18T15:22:12.470081Z  INFO forest_filecoin::chain_sync::tipset_syncer: Validating tipset: EPOCH = 22, N blocks = 1
2024-05-18T15:22:12.474142Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration: Running Dragon migration at epoch 20
2024-05-18T15:22:12.485057Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration::common::state_migration: Processing deferred migrations
2024-05-18T15:22:12.487119Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration: Running Dragon migration at epoch 20
2024-05-18T15:22:12.491795Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration::common::state_migration: Processing deferred migrations
2024-05-18T15:22:12.497770Z  WARN forest_filecoin::chain_sync::tipset_syncer: Validating block [CID = bafy2bzacedqbhvm7ipszg6gmenxtusx7jcgpo3nyzjez3qa7oav7vb6y43jbq] in EPOCH = 22 failed: Validation error: Processing error: Could not update state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: "tuple", expect: 12, value: 13 }, Processing error: Failed to calculate state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: "tuple", expect: 12, value: 13 }
2024-05-18T15:22:12.498132Z ERROR forest_filecoin::chain_sync::tipset_syncer: Sync messages check state failed for tipset range
2024-05-18T15:22:12.498261Z ERROR forest_filecoin::chain_sync::chain_muxer: Bootstrapping failed, re-evaluating the network head to retry the bootstrap. Error = TipsetRangeSyncer(Validation("Processing error: Could not update state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: \"tuple\", expect: 12, value: 13 }, Processing error: Failed to calculate state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: \"tuple\", expect: 12, value: 13 }"))
2024-05-18T15:22:12.498301Z  INFO forest_filecoin::chain_sync::chain_muxer: Evaluating network head...
2024-05-18T15:22:12.498467Z  INFO forest_filecoin::chain_sync::chain_muxer: local head is behind the network, local_epoch: 21, now_epoch: 22195
2024-05-18T15:22:19.190085Z  INFO forest_filecoin::chain_sync::chain_muxer: Local node is behind the network, starting BOOTSTRAP from LOCAL_HEAD = 21 -> NETWORK_HEAD = 1689
2024-05-18T15:22:19.680808Z  INFO forest_filecoin::chain_sync::tipset_syncer: Validating tipset: EPOCH = 21, N blocks = 1
2024-05-18T15:22:19.681206Z  INFO forest_filecoin::chain_sync::tipset_syncer: Validating tipset: EPOCH = 22, N blocks = 1
2024-05-18T15:22:19.684239Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration: Running Dragon migration at epoch 20
2024-05-18T15:22:19.692004Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration::common::state_migration: Processing deferred migrations
2024-05-18T15:22:19.694018Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration: Running Dragon migration at epoch 20
2024-05-18T15:22:19.699092Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration::common::state_migration: Processing deferred migrations
2024-05-18T15:22:19.700406Z  WARN forest_filecoin::chain_sync::tipset_syncer: Validating block [CID = bafy2bzacedqbhvm7ipszg6gmenxtusx7jcgpo3nyzjez3qa7oav7vb6y43jbq] in EPOCH = 22 failed: Validation error: Processing error: Could not update state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: "tuple", expect: 12, value: 13 }, Processing error: Failed to calculate state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: "tuple", expect: 12, value: 13 }
2024-05-18T15:22:19.700860Z ERROR forest_filecoin::chain_sync::tipset_syncer: Sync messages check state failed for tipset range
2024-05-18T15:22:19.701031Z ERROR forest_filecoin::chain_sync::chain_muxer: Bootstrapping failed, re-evaluating the network head to retry the bootstrap. Error = TipsetRangeSyncer(Validation("Processing error: Could not update state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: \"tuple\", expect: 12, value: 13 }, Processing error: Failed to calculate state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: \"tuple\", expect: 12, value: 13 }"))
2024-05-18T15:22:19.701080Z  INFO forest_filecoin::chain_sync::chain_muxer: Evaluating network head...
2024-05-18T15:22:19.701339Z  INFO forest_filecoin::chain_sync::chain_muxer: local head is behind the network, local_epoch: 21, now_epoch: 22197
2024-05-18T15:22:26.315061Z  INFO forest_filecoin::chain_sync::chain_muxer: Local node is behind the network, starting BOOTSTRAP from LOCAL_HEAD = 21 -> NETWORK_HEAD = 1690
2024-05-18T15:22:26.786452Z  INFO forest_filecoin::chain_sync::tipset_syncer: Validating tipset: EPOCH = 21, N blocks = 1
2024-05-18T15:22:26.786881Z  INFO forest_filecoin::chain_sync::tipset_syncer: Validating tipset: EPOCH = 22, N blocks = 1
2024-05-18T15:22:26.790089Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration: Running Dragon migration at epoch 20
2024-05-18T15:22:26.794819Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration::common::state_migration: Processing deferred migrations
2024-05-18T15:22:26.796450Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration: Running Dragon migration at epoch 20
2024-05-18T15:22:26.801812Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration::common::state_migration: Processing deferred migrations
2024-05-18T15:22:26.803514Z  WARN forest_filecoin::chain_sync::tipset_syncer: Validating block [CID = bafy2bzacedqbhvm7ipszg6gmenxtusx7jcgpo3nyzjez3qa7oav7vb6y43jbq] in EPOCH = 22 failed: Validation error: Processing error: Could not update state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: "tuple", expect: 12, value: 13 }, Processing error: Failed to calculate state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: "tuple", expect: 12, value: 13 }
2024-05-18T15:22:26.803908Z ERROR forest_filecoin::chain_sync::tipset_syncer: Sync messages check state failed for tipset range
2024-05-18T15:22:26.804044Z ERROR forest_filecoin::chain_sync::chain_muxer: Bootstrapping failed, re-evaluating the network head to retry the bootstrap. Error = TipsetRangeSyncer(Validation("Processing error: Could not update state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: \"tuple\", expect: 12, value: 13 }, Processing error: Failed to calculate state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: \"tuple\", expect: 12, value: 13 }"))
2024-05-18T15:22:26.804084Z  INFO forest_filecoin::chain_sync::chain_muxer: Evaluating network head...
2024-05-18T15:22:26.804251Z  INFO forest_filecoin::chain_sync::chain_muxer: local head is behind the network, local_epoch: 21, now_epoch: 22199
2024-05-18T15:22:33.679196Z  INFO forest_filecoin::chain_sync::chain_muxer: Local node is behind the network, starting BOOTSTRAP from LOCAL_HEAD = 21 -> NETWORK_HEAD = 1691
2024-05-18T15:22:34.153916Z  INFO forest_filecoin::chain_sync::tipset_syncer: Validating tipset: EPOCH = 21, N blocks = 1
2024-05-18T15:22:34.154326Z  INFO forest_filecoin::chain_sync::tipset_syncer: Validating tipset: EPOCH = 22, N blocks = 1
2024-05-18T15:22:34.156703Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration: Running Dragon migration at epoch 20
2024-05-18T15:22:34.160522Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration::common::state_migration: Processing deferred migrations
2024-05-18T15:22:34.162044Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration: Running Dragon migration at epoch 20
2024-05-18T15:22:34.166423Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration::common::state_migration: Processing deferred migrations
2024-05-18T15:22:34.170632Z  WARN forest_filecoin::chain_sync::tipset_syncer: Validating block [CID = bafy2bzacedqbhvm7ipszg6gmenxtusx7jcgpo3nyzjez3qa7oav7vb6y43jbq] in EPOCH = 22 failed: Validation error: Processing error: Could not update state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: "tuple", expect: 12, value: 13 }, Processing error: Failed to calculate state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: "tuple", expect: 12, value: 13 }
2024-05-18T15:22:34.170943Z ERROR forest_filecoin::chain_sync::tipset_syncer: Sync messages check state failed for tipset range
2024-05-18T15:22:34.171042Z ERROR forest_filecoin::chain_sync::chain_muxer: Bootstrapping failed, re-evaluating the network head to retry the bootstrap. Error = TipsetRangeSyncer(Validation("Processing error: Could not update state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: \"tuple\", expect: 12, value: 13 }, Processing error: Failed to calculate state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: \"tuple\", expect: 12, value: 13 }"))
2024-05-18T15:22:34.171079Z  INFO forest_filecoin::chain_sync::chain_muxer: Evaluating network head...
2024-05-18T15:22:34.171204Z  INFO forest_filecoin::chain_sync::chain_muxer: local head is behind the network, local_epoch: 21, now_epoch: 22201
2024-05-18T15:22:41.014337Z  INFO forest_filecoin::chain_sync::chain_muxer: Local node is behind the network, starting BOOTSTRAP from LOCAL_HEAD = 21 -> NETWORK_HEAD = 1692
2024-05-18T15:22:41.483631Z  INFO forest_filecoin::chain_sync::tipset_syncer: Validating tipset: EPOCH = 21, N blocks = 1
2024-05-18T15:22:41.484099Z  INFO forest_filecoin::chain_sync::tipset_syncer: Validating tipset: EPOCH = 22, N blocks = 1
2024-05-18T15:22:41.486984Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration: Running Dragon migration at epoch 20
2024-05-18T15:22:41.490826Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration::common::state_migration: Processing deferred migrations
2024-05-18T15:22:41.492287Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration: Running Dragon migration at epoch 20
2024-05-18T15:22:41.496697Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration::common::state_migration: Processing deferred migrations
2024-05-18T15:22:41.500163Z  WARN forest_filecoin::chain_sync::tipset_syncer: Validating block [CID = bafy2bzacedqbhvm7ipszg6gmenxtusx7jcgpo3nyzjez3qa7oav7vb6y43jbq] in EPOCH = 22 failed: Validation error: Processing error: Could not update state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: "tuple", expect: 12, value: 13 }, Processing error: Failed to calculate state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: "tuple", expect: 12, value: 13 }
2024-05-18T15:22:41.500471Z ERROR forest_filecoin::chain_sync::tipset_syncer: Sync messages check state failed for tipset range
2024-05-18T15:22:41.500594Z ERROR forest_filecoin::chain_sync::chain_muxer: Bootstrapping failed, re-evaluating the network head to retry the bootstrap. Error = TipsetRangeSyncer(Validation("Processing error: Could not update state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: \"tuple\", expect: 12, value: 13 }, Processing error: Failed to calculate state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: \"tuple\", expect: 12, value: 13 }"))
2024-05-18T15:22:41.500630Z  INFO forest_filecoin::chain_sync::chain_muxer: Evaluating network head...
2024-05-18T15:22:41.500767Z  INFO forest_filecoin::chain_sync::chain_muxer: local head is behind the network, local_epoch: 21, now_epoch: 22202
2024-05-18T15:22:48.393868Z  INFO forest_filecoin::chain_sync::chain_muxer: Local node is behind the network, starting BOOTSTRAP from LOCAL_HEAD = 21 -> NETWORK_HEAD = 1693
2024-05-18T15:22:48.882014Z  INFO forest_filecoin::chain_sync::tipset_syncer: Validating tipset: EPOCH = 21, N blocks = 1
2024-05-18T15:22:48.882420Z  INFO forest_filecoin::chain_sync::tipset_syncer: Validating tipset: EPOCH = 22, N blocks = 1
2024-05-18T15:22:48.885117Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration: Running Dragon migration at epoch 20
2024-05-18T15:22:48.889448Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration::common::state_migration: Processing deferred migrations
2024-05-18T15:22:48.891222Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration: Running Dragon migration at epoch 20
2024-05-18T15:22:48.896309Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration::common::state_migration: Processing deferred migrations
2024-05-18T15:22:48.897715Z  WARN forest_filecoin::chain_sync::tipset_syncer: Validating block [CID = bafy2bzacedqbhvm7ipszg6gmenxtusx7jcgpo3nyzjez3qa7oav7vb6y43jbq] in EPOCH = 22 failed: Validation error: Processing error: Could not update state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: "tuple", expect: 12, value: 13 }, Processing error: Failed to calculate state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: "tuple", expect: 12, value: 13 }
2024-05-18T15:22:48.898303Z ERROR forest_filecoin::chain_sync::tipset_syncer: Sync messages check state failed for tipset range
2024-05-18T15:22:48.898463Z ERROR forest_filecoin::chain_sync::chain_muxer: Bootstrapping failed, re-evaluating the network head to retry the bootstrap. Error = TipsetRangeSyncer(Validation("Processing error: Could not update state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: \"tuple\", expect: 12, value: 13 }, Processing error: Failed to calculate state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: \"tuple\", expect: 12, value: 13 }"))
2024-05-18T15:22:48.898509Z  INFO forest_filecoin::chain_sync::chain_muxer: Evaluating network head...
2024-05-18T15:22:48.898706Z  INFO forest_filecoin::chain_sync::chain_muxer: local head is behind the network, local_epoch: 21, now_epoch: 22204
2024-05-18T15:22:55.837532Z  INFO forest_filecoin::chain_sync::chain_muxer: Local node is behind the network, starting BOOTSTRAP from LOCAL_HEAD = 21 -> NETWORK_HEAD = 1694
2024-05-18T15:22:56.331583Z  INFO forest_filecoin::chain_sync::tipset_syncer: Validating tipset: EPOCH = 21, N blocks = 1
2024-05-18T15:22:56.331979Z  INFO forest_filecoin::chain_sync::tipset_syncer: Validating tipset: EPOCH = 22, N blocks = 1
2024-05-18T15:22:56.334268Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration: Running Dragon migration at epoch 20
2024-05-18T15:22:56.337879Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration::common::state_migration: Processing deferred migrations
2024-05-18T15:22:56.339211Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration: Running Dragon migration at epoch 20
2024-05-18T15:22:56.344077Z  INFO compute_tipset_state_blocking: forest_filecoin::state_migration::common::state_migration: Processing deferred migrations
2024-05-18T15:22:56.347879Z  WARN forest_filecoin::chain_sync::tipset_syncer: Validating block [CID = bafy2bzacedqbhvm7ipszg6gmenxtusx7jcgpo3nyzjez3qa7oav7vb6y43jbq] in EPOCH = 22 failed: Validation error: Processing error: Failed to calculate state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: "tuple", expect: 12, value: 13 }, Processing error: Could not update state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: "tuple", expect: 12, value: 13 }
2024-05-18T15:22:56.348246Z ERROR forest_filecoin::chain_sync::tipset_syncer: Sync messages check state failed for tipset range
2024-05-18T15:22:56.348382Z ERROR forest_filecoin::chain_sync::chain_muxer: Bootstrapping failed, re-evaluating the network head to retry the bootstrap. Error = TipsetRangeSyncer(Validation("Processing error: Failed to calculate state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: \"tuple\", expect: 12, value: 13 }, Processing error: Could not update state: state migration failed for bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq actor, addr t05:Serialization error for Cbor protocol: RequireLength { name: \"tuple\", expect: 12, value: 13 }"))
2024-05-18T15:22:56.348423Z  INFO forest_filecoin::chain_sync::chain_muxer: Evaluating network head...
2024-05-18T15:22:56.348571Z  INFO forest_filecoin::chain_sync::chain_muxer: local head is behind the network, local_epoch: 21, now_epoch: 22206
## Expected behaviour

The forest node should recover from the packet drop and sync the latest block

Screenshots

image image

Environment (please complete the following information):

  • OS: Ubuntu20.04
  • Branch/commit： forest-filecoin 0.17.2+git.c23b5b35315

Other information and links

frystal avatar May 18 '24 15:05 frystal