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

Venus Node Cannot Sync with Latest Chain Head in Local Development Filecoin Network When Under Network Packets Drop #6337

Open
1 of 7 tasks
frystal opened this issue May 20, 2024 · 3 comments
Open
1 of 7 tasks

Venus Node Cannot Sync with Latest Chain Head in Local Development Filecoin Network When Under Network Packets Drop #6337

frystal opened this issue May 20, 2024 · 3 comments
Labels
C-bug Category: This is a bug

Comments

@frystal
Copy link

frystal commented May 20, 2024

Sophon Service / 智子服务

  • venus
  • sophon-messager
  • sophon-miner
  • sophon-auth
  • sophon-gateway
  • sophon-co
  • 文档 / docs

Version / 版本

{
        "Version": "1.15.1+git.4dd92bac"
}

Describe the Bug / 描述

While running the local Filecoin network following the instructions from https://lotus.filecoin.io/lotus/developers/local-network/, I let Venus join the local Filecoin network along with Forest and Lotus. After applying the network chaos method random drop 80 packets for 1 minute to the Lotus miner node, the Venus node's chain head stuck at the height 21.

Logging Information / 日志

<details>
  <summary>Venus node chain head</summary>
  
{
        "Height": 21,
        "ParentWeight": "117888",
        "Cids": [
                {
                        "/": "bafy2bzaceck7r5kswyarx5kg444unej5vypsmn2qtyouuhwxo3iszoo72ksvk"
                }
        ],
        "Timestamp": "2024-05-17 14:43:54"
}
Venus node swarm peers ``` 12D3KooWHm5aBpFWeXQ8C7i6tCfbxCuKHHakgqTQrvqff7xRovhV, [/ip4/10.244.1.188/udp/4001/quic-v1] (Lotus miner) ```
Lotus miner chain head 
root@lotus-miner-0:~/lotus-local-net# ./lotus chain head 
bafy2bzacedpmymp6vtr7dgdyxuu7eqy6winu6wcvgelftfdxr2htpohmilcss
Lotus miner net peers 
QmfG5gmg4r3S59wmC15H6TtphBAethWtTFH5HKZogvHQdy, [/ip4/10.244.1.191/udp/45565/quic-v1] (Venus node)
Venus daemon log 
024-05-20T09:49:56.099Z	INFO	chainsync.dispatcher	dispatcher/dispatcher.go:185	received new tipset	{"height": "21", "blocks": 1, "from": "12D3KooWHm5aBpFWeXQ8C7i6tCfbxCuKHHakgqTQrvqff7xRovhV", "current work len": 1, "incoming channel len": 0}
2024-05-20T09:49:56.100Z	INFO	chainsync.syncer	syncer/syncer.go:192	syncOne tipset, height:21, blocks:{ bafy2bzaceck7r5kswyarx5kg444unej5vypsmn2qtyouuhwxo3iszoo72ksvk }
2024-05-20T09:49:56.105Z	INFO	consensus	consensus/block_validator.go:141	block validation	{"took": 0.004866984, "height": "21", "block": "bafy2bzaceck7r5kswyarx5kg444unej5vypsmn2qtyouuhwxo3iszoo72ksvk", "age": 241562.105133289}
2024-05-20T09:49:56.106Z	INFO	chain.store	chain/store.go:592	SetHead { bafy2bzaceck7r5kswyarx5kg444unej5vypsmn2qtyouuhwxo3iszoo72ksvk } 21
2024-05-20T09:49:56.107Z	INFO	chainsync.syncer	syncer/syncer.go:286	handle tipset height 21, count 1, took 0.0071(s)
2024-05-20T09:50:02.107Z	WARN	fork	fork/fork.go:685	STARTING migration	{"height": "20", "from": "bafy2bzacedx57mo73sbp73ffr5ytyabmgt362gxgvsiavd3xsyrnmcw2bsfyg"}
manifest cid: bafy2bzacecn7uxgehrqbcs462ktl2h23u23cmduy2etqj6xrd6tkkja56fna4
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Started 29 workers
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Result writer started
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Creating migration jobs
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Done creating 20 migration jobs after 303.082µs
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 20 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 8 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 13 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 5 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 12 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 2 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 14 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 9 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 7 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 0 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 21 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 4 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 11 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 16 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 19 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 10 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 23 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 25 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 6 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 22 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 26 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 17 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 28 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 24 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 15 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 1 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 3 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 27 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Worker 18 done
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	All workers done after 678.866µs
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Result writer wrote 19 results to state tree after 703.887µs
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Running deferred migrations
2024-05-20T09:50:02.108Z	INFO	fork	fork/fork.go:185	Running deferred migration for t05
2024-05-20T09:50:02.108Z	ERROR	fork	fork/fork.go:691	FAILED migration	{"height": "20", "from": "bafy2bzacedx57mo73sbp73ffr5ytyabmgt362gxgvsiavd3xsyrnmcw2bsfyg", "error": "migrating actors v11 state: upgrading to actors v13: failed to run migration: running deferred job: state migration failed for actor code bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq, addr t05: using cache: migrating state: failed to load market state for t05: cbor input had wrong number of fields"}
2024-05-20T09:50:02.108Z	INFO	consensus	consensus/expected.go:173	process ts height 21, blocks 1, took 0.0014(s)
2024-05-20T09:50:02.108Z	ERROR	chainsync.syncer	syncer/syncer.go:791	stmgr.runStateTransaction failed:error validating tipset: hand fork error: migrating actors v11 state: upgrading to actors v13: failed to run migration: running deferred job: state migration failed for actor code bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq, addr t05: using cache: migrating state: failed to load market state for t05: cbor input had wrong number of fields
2024-05-20T09:50:03.408Z	INFO	sync.module	syncer/syncer_submodule.go:186	received new block bafy2bzacealq5u6cb5g2c35livqc4hkthkebmhx2lzqltpngpml32yjvkhxuk height 22 from peer 12D3KooWHm5aBpFWeXQ8C7i6tCfbxCuKHHakgqTQrvqff7xRovhV age 67h6m5.408370681s
2024-05-20T09:50:03.409Z	WARN	sync.module	syncer/syncer_submodule.go:196	received block(22, bafy2bzacealq5u6cb5g2c35livqc4hkthkebmhx2lzqltpngpml32yjvkhxuk) with large delay : 67h6m5.409300316s
2024-05-20T09:50:03.409Z	INFO	chainsync.dispatcher	dispatcher/dispatcher.go:185	received new tipset	{"height": "22", "blocks": 1, "from": "12D3KooWHm5aBpFWeXQ8C7i6tCfbxCuKHHakgqTQrvqff7xRovhV", "current work len": 1, "incoming channel len": 0}
2024-05-20T09:50:03.409Z	INFO	chainsync.syncer	syncer/syncer.go:192	syncOne tipset, height:22, blocks:{ bafy2bzacealq5u6cb5g2c35livqc4hkthkebmhx2lzqltpngpml32yjvkhxuk }
2024-05-20T09:50:03.410Z	WARN	fork	fork/fork.go:685	STARTING migration	{"height": "20", "from": "bafy2bzacedx57mo73sbp73ffr5ytyabmgt362gxgvsiavd3xsyrnmcw2bsfyg"}
manifest cid: bafy2bzacecn7uxgehrqbcs462ktl2h23u23cmduy2etqj6xrd6tkkja56fna4
2024-05-20T09:50:03.410Z	INFO	fork	fork/fork.go:185	Started 29 workers
2024-05-20T09:50:03.410Z	INFO	fork	fork/fork.go:185	Result writer started
manifest cid: bafy2bzacecn7uxgehrqbcs462ktl2h23u23cmduy2etqj6xrd6tkkja56fna4
manifest cid: bafy2bzacecn7uxgehrqbcs462ktl2h23u23cmduy2etqj6xrd6tkkja56fna4
2024-05-20T09:50:03.414Z	INFO	fork	fork/fork.go:185	Creating migration jobs
2024-05-20T09:50:03.414Z	INFO	fork	fork/fork.go:185	Done creating 20 migration jobs after 4.522101ms
2024-05-20T09:50:03.414Z	INFO	fork	fork/fork.go:185	Worker 4 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 11 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 12 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 13 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 14 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 15 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 16 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 17 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 18 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 19 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 20 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 21 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 22 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 23 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 24 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 25 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 26 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 27 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 28 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 2 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 3 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 0 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 10 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 9 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 8 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 7 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 6 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 5 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Worker 1 done
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	All workers done after 5.074842ms
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Result writer wrote 19 results to state tree after 5.089972ms
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Running deferred migrations
2024-05-20T09:50:03.415Z	INFO	fork	fork/fork.go:185	Running deferred migration for t05
2024-05-20T09:50:03.415Z	ERROR	fork	fork/fork.go:691	FAILED migration	{"height": "20", "from": "bafy2bzacedx57mo73sbp73ffr5ytyabmgt362gxgvsiavd3xsyrnmcw2bsfyg", "error": "migrating actors v11 state: upgrading to actors v13: failed to run migration: running deferred job: state migration failed for actor code bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq, addr t05: using cache: migrating state: failed to load market state for t05: cbor input had wrong number of fields"}
2024-05-20T09:50:03.415Z	INFO	consensus	consensus/expected.go:173	process ts height 21, blocks 1, took 0.0056(s)
2024-05-20T09:50:03.415Z	WARN	fork	fork/fork.go:685	STARTING migration	{"height": "20", "from": "bafy2bzacedx57mo73sbp73ffr5ytyabmgt362gxgvsiavd3xsyrnmcw2bsfyg"}
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Started 29 workers
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Result writer started
2024-05-20T09:50:03.416Z	WARN	fork	fork/fork.go:685	STARTING migration	{"height": "20", "from": "bafy2bzacedx57mo73sbp73ffr5ytyabmgt362gxgvsiavd3xsyrnmcw2bsfyg"}
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Started 29 workers
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Result writer started
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Creating migration jobs
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Done creating 20 migration jobs after 435.437µs
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 0 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 1 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 2 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 3 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 4 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 5 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 6 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 7 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 8 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 9 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 10 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 11 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 12 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 13 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 14 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 15 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 16 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 17 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 18 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 19 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 20 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 21 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 22 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 23 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 24 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 25 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 26 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 27 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Worker 28 done
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	All workers done after 854.282µs
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Creating migration jobs
2024-05-20T09:50:03.416Z	INFO	fork	fork/fork.go:185	Done creating 20 migration jobs after 602.043µs
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 9 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 10 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 4 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 24 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 8 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 28 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 15 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 6 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 25 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 16 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Result writer wrote 19 results to state tree after 1.401963ms
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 26 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 12 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 23 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 22 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 20 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 5 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 13 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 14 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 1 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 11 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 7 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 2 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 17 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 3 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 18 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 27 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 21 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Running deferred migrations
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Running deferred migration for t05
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 19 done
2024-05-20T09:50:03.417Z	ERROR	fork	fork/fork.go:691	FAILED migration	{"height": "20", "from": "bafy2bzacedx57mo73sbp73ffr5ytyabmgt362gxgvsiavd3xsyrnmcw2bsfyg", "error": "migrating actors v11 state: upgrading to actors v13: failed to run migration: running deferred job: state migration failed for actor code bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq, addr t05: using cache: migrating state: failed to load market state for t05: cbor input had wrong number of fields"}
2024-05-20T09:50:03.417Z	INFO	consensus	consensus/expected.go:173	process ts height 21, blocks 1, took 0.0019(s)
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Worker 0 done
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	All workers done after 1.424154ms
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Result writer wrote 19 results to state tree after 1.448185ms
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Running deferred migrations
2024-05-20T09:50:03.417Z	INFO	fork	fork/fork.go:185	Running deferred migration for t05
2024-05-20T09:50:03.417Z	ERROR	fork	fork/fork.go:691	FAILED migration	{"height": "20", "from": "bafy2bzacedx57mo73sbp73ffr5ytyabmgt362gxgvsiavd3xsyrnmcw2bsfyg", "error": "migrating actors v11 state: upgrading to actors v13: failed to run migration: running deferred job: state migration failed for actor code bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq, addr t05: using cache: migrating state: failed to load market state for t05: cbor input had wrong number of fields"}
2024-05-20T09:50:03.417Z	INFO	consensus	consensus/expected.go:173	process ts height 21, blocks 1, took 0.0017(s)
2024-05-20T09:50:03.421Z	INFO	chainsync.syncer	syncer/syncer.go:286	handle tipset height 22, count 1, took 0.0115(s)
2024-05-20T09:50:03.421Z	INFO	chainsync.dispatcher	dispatcher/dispatcher.go:292	failed sync of { bafy2bzacealq5u6cb5g2c35livqc4hkthkebmhx2lzqltpngpml32yjvkhxuk } at 22  failed to sync tipset { bafy2bzacealq5u6cb5g2c35livqc4hkthkebmhx2lzqltpngpml32yjvkhxuk }, number 0 of 1 in chain: validate mining failed 3 errors occurred:
  * hand fork error: migrating actors v11 state: upgrading to actors v13: failed to run migration: running deferred job: state migration failed for actor code bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq, addr t05: using cache: migrating state: failed to load market state for t05: cbor input had wrong number of fields
error validating tipset
github.com/filecoin-project/venus/pkg/consensus.(*Expected).RunStateTransition
  /root/venus/pkg/consensus/expected.go:233
github.com/filecoin-project/venus/pkg/statemanger.(*Stmgr).RunStateTransition
  /root/venus/pkg/statemanger/state_manger.go:310
github.com/filecoin-project/venus/pkg/consensus.(*BlockValidator).validateBlock.func1
  /root/venus/pkg/consensus/block_validator.go:199
github.com/Gurpartap/async.Err.func1
  /go/pkg/mod/github.com/!gurpartap/[email protected]/error.go:29
runtime.goexit
  /usr/local/go/src/runtime/asm_amd64.s:1650
  * hand fork error: migrating actors v11 state: upgrading to actors v13: failed to run migration: running deferred job: state migration failed for actor code bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq, addr t05: using cache: migrating state: failed to load market state for t05: cbor input had wrong number of fields
error validating tipset
github.com/filecoin-project/venus/pkg/consensus.(*Expected).RunStateTransition
  /root/venus/pkg/consensus/expected.go:233
github.com/filecoin-project/venus/pkg/statemanger.(*Stmgr).RunStateTransition
  /root/venus/pkg/statemanger/state_manger.go:310
github.com/filecoin-project/venus/pkg/consensus.(*BlockValidator).validateBlock.func8
  /root/venus/pkg/consensus/block_validator.go:266
github.com/Gurpartap/async.Err.func1
  /go/pkg/mod/github.com/!gurpartap/[email protected]/error.go:29
runtime.goexit
  /usr/local/go/src/runtime/asm_amd64.s:1650
  * get tipsetstate(22, [bafy2bzaceck7r5kswyarx5kg444unej5vypsmn2qtyouuhwxo3iszoo72ksvk]) failed: error validating tipset: hand fork error: migrating actors v11 state: upgrading to actors v13: failed to run migration: running deferred job: state migration failed for actor code bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq, addr t05: using cache: migrating state: failed to load market state for t05: cbor input had wrong number of fields


2024-05-20T09:50:10.882Z	INFO	sync.module	syncer/syncer_submodule.go:186	received new block bafy2bzaced7w4ujbezy325pcpfndxnaajbg62dfggxrjohoh6hejo4umkgfla height 23 from peer 12D3KooWHm5aBpFWeXQ8C7i6tCfbxCuKHHakgqTQrvqff7xRovhV age 67h6m8.882481133s
2024-05-20T09:50:10.883Z	WARN	sync.module	syncer/syncer_submodule.go:196	received block(23, bafy2bzaced7w4ujbezy325pcpfndxnaajbg62dfggxrjohoh6hejo4umkgfla) with large delay : 67h6m8.88346081s
2024-05-20T09:50:10.883Z	INFO	chainsync.dispatcher	dispatcher/dispatcher.go:185	received new tipset	{"height": "23", "blocks": 1, "from": "12D3KooWHm5aBpFWeXQ8C7i6tCfbxCuKHHakgqTQrvqff7xRovhV", "current work len": 1, "incoming channel len": 0}
2024-05-20T09:50:10.883Z	INFO	chainsync.syncer	syncer/syncer.go:192	syncOne tipset, height:22, blocks:{ bafy2bzacealq5u6cb5g2c35livqc4hkthkebmhx2lzqltpngpml32yjvkhxuk }
2024-05-20T09:50:10.884Z	WARN	fork	fork/fork.go:685	STARTING migration	{"height": "20", "from": "bafy2bzacedx57mo73sbp73ffr5ytyabmgt362gxgvsiavd3xsyrnmcw2bsfyg"}
manifest cid: bafy2bzacecn7uxgehrqbcs462ktl2h23u23cmduy2etqj6xrd6tkkja56fna4
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Started 29 workers
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Creating migration jobs
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Result writer started
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Done creating 20 migration jobs after 175.767µs
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 11 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 25 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 12 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 13 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 18 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 19 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 20 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 21 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 14 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 22 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 15 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 23 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 24 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 17 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 16 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 9 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 8 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 7 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 6 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 1 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 10 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 5 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 0 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 4 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 2 done
2024-05-20T09:50:10.884Z	INFO	fork	fork/fork.go:185	Worker 3 done
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Worker 27 done
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Worker 28 done
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Worker 26 done
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	All workers done after 521.28µs
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Result writer wrote 19 results to state tree after 540.08µs
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Running deferred migrations
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Running deferred migration for t05
2024-05-20T09:50:10.885Z	ERROR	fork	fork/fork.go:691	FAILED migration	{"height": "20", "from": "bafy2bzacedx57mo73sbp73ffr5ytyabmgt362gxgvsiavd3xsyrnmcw2bsfyg", "error": "migrating actors v11 state: upgrading to actors v13: failed to run migration: running deferred job: state migration failed for actor code bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq, addr t05: using cache: migrating state: failed to load market state for t05: cbor input had wrong number of fields"}
2024-05-20T09:50:10.885Z	INFO	consensus	consensus/expected.go:173	process ts height 21, blocks 1, took 0.0011(s)
manifest cid: bafy2bzacecn7uxgehrqbcs462ktl2h23u23cmduy2etqj6xrd6tkkja56fna4
2024-05-20T09:50:10.885Z	WARN	fork	fork/fork.go:685	STARTING migration	{"height": "20", "from": "bafy2bzacedx57mo73sbp73ffr5ytyabmgt362gxgvsiavd3xsyrnmcw2bsfyg"}
2024-05-20T09:50:10.885Z	WARN	fork	fork/fork.go:685	STARTING migration	{"height": "20", "from": "bafy2bzacedx57mo73sbp73ffr5ytyabmgt362gxgvsiavd3xsyrnmcw2bsfyg"}
manifest cid: bafy2bzacecn7uxgehrqbcs462ktl2h23u23cmduy2etqj6xrd6tkkja56fna4
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Started 29 workers
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Creating migration jobs
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Started 29 workers
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Creating migration jobs
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Done creating 20 migration jobs after 188.507µs
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Worker 10 done
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Worker 24 done
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Result writer started
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Worker 6 done
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Worker 13 done
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Worker 26 done
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Done creating 20 migration jobs after 200.717µs
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Worker 9 done
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Worker 5 done
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Worker 7 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 22 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 15 done
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Result writer started
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Worker 8 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 3 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 14 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 3 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 1 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 2 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 12 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 1 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 6 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 4 done
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Worker 11 done
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Worker 14 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 25 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 11 done
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Worker 0 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 24 done
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Worker 16 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 27 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 18 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 26 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 27 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 22 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 23 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 19 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 7 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 18 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 0 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 21 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 17 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 19 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 4 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 2 done
2024-05-20T09:50:10.885Z	INFO	fork	fork/fork.go:185	Worker 20 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 17 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 10 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 15 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 13 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 28 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 8 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Result writer wrote 19 results to state tree after 587.872µs
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 16 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 9 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 23 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 20 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 28 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 12 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 21 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 5 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	All workers done after 566.892µs
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Running deferred migrations
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Worker 25 done
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	All workers done after 678.355µs
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Running deferred migration for t05
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Result writer wrote 19 results to state tree after 741.068µs
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Running deferred migrations
2024-05-20T09:50:10.886Z	INFO	fork	fork/fork.go:185	Running deferred migration for t05
2024-05-20T09:50:10.886Z	ERROR	fork	fork/fork.go:691	FAILED migration	{"height": "20", "from": "bafy2bzacedx57mo73sbp73ffr5ytyabmgt362gxgvsiavd3xsyrnmcw2bsfyg", "error": "migrating actors v11 state: upgrading to actors v13: failed to run migration: running deferred job: state migration failed for actor code bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq, addr t05: using cache: migrating state: failed to load market state for t05: cbor input had wrong number of fields"}
2024-05-20T09:50:10.886Z	INFO	consensus	consensus/expected.go:173	process ts height 21, blocks 1, took 0.0013(s)
2024-05-20T09:50:10.886Z	ERROR	fork	fork/fork.go:691	FAILED migration	{"height": "20", "from": "bafy2bzacedx57mo73sbp73ffr5ytyabmgt362gxgvsiavd3xsyrnmcw2bsfyg", "error": "migrating actors v11 state: upgrading to actors v13: failed to run migration: running deferred job: state migration failed for actor code bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq, addr t05: using cache: migrating state: failed to load market state for t05: cbor input had wrong number of fields"}
2024-05-20T09:50:10.886Z	INFO	consensus	consensus/expected.go:173	process ts height 21, blocks 1, took 0.0012(s)
2024-05-20T09:50:10.888Z	INFO	chainsync.syncer	syncer/syncer.go:286	handle tipset height 23, count 1, took 0.0047(s)
2024-05-20T09:50:10.888Z	INFO	chainsync.dispatcher	dispatcher/dispatcher.go:292	failed sync of { bafy2bzaced7w4ujbezy325pcpfndxnaajbg62dfggxrjohoh6hejo4umkgfla } at 23  failed to sync tipset { bafy2bzacealq5u6cb5g2c35livqc4hkthkebmhx2lzqltpngpml32yjvkhxuk }, number 0 of 2 in chain: validate mining failed 3 errors occurred:
  * hand fork error: migrating actors v11 state: upgrading to actors v13: failed to run migration: running deferred job: state migration failed for actor code bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq, addr t05: using cache: migrating state: failed to load market state for t05: cbor input had wrong number of fields
error validating tipset
github.com/filecoin-project/venus/pkg/consensus.(*Expected).RunStateTransition
  /root/venus/pkg/consensus/expected.go:233
github.com/filecoin-project/venus/pkg/statemanger.(*Stmgr).RunStateTransition
  /root/venus/pkg/statemanger/state_manger.go:310
github.com/filecoin-project/venus/pkg/consensus.(*BlockValidator).validateBlock.func1
  /root/venus/pkg/consensus/block_validator.go:199
github.com/Gurpartap/async.Err.func1
  /go/pkg/mod/github.com/!gurpartap/[email protected]/error.go:29
runtime.goexit
  /usr/local/go/src/runtime/asm_amd64.s:1650
  * hand fork error: migrating actors v11 state: upgrading to actors v13: failed to run migration: running deferred job: state migration failed for actor code bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq, addr t05: using cache: migrating state: failed to load market state for t05: cbor input had wrong number of fields
error validating tipset
github.com/filecoin-project/venus/pkg/consensus.(*Expected).RunStateTransition
  /root/venus/pkg/consensus/expected.go:233
github.com/filecoin-project/venus/pkg/statemanger.(*Stmgr).RunStateTransition
  /root/venus/pkg/statemanger/state_manger.go:310
github.com/filecoin-project/venus/pkg/consensus.(*BlockValidator).validateBlock.func8
  /root/venus/pkg/consensus/block_validator.go:266
github.com/Gurpartap/async.Err.func1
  /go/pkg/mod/github.com/!gurpartap/[email protected]/error.go:29
runtime.goexit
  /usr/local/go/src/runtime/asm_amd64.s:1650
  * get tipsetstate(22, [bafy2bzaceck7r5kswyarx5kg444unej5vypsmn2qtyouuhwxo3iszoo72ksvk]) failed: error validating tipset: hand fork error: migrating actors v11 state: upgrading to actors v13: failed to run migration: running deferred job: state migration failed for actor code bafk2bzaceaw6dslv6pfqha4ynghq2imij5khnnjrie22kmfgtpie3bvxho6jq, addr t05: using cache: migrating state: failed to load market state for t05: cbor input had wrong number of fields
```

Repo Steps / 重现步骤

  1. Follow the instructions from Lotus to set up a local Filecoin network with 1 Lotus miner, 1 Lotus nodes, 1 Forest nodes .
  2. Start the Venus with the following command: "./venus daemon --swarmlisten=/ip4/0.0.0.0/tcp/4000 --genesisfile=./devgen.car --network=2k --password=123456"
  3. Wait 30 seconds until the Venus node is synced with the latest block.
  4. Apply 1s network latency for 1m for Forest node.
  5. Apply random drop 80 network packets for 1 minute to the Venus node.
  6. Observe that the Venus node chain head is stuck at height 21.
@frystal frystal added the C-bug Category: This is a bug label May 20, 2024
@simlecode
Copy link
Collaborator

What is your Lotus version

@simlecode simlecode mentioned this issue Jul 26, 2024
Closed
7 tasks
@frystal
Copy link
Author

frystal commented Aug 5, 2024

The Lotus version is

Daemon:  1.26.3+2k+git.560826d5c.dirty+api1.5.0
Local: lotus version 1.26.3+2k+git.560826d5c.dirty

@simlecode
Copy link
Collaborator

I tested the 2k network using Venus v.16.0 and Lotus v1.28.1, and it ran normally. Can you test it again using these two versions.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
C-bug Category: This is a bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@frystal @simlecode