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

Lotus daemon crash #12151

Open
5 of 11 tasks
frystal opened this issue Jun 26, 2024 · 4 comments
Open
5 of 11 tasks

Lotus daemon crash #12151

frystal opened this issue Jun 26, 2024 · 4 comments
Labels
kind/bug Kind: Bug

Comments

@frystal
Copy link

frystal commented Jun 26, 2024

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.26.3+2k+git.560826d5c.dirty+api1.5.0
Local: lotus version 1.26.3+2k+git.560826d5c.dirty

Repro Steps

  1. Setup the lotus local devnet by the
  2. Run lotus daemon with CMD "./lotus daemon --genesis=./devgen.car"

Describe the Bug

According toward the log, the lotus daemon crash with:

SIGSEGV: segmentation violation
PC=0x7ffe3f163a16 m=37 sigcode=1

Here is the dumped go-routines when crashed.
go-routines.txt

Logging Information

2024-06-23T09:01:58.086Z	INFO	main	lotus/daemon.go:228	lotus repo: /root/.lotus-local-net
2024-06-23T09:01:58.086Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-0-0-50c7368dea9593ed0989e70974d28024efa9d156d585b7eea1be22b2e753f331.vk is ok
2024-06-23T09:01:58.086Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-empty-sector-update-merkletree-poseidon_hasher-8-0-0-92180959e1918d26350b8e6cfe217bbdd0a2d8de51ebec269078b364b715ad63.vk is ok
2024-06-23T09:01:58.087Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-empty-sector-update-merkletree-poseidon_hasher-8-8-0-3b7f44a9362e3985369454947bc94022e118211e49fd672d52bec1cbfd599d18.vk is ok
2024-06-23T09:01:58.087Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-0-0-0170db1f394b35d995252228ee359194b13199d259380541dc529fb0099096b0.vk is ok
2024-06-23T09:01:58.087Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-8-2-b62098629d07946e9028127e70295ed996fe3ed25b0f9f88eb610a0ab4385a3c.vk is ok
2024-06-23T09:01:58.087Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-0-0-3ea05428c9d11689f23529cde32fd30aabd50f7d2c93657c1d3650bca3e8ea9e.vk is ok
2024-06-23T09:01:58.087Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-0-0-0cfb4f178bbb71cf2ecfcd42accce558b27199ab4fb59cb78f2483fe21ef36d9.vk is ok
2024-06-23T09:01:58.087Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-8-0-559e581f022bb4e4ec6e719e563bf0e026ad6de42e56c18714a2c692b1b88d7e.vk is ok
2024-06-23T09:01:58.087Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-empty-sector-update-merkletree-poseidon_hasher-8-0-0-fb9e095bebdd77511c0269b967b4d87ba8b8a525edaa0e165de23ba454510194.vk is ok
2024-06-23T09:01:58.087Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-stacked-proof-of-replication-merkletree-poseidon_hasher-8-8-2-sha256_hasher-96f1b4a04c5c51e4759bbf224bbc2ef5a42c7100f16ec0637123f16a845ddfb2.vk is ok
2024-06-23T09:01:58.087Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-empty-sector-update-merkletree-poseidon_hasher-8-0-0-61fa69f38b9cc771ba27b670124714b4ea77fbeae05e377fb859c4a43b73a30c.vk is ok
2024-06-23T09:01:58.087Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-empty-sector-update-merkletree-poseidon_hasher-8-8-2-102e1444a7e9a97ebf1e3d6855dcc77e66c011ea66f936d9b2c508f87f2f83a7.vk is ok
2024-06-23T09:01:58.087Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-stacked-proof-of-replication-merkletree-poseidon_hasher-8-0-0-sha256_hasher-032d3138d22506ec0082ed72b2dcba18df18477904e35bafee82b3793b06832f.vk is ok
2024-06-23T09:01:58.087Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-0-0-5294475db5237a2e83c3e52fd6c2b03859a1831d45ed08c4f35dbf9a803165a9.vk is ok
2024-06-23T09:01:58.087Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-0-0-7d739b8cf60f1b0709eeebee7730e297683552e4b69cab6984ec0285663c5781.vk is ok
2024-06-23T09:01:58.087Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-stacked-proof-of-replication-merkletree-poseidon_hasher-8-0-0-sha256_hasher-ecd683648512ab1765faa2a5f14bab48f676e633467f0aa8aad4b55dcb0652bb.vk is ok
2024-06-23T09:01:58.087Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-stacked-proof-of-replication-merkletree-poseidon_hasher-8-8-0-sha256_hasher-82a357d2f2ca81dc61bb45f4a762807aedee1b0a53fd6c4e77b46a01bfef7820.vk is ok
2024-06-23T09:01:58.087Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-stacked-proof-of-replication-merkletree-poseidon_hasher-8-0-0-sha256_hasher-6babf46ce344ae495d558e7770a585b2382d54f225af8ed0397b8be7c3fcd472.vk is ok
2024-06-23T09:01:58.095Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-8-2-2627e4006b67f99cef990c0a47d5426cb7ab0a0ad58fc1061547bf2d28b09def.vk is ok
2024-06-23T09:01:58.096Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-proof-of-spacetime-fallback-merkletree-poseidon_hasher-8-8-0-0377ded656c6f524f1618760bffe4e0a1c51d5a70c4509eedae8a27555733edc.vk is ok
2024-06-23T09:01:58.537Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:209	Parameter file /var/tmp/filecoin-proof-parameters/v28-fil-inner-product-v1.srs is ok
2024-06-23T09:01:58.538Z	INFO	paramfetch	go-paramfetch@v0.0.4/paramfetch.go:233	parameter and key-fetching complete
2024-06-23T09:01:58.551Z	INFO	modules	modules/core.go:63	memory limits initialized	{"max_mem_heap": 0, "total_system_mem": 540819824640, "effective_mem_limit": 540819824640}
2024-06-23T09:01:58.554Z	WARN	modules	modules/core.go:123	failed to initialize cgroup-driven watchdog; err: failed to load cgroup for process: cgroups: cgroup deleted
2024-06-23T09:01:58.554Z	WARN	modules	modules/core.go:124	trying a system-driven watchdog
2024-06-23T09:01:58.554Z	INFO	watchdog	go-watchdog@v1.3.0/watermarks.go:16	initialized watermark watchdog policy; watermarks: []; thresholds: [270409912320 324491894784 378573877248 459696850944 486737842176 500258337792 513778833408]
2024-06-23T09:01:58.554Z	INFO	watchdog	go-watchdog@v1.3.0/watchdog.go:472	initialized heap profile capture; threshold: 0.900000; max captures: 10; dir: /root/.lotus-local-net/heapprof
2024-06-23T09:01:58.554Z	INFO	modules	modules/core.go:129	initialized system-driven watchdog
2024-06-23T09:01:58.556Z	ERROR	alerting	alerting/alerts.go:106	alert raised	{"type": {"System":"process","Subsystem":"udp-buffer-size"}, "message": {"current_size":212992,"help":"See https://github.com/quic-go/quic-go/wiki/UDP-Buffer-Sizes for details.","message":"UDP buffer size is low","wanted_size":2097152}}
2024-06-23T09:01:58.558Z	INFO	p2pnode	lp2p/rcmgr.go:39	libp2p resource manager is enabled
2024-06-23T09:01:58.558Z	DEBUG	rcmgr	resource-manager/limit.go:84	initializing new limiter with config	{"limits": {}}
2024-06-23T09:01:58.575Z	INFO	badger	v2@v2.2007.4/levels.go:183	All 0 tables opened in 0s

2024-06-23T09:01:58.579Z	INFO	badger	v2@v2.2007.4/value.go:1158	Replaying file id: 0 at offset: 0

2024-06-23T09:01:58.579Z	INFO	badger	v2@v2.2007.4/value.go:1178	Replay took: 3.66µs

2024-06-23T09:01:58.588Z	INFO	badger	v2@v2.2007.4/levels.go:183	All 0 tables opened in 0s

2024-06-23T09:01:58.592Z	INFO	badger	v2@v2.2007.4/value.go:1158	Replaying file id: 0 at offset: 0

2024-06-23T09:01:58.592Z	INFO	badger	v2@v2.2007.4/value.go:1178	Replay took: 5.25µs

2024-06-23T09:01:58.614Z	INFO	badgerbs	v2@v2.2007.4/levels.go:183	All 0 tables opened in 0s

2024-06-23T09:01:58.618Z	INFO	badgerbs	v2@v2.2007.4/value.go:1158	Replaying file id: 0 at offset: 0

2024-06-23T09:01:58.618Z	INFO	badgerbs	v2@v2.2007.4/value.go:1178	Replay took: 3.92µs

2024-06-23T09:01:58.636Z	INFO	badgerbs	v2@v2.2007.4/levels.go:183	All 1 tables opened in 8ms

2024-06-23T09:01:58.676Z	INFO	badgerbs	v2@v2.2007.4/value.go:1158	Replaying file id: 0 at offset: 14860194

2024-06-23T09:01:58.677Z	INFO	badgerbs	v2@v2.2007.4/value.go:1178	Replay took: 5.54µs

2024/06/23 09:01:58 failed to sufficiently increase receive buffer size (was: 208 kiB, wanted: 2048 kiB, got: 416 kiB). See https://github.com/quic-go/quic-go/wiki/UDP-Buffer-Sizes for details.
2024-06-23T09:01:58.683Z	INFO	p2pnode	lp2p/addrs.go:101	Swarm listening at: [/ip6/::1/tcp/4000 /ip4/127.0.0.1/udp/4001/quic-v1 /ip4/10.244.0.48/udp/4001/quic-v1 /ip6/::1/udp/4001/quic-v1 /ip4/127.0.0.1/udp/4001/quic-v1/webtransport/certhash/uEiDwTSQc61iEhOByp0GLhVZG1NeH3lnDECAl6ILathtF_A/certhash/uEiBrt4tjqvkTg94IxDXt4XJbaw9f_wVjJb9vYs5yK5r87A /ip4/10.244.0.48/udp/4001/quic-v1/webtransport/certhash/uEiDwTSQc61iEhOByp0GLhVZG1NeH3lnDECAl6ILathtF_A/certhash/uEiBrt4tjqvkTg94IxDXt4XJbaw9f_wVjJb9vYs5yK5r87A /ip6/::1/udp/4001/quic-v1/webtransport/certhash/uEiDwTSQc61iEhOByp0GLhVZG1NeH3lnDECAl6ILathtF_A/certhash/uEiBrt4tjqvkTg94IxDXt4XJbaw9f_wVjJb9vYs5yK5r87A /ip4/127.0.0.1/tcp/4000 /ip4/10.244.0.48/tcp/4000]
2024-06-23T09:01:58.717Z	INFO	modules	modules/services.go:158	subscribing to pubsub topic /fil/blocks/localnet-6aeed03f-56ae-4954-8168-a8b36445fa51
2024-06-23T09:01:58.717Z	INFO	modules	modules/services.go:178	subscribing to pubsub topic /fil/msgs/localnet-6aeed03f-56ae-4954-8168-a8b36445fa51
2024-06-23T09:01:58.718Z	INFO	messagepool	messagepool/messagepool.go:446	mpool ready
2024-06-23T09:01:58.718Z	INFO	modules	modules/services.go:223	relaying messages for pubsub topic /indexer/ingest/localnet-6aeed03f-56ae-4954-8168-a8b36445fa51
2024-06-23T09:01:58.719Z	WARN	modules	modules/core.go:147	Generating new API secret
2024-06-23T09:01:58.720Z	INFO	importmgr	imports/manager.go:61	sanity checking imports
2024/06/23 09:01:58 storess: Query
2024/06/23 09:01:58 storess: q.Prefix: 
2024/06/23 09:01:58 storess: q.KeysOnly: true
2024/06/23 09:01:58 storess: q.Filters: 0
2024/06/23 09:01:58 storess: q.Orders: 0
2024/06/23 09:01:58 storess: q.Offset: 0
2024-06-23T09:01:58.720Z	INFO	importmgr	imports/manager.go:98	sanity check completed	{"broken": 0, "total": 0}
2024-06-23T09:01:58.726Z	INFO	modules	modules/ethmodule.go:63	Start prefilling GetTipsetByHeight cache
2024-06-23T09:01:58.726Z	INFO	modules	modules/ethmodule.go:68	Prefilling GetTipsetByHeight done in 125.133µs
2024-06-23T09:01:58.731Z	INFO	splitstore	splitstore/splitstore.go:791	starting splitstore	{"baseEpoch": "0", "warmupEpoch": 0}
2024-06-23T09:01:58.731Z	INFO	dt-impl	impl/impl.go:138	start data-transfer module
2024-06-23T09:01:58.731Z	WARN	statemgr	stmgr/forks.go:245	STARTING pre-migration
manifest cid: bafy2bzacecn7uxgehrqbcs462ktl2h23u23cmduy2etqj6xrd6tkkja56fna4
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Creating migration jobs
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Done creating 17 migration jobs after 196.905µs
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 16 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 49 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 84 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Started 128 workers
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 127 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 48 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 100 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 67 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 45 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 68 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 92 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 74 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 122 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 9 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 89 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 62 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 94 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 93 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 91 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 44 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 126 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 102 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 119 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 99 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 61 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 96 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 103 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 35 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 120 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 112 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 98 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 23 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 105 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 25 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 86 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 18 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 24 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 50 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 63 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 111 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 107 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 51 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 117 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 121 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 110 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 56 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 58 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 83 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 47 done
2024-06-23T09:01:58.733Z	INFO	markets	loggers/loggers.go:65	module ready	{"module": "client data transfer"}
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 52 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 81 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Result writer started
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 82 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 101 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 46 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 85 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 115 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 33 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 116 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 113 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 0 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 5 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 11 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 4 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 7 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 15 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 8 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 43 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 30 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 76 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 40 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 123 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 29 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 124 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 66 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 72 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 90 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 114 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 125 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 69 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 65 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 80 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 73 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 71 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 95 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 87 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 75 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 118 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 78 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 77 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 88 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 34 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 28 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 108 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 60 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 36 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 32 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 79 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 104 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 97 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 64 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 38 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 31 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 59 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 53 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 39 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 27 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 21 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 57 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 109 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 19 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 106 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 54 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 20 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 42 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 22 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 55 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 26 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 41 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 37 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 12 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 17 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 1 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 10 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 3 done
2024-06-23T09:01:58.732Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 70 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 2 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 14 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 13 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	Worker 6 done
2024-06-23T09:01:58.733Z	INFO	fil-consensus	filcns/upgrades.go:2627	All workers done after 1.5629ms
2024-06-23T09:01:58.734Z	INFO	fil-consensus	filcns/upgrades.go:2627	Result writer wrote 16 results to state tree after 1.593731ms
2024-06-23T09:01:58.734Z	INFO	fil-consensus	filcns/upgrades.go:2627	Running deferred migrations
2024-06-23T09:01:58.734Z	INFO	fil-consensus	filcns/upgrades.go:2627	Running deferred migration for t05
2024-06-23T09:01:58.734Z	INFO	markets	loggers/loggers.go:65	module ready	{"module": "storage client"}
2024-06-23T09:01:58.734Z	INFO	markets	loggers/loggers.go:65	module ready	{"module": "discovery"}
2024-06-23T09:01:58.734Z	INFO	markets	loggers/loggers.go:65	module ready	{"module": "retrieval client"}
2024-06-23T09:01:58.734Z	INFO	fil-consensus	filcns/upgrades.go:2627	All 17 done after 2.094194ms (8118/s)
2024-06-23T09:01:58.734Z	WARN	statemgr	stmgr/forks.go:258	COMPLETED pre-migration	{"duration": 0.002960627}
2024-06-23T09:01:58.743Z	INFO	healthcheck	node/health.go:57	waiting 1s before starting ChainNotify channel
2024-06-23T09:01:59.744Z	INFO	healthcheck	node/health.go:70	started ChainNotify channel
2024-06-23T09:02:03.605Z	INFO	basichost	basic/natmgr.go:112	DiscoverNAT error:no NAT found
2024-06-23T09:02:03.716Z	WARN	peermgr	peermgr/peermgr.go:205	no peers connected, and no bootstrappers configured
2024-06-23T09:02:08.716Z	WARN	peermgr	peermgr/peermgr.go:205	no peers connected, and no bootstrappers configured
2024-06-23T09:02:13.716Z	WARN	peermgr	peermgr/peermgr.go:205	no peers connected, and no bootstrappers configured
2024-06-23T09:02:18.716Z	WARN	peermgr	peermgr/peermgr.go:205	no peers connected, and no bootstrappers configured
2024-06-23T09:02:23.716Z	WARN	peermgr	peermgr/peermgr.go:205	no peers connected, and no bootstrappers configured
2024-06-23T09:02:28.716Z	WARN	peermgr	peermgr/peermgr.go:205	no peers connected, and no bootstrappers configured
2024-06-23T09:02:31.357Z	INFO	chain	chain/sync_manager.go:220	selected initial sync target: [bafy2bzacedjfus4ia74turkwucymbe2jin5s7uiwkli2keggiiyyzmwyauek6]
2024-06-23T09:02:31.357Z	INFO	chain	chain/sync_manager.go:316	worker 0 syncing in [bafy2bzacedjfus4ia74turkwucymbe2jin5s7uiwkli2keggiiyyzmwyauek6]
2024-06-23T09:02:31.360Z	INFO	chain	chain/sync.go:790	Got blocks: 6 6
2024-06-23T09:02:31.407Z	INFO	chain	chain/sync.go:625	block validation	{"took": 0.045074187, "height": "1", "age": 401632.407847973}
2024-06-23T09:02:31.408Z	INFO	chain	chain/sync.go:1118	fetching messages at 0
2024-06-23T09:02:31.411Z	INFO	chain	chain/sync.go:1160	fetching messages for 6 tipsets at 0 done; took 3.270885ms
2024-06-23T09:02:31.821Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzacedjfus4ia74turkwucymbe2jin5s7uiwkli2keggiiyyzmwyauek6", "delay": 401608, "miner": "t01000"}
2024-06-23T09:02:32.463Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzacedgob75s4bfnbliqmjpim24stz6cskwfvhs4psja3xt7mhvouez34", "delay": 401605, "miner": "t01000"}
2024-06-23T09:02:34.729Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzaceafzku26qkw3szhz56z76bcaqyzpmy6h6hfmv4hkeqzwgtzcxidcg", "delay": 401603, "miner": "t01000"}
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
[DEBUG]<StoragePower::4> ProofValidationBatch was nil, quitting verification
2024-06-23T09:02:36.243Z	INFO	consensus-common	consensus/compute_state.go:304	ApplyBlocks stats	{"early": 0.00000449, "earlyCronGas": 0, "vmMsg": 4.827442726, "msgGas": 0, "vmCron": 0.002374221, "cronGas": 24133947, "vmFlush": 0.001607532, "epoch": "1", "tsk": "{bafy2bzaceahpklrko5yeioncybcxaaru2yaunwmi6uvweby745nrmm3yqe3eo}"}
2024-06-23T09:02:36.245Z	INFO	chain	chain/sync.go:625	block validation	{"took": 4.833903923, "height": "2", "age": 401633.245356509}
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
...
skipping 45000 lines 
...
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
[DEBUG]<StoragePower::4> ProofValidationBatch was nil, quitting verification
2024-06-23T12:15:49.732Z	INFO	consensus-common	consensus/compute_state.go:304	ApplyBlocks stats	{"early": 0.00000547, "earlyCronGas": 0, "vmMsg": 0.007335319, "msgGas": 2431726, "vmCron": 0.002929384, "cronGas": 16206903, "vmFlush": 0.001601615, "epoch": "5025", "tsk": "{bafy2bzacea6gpm4p3ohh3px6nofoemltzdkggwxfas7esj7ciokjvobhzu54w}"}
2024-06-23T12:15:49.766Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzacedhszivsy5pzzevpmbuxblxq2gtpmvltlwzpwzomenwvzxx72ss5c", "delay": 393130, "miner": "t01000"}
2024-06-23T12:15:49.769Z	INFO	chain	chain/sync_manager.go:234	selected sync target: [bafy2bzacedhszivsy5pzzevpmbuxblxq2gtpmvltlwzpwzomenwvzxx72ss5c]
2024-06-23T12:15:49.769Z	INFO	chain	chain/sync_manager.go:316	worker 4976 syncing in [bafy2bzacedhszivsy5pzzevpmbuxblxq2gtpmvltlwzpwzomenwvzxx72ss5c]
2024-06-23T12:15:49.776Z	INFO	chain	chain/sync.go:625	block validation	{"took": 0.006938588, "height": "5026", "age": 393130.776710132}
2024-06-23T12:15:49.777Z	INFO	chainstore	store/store.go:683	New heaviest tipset! [bafy2bzacedhszivsy5pzzevpmbuxblxq2gtpmvltlwzpwzomenwvzxx72ss5c] (height=5026)
2024-06-23T12:15:49.778Z	INFO	chain	chain/sync_manager.go:324	worker 4976 done; took 8.592305ms
2024-06-23T12:15:52.090Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzacec6wfbw7y57ke7y6scxjf723upmcgcqsebjxp4oqavkh23clvyjyk", "delay": 393129, "miner": "t01000"}
2024-06-23T12:15:52.094Z	INFO	chain	chain/sync_manager.go:234	selected sync target: [bafy2bzacec6wfbw7y57ke7y6scxjf723upmcgcqsebjxp4oqavkh23clvyjyk]
2024-06-23T12:15:52.094Z	INFO	chain	chain/sync_manager.go:316	worker 4977 syncing in [bafy2bzacec6wfbw7y57ke7y6scxjf723upmcgcqsebjxp4oqavkh23clvyjyk]
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
[DEBUG]<StoragePower::4> ProofValidationBatch was nil, quitting verification
2024-06-23T12:15:52.108Z	INFO	consensus-common	consensus/compute_state.go:304	ApplyBlocks stats	{"early": 0.00000534, "earlyCronGas": 0, "vmMsg": 0.008342638, "msgGas": 2431726, "vmCron": 0.003677285, "cronGas": 16206803, "vmFlush": 0.001462071, "epoch": "5026", "tsk": "{bafy2bzacedhszivsy5pzzevpmbuxblxq2gtpmvltlwzpwzomenwvzxx72ss5c}"}
2024-06-23T12:15:52.109Z	INFO	chain	chain/sync.go:625	block validation	{"took": 0.015409259, "height": "5027", "age": 393129.109900288}
2024-06-23T12:15:52.110Z	INFO	chainstore	store/store.go:683	New heaviest tipset! [bafy2bzacec6wfbw7y57ke7y6scxjf723upmcgcqsebjxp4oqavkh23clvyjyk] (height=5027)
2024-06-23T12:15:52.111Z	INFO	chain	chain/sync_manager.go:324	worker 4977 done; took 16.920413ms
2024-06-23T12:15:54.413Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzacebkqtul2gx6u33beplft24rbas7vunxh74dtk23m3zlcscbln7qeq", "delay": 393127, "miner": "t01000"}
2024-06-23T12:15:54.417Z	INFO	chain	chain/sync_manager.go:234	selected sync target: [bafy2bzacebkqtul2gx6u33beplft24rbas7vunxh74dtk23m3zlcscbln7qeq]
2024-06-23T12:15:54.417Z	INFO	chain	chain/sync_manager.go:316	worker 4978 syncing in [bafy2bzacebkqtul2gx6u33beplft24rbas7vunxh74dtk23m3zlcscbln7qeq]
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
[DEBUG]<StoragePower::4> ProofValidationBatch was nil, quitting verification
2024-06-23T12:15:54.431Z	INFO	consensus-common	consensus/compute_state.go:304	ApplyBlocks stats	{"early": 0.00000475, "earlyCronGas": 0, "vmMsg": 0.00840312, "msgGas": 1215863, "vmCron": 0.003055647, "cronGas": 16206631, "vmFlush": 0.001623457, "epoch": "5027", "tsk": "{bafy2bzacec6wfbw7y57ke7y6scxjf723upmcgcqsebjxp4oqavkh23clvyjyk}"}
2024-06-23T12:15:54.432Z	INFO	chain	chain/sync.go:625	block validation	{"took": 0.014976148, "height": "5028", "age": 393127.43256013}
2024-06-23T12:15:54.433Z	INFO	chainstore	store/store.go:683	New heaviest tipset! [bafy2bzacebkqtul2gx6u33beplft24rbas7vunxh74dtk23m3zlcscbln7qeq] (height=5028)
2024-06-23T12:15:54.434Z	INFO	chain	chain/sync_manager.go:324	worker 4978 done; took 16.880312ms
2024-06-23T12:15:56.733Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzacebvwvlvkl4cfctk4dvbysdvi57zsukybhl6ddtzapv755rwi5uabo", "delay": 393125, "miner": "t01000"}
2024-06-23T12:15:56.737Z	INFO	chain	chain/sync_manager.go:234	selected sync target: [bafy2bzacebvwvlvkl4cfctk4dvbysdvi57zsukybhl6ddtzapv755rwi5uabo]
2024-06-23T12:15:56.737Z	INFO	chain	chain/sync_manager.go:316	worker 4979 syncing in [bafy2bzacebvwvlvkl4cfctk4dvbysdvi57zsukybhl6ddtzapv755rwi5uabo]
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
[DEBUG]<StoragePower::4> ProofValidationBatch was nil, quitting verification
2024-06-23T12:15:56.749Z	INFO	consensus-common	consensus/compute_state.go:304	ApplyBlocks stats	{"early": 0.0000045, "earlyCronGas": 0, "vmMsg": 0.007235766, "msgGas": 2431726, "vmCron": 0.00209661, "cronGas": 16206603, "vmFlush": 0.001675088, "epoch": "5028", "tsk": "{bafy2bzacebkqtul2gx6u33beplft24rbas7vunxh74dtk23m3zlcscbln7qeq}"}
2024-06-23T12:15:56.750Z	INFO	chain	chain/sync.go:625	block validation	{"took": 0.012559759, "height": "5029", "age": 393125.750149292}
2024-06-23T12:15:56.750Z	INFO	chainstore	store/store.go:683	New heaviest tipset! [bafy2bzacebvwvlvkl4cfctk4dvbysdvi57zsukybhl6ddtzapv755rwi5uabo] (height=5029)
2024-06-23T12:15:56.751Z	INFO	chain	chain/sync_manager.go:324	worker 4979 done; took 14.03627ms
2024-06-23T12:15:59.055Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzacecp2by4bkk7l3aloidzaqpowf4vqocvw7lxicovqwyfuex5qp7wji", "delay": 393124, "miner": "t01000"}
2024-06-23T12:15:59.059Z	INFO	chain	chain/sync_manager.go:234	selected sync target: [bafy2bzacecp2by4bkk7l3aloidzaqpowf4vqocvw7lxicovqwyfuex5qp7wji]
2024-06-23T12:15:59.059Z	INFO	chain	chain/sync_manager.go:316	worker 4980 syncing in [bafy2bzacecp2by4bkk7l3aloidzaqpowf4vqocvw7lxicovqwyfuex5qp7wji]
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
[DEBUG]<StoragePower::4> ProofValidationBatch was nil, quitting verification
2024-06-23T12:15:59.072Z	INFO	consensus-common	consensus/compute_state.go:304	ApplyBlocks stats	{"early": 0.00000494, "earlyCronGas": 0, "vmMsg": 0.008486802, "msgGas": 2431726, "vmCron": 0.002368858, "cronGas": 16207275, "vmFlush": 0.001568385, "epoch": "5029", "tsk": "{bafy2bzacebvwvlvkl4cfctk4dvbysdvi57zsukybhl6ddtzapv755rwi5uabo}"}
2024-06-23T12:15:59.074Z	INFO	chain	chain/sync.go:625	block validation	{"took": 0.014672619, "height": "5030", "age": 393124.074217764}
2024-06-23T12:15:59.075Z	INFO	chainstore	store/store.go:683	New heaviest tipset! [bafy2bzacecp2by4bkk7l3aloidzaqpowf4vqocvw7lxicovqwyfuex5qp7wji] (height=5030)
2024-06-23T12:15:59.075Z	INFO	chain	chain/sync_manager.go:324	worker 4980 done; took 16.662025ms
2024-06-23T12:16:01.381Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzacecwmk47l35xlcglpnvo7r6bjwadwd62jcqgja3jwq5brv2xzu37mk", "delay": 393122, "miner": "t01000"}
2024-06-23T12:16:01.385Z	INFO	chain	chain/sync_manager.go:234	selected sync target: [bafy2bzacecwmk47l35xlcglpnvo7r6bjwadwd62jcqgja3jwq5brv2xzu37mk]
2024-06-23T12:16:01.385Z	INFO	chain	chain/sync_manager.go:316	worker 4981 syncing in [bafy2bzacecwmk47l35xlcglpnvo7r6bjwadwd62jcqgja3jwq5brv2xzu37mk]
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
[DEBUG]<StoragePower::4> ProofValidationBatch was nil, quitting verification
2024-06-23T12:16:01.399Z	INFO	consensus-common	consensus/compute_state.go:304	ApplyBlocks stats	{"early": 0.00000528, "earlyCronGas": 0, "vmMsg": 0.008098581, "msgGas": 2431726, "vmCron": 0.002975635, "cronGas": 16206831, "vmFlush": 0.001643837, "epoch": "5030", "tsk": "{bafy2bzacecp2by4bkk7l3aloidzaqpowf4vqocvw7lxicovqwyfuex5qp7wji}"}
2024-06-23T12:16:01.400Z	INFO	chain	chain/sync.go:625	block validation	{"took": 0.0147155, "height": "5031", "age": 393122.400572976}
2024-06-23T12:16:01.400Z	INFO	chainstore	store/store.go:683	New heaviest tipset! [bafy2bzacecwmk47l35xlcglpnvo7r6bjwadwd62jcqgja3jwq5brv2xzu37mk] (height=5031)
2024-06-23T12:16:01.401Z	INFO	chain	chain/sync_manager.go:324	worker 4981 done; took 16.411698ms
2024-06-23T12:16:03.722Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzacecwv7lnxhod2iiw735obzvrhv7wsl5fjpfzp3qubqtzv3z2jr7lco", "delay": 393120, "miner": "t01000"}
2024-06-23T12:16:03.724Z	INFO	chain	chain/sync_manager.go:234	selected sync target: [bafy2bzacecwv7lnxhod2iiw735obzvrhv7wsl5fjpfzp3qubqtzv3z2jr7lco]
2024-06-23T12:16:03.724Z	INFO	chain	chain/sync_manager.go:316	worker 4982 syncing in [bafy2bzacecwv7lnxhod2iiw735obzvrhv7wsl5fjpfzp3qubqtzv3z2jr7lco]
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
[DEBUG]<StoragePower::4> ProofValidationBatch was nil, quitting verification
2024-06-23T12:16:03.735Z	INFO	consensus-common	consensus/compute_state.go:304	ApplyBlocks stats	{"early": 0.0000051, "earlyCronGas": 0, "vmMsg": 0.006180927, "msgGas": 2431726, "vmCron": 0.002094019, "cronGas": 16206731, "vmFlush": 0.001844953, "epoch": "5031", "tsk": "{bafy2bzacecwmk47l35xlcglpnvo7r6bjwadwd62jcqgja3jwq5brv2xzu37mk}"}
2024-06-23T12:16:03.736Z	INFO	chain	chain/sync.go:625	block validation	{"took": 0.011593111, "height": "5032", "age": 393120.736841117}
2024-06-23T12:16:03.737Z	INFO	chainstore	store/store.go:683	New heaviest tipset! [bafy2bzacecwv7lnxhod2iiw735obzvrhv7wsl5fjpfzp3qubqtzv3z2jr7lco] (height=5032)
2024-06-23T12:16:03.738Z	INFO	chain	chain/sync_manager.go:324	worker 4982 done; took 13.094634ms
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
[DEBUG]<StoragePower::4> ProofValidationBatch was nil, quitting verification
2024-06-23T12:16:05.824Z	INFO	consensus-common	consensus/compute_state.go:304	ApplyBlocks stats	{"early": 0.0000032, "earlyCronGas": 0, "vmMsg": 0.00664355, "msgGas": 2431726, "vmCron": 0.002692887, "cronGas": 16210447, "vmFlush": 0.001986057, "epoch": "5032", "tsk": "{bafy2bzacecwv7lnxhod2iiw735obzvrhv7wsl5fjpfzp3qubqtzv3z2jr7lco}"}
2024-06-23T12:16:06.036Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzacedhfgh5miyf765xjdohvnp2c3nil2kn7gtmf45pxpgaqflvt3twti", "delay": 393119, "miner": "t01000"}
2024-06-23T12:16:06.040Z	INFO	chain	chain/sync_manager.go:234	selected sync target: [bafy2bzacedhfgh5miyf765xjdohvnp2c3nil2kn7gtmf45pxpgaqflvt3twti]
2024-06-23T12:16:06.040Z	INFO	chain	chain/sync_manager.go:316	worker 4983 syncing in [bafy2bzacedhfgh5miyf765xjdohvnp2c3nil2kn7gtmf45pxpgaqflvt3twti]
2024-06-23T12:16:06.048Z	INFO	chain	chain/sync.go:625	block validation	{"took": 0.007794882, "height": "5033", "age": 393119.048913931}
2024-06-23T12:16:06.049Z	INFO	chainstore	store/store.go:683	New heaviest tipset! [bafy2bzacedhfgh5miyf765xjdohvnp2c3nil2kn7gtmf45pxpgaqflvt3twti] (height=5033)
2024-06-23T12:16:06.050Z	INFO	chain	chain/sync_manager.go:324	worker 4983 done; took 9.45874ms
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
[DEBUG]<StoragePower::4> ProofValidationBatch was nil, quitting verification
2024-06-23T12:16:08.327Z	INFO	consensus-common	consensus/compute_state.go:304	ApplyBlocks stats	{"early": 0.00000456, "earlyCronGas": 0, "vmMsg": 0.007872135, "msgGas": 2431726, "vmCron": 0.00280591, "cronGas": 16210383, "vmFlush": 0.001794192, "epoch": "5033", "tsk": "{bafy2bzacedhfgh5miyf765xjdohvnp2c3nil2kn7gtmf45pxpgaqflvt3twti}"}
2024-06-23T12:16:08.518Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzacecc365c2ybhbn55kwvckpvqxiqaj4ppacgkorbyg354unwiu7gbga", "delay": 393117, "miner": "t01000"}
2024-06-23T12:16:08.522Z	INFO	chain	chain/sync_manager.go:234	selected sync target: [bafy2bzacecc365c2ybhbn55kwvckpvqxiqaj4ppacgkorbyg354unwiu7gbga]
2024-06-23T12:16:08.522Z	INFO	chain	chain/sync_manager.go:316	worker 4984 syncing in [bafy2bzacecc365c2ybhbn55kwvckpvqxiqaj4ppacgkorbyg354unwiu7gbga]
2024-06-23T12:16:08.530Z	INFO	chain	chain/sync.go:625	block validation	{"took": 0.007048242, "height": "5034", "age": 393117.530251207}
2024-06-23T12:16:08.530Z	INFO	chainstore	store/store.go:683	New heaviest tipset! [bafy2bzacecc365c2ybhbn55kwvckpvqxiqaj4ppacgkorbyg354unwiu7gbga] (height=5034)
2024-06-23T12:16:08.531Z	INFO	chain	chain/sync_manager.go:324	worker 4984 done; took 9.073099ms
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
[DEBUG]<StoragePower::4> ProofValidationBatch was nil, quitting verification
2024-06-23T12:16:10.766Z	INFO	consensus-common	consensus/compute_state.go:304	ApplyBlocks stats	{"early": 0.00000429, "earlyCronGas": 0, "vmMsg": 0.00803308, "msgGas": 2431726, "vmCron": 0.003076918, "cronGas": 16207047, "vmFlush": 0.002180102, "epoch": "5034", "tsk": "{bafy2bzacecc365c2ybhbn55kwvckpvqxiqaj4ppacgkorbyg354unwiu7gbga}"}
2024-06-23T12:16:10.808Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzacecvgaqmffjuwvo7geb7olj2rm6i5aigsoj7eyxjfwft3og6yxj3py", "delay": 393115, "miner": "t01000"}
2024-06-23T12:16:10.812Z	INFO	chain	chain/sync_manager.go:234	selected sync target: [bafy2bzacecvgaqmffjuwvo7geb7olj2rm6i5aigsoj7eyxjfwft3og6yxj3py]
2024-06-23T12:16:10.812Z	INFO	chain	chain/sync_manager.go:316	worker 4985 syncing in [bafy2bzacecvgaqmffjuwvo7geb7olj2rm6i5aigsoj7eyxjfwft3og6yxj3py]
2024-06-23T12:16:10.820Z	INFO	chain	chain/sync.go:625	block validation	{"took": 0.007543526, "height": "5035", "age": 393115.82090284}
2024-06-23T12:16:10.821Z	INFO	chainstore	store/store.go:683	New heaviest tipset! [bafy2bzacecvgaqmffjuwvo7geb7olj2rm6i5aigsoj7eyxjfwft3og6yxj3py] (height=5035)
2024-06-23T12:16:10.822Z	INFO	chain	chain/sync_manager.go:324	worker 4985 done; took 9.458091ms
2024-06-23T12:16:13.114Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzacecw2hbqzdh3ziwaowtqiblq5chl262qq2zkaszny7lfwk4tgqmj6s", "delay": 393114, "miner": "t01000"}
2024-06-23T12:16:13.118Z	INFO	chain	chain/sync_manager.go:234	selected sync target: [bafy2bzacecw2hbqzdh3ziwaowtqiblq5chl262qq2zkaszny7lfwk4tgqmj6s]
2024-06-23T12:16:13.118Z	INFO	chain	chain/sync_manager.go:316	worker 4986 syncing in [bafy2bzacecw2hbqzdh3ziwaowtqiblq5chl262qq2zkaszny7lfwk4tgqmj6s]
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
[DEBUG]<StoragePower::4> ProofValidationBatch was nil, quitting verification
2024-06-23T12:16:13.131Z	INFO	consensus-common	consensus/compute_state.go:304	ApplyBlocks stats	{"early": 0.00000551, "earlyCronGas": 0, "vmMsg": 0.007829733, "msgGas": 2431726, "vmCron": 0.002575964, "cronGas": 16207275, "vmFlush": 0.001681948, "epoch": "5035", "tsk": "{bafy2bzacecvgaqmffjuwvo7geb7olj2rm6i5aigsoj7eyxjfwft3og6yxj3py}"}
2024-06-23T12:16:13.133Z	INFO	chain	chain/sync.go:625	block validation	{"took": 0.014053082, "height": "5036", "age": 393114.133055522}
2024-06-23T12:16:13.133Z	INFO	chainstore	store/store.go:683	New heaviest tipset! [bafy2bzacecw2hbqzdh3ziwaowtqiblq5chl262qq2zkaszny7lfwk4tgqmj6s] (height=5036)
2024-06-23T12:16:13.134Z	INFO	chain	chain/sync_manager.go:324	worker 4986 done; took 15.859133ms
2024-06-23T12:16:15.422Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzacedehfvezsptagb66ivap2c6ktdiknptrvubploxih2t7koou4mtca", "delay": 393112, "miner": "t01000"}
2024-06-23T12:16:15.426Z	INFO	chain	chain/sync_manager.go:234	selected sync target: [bafy2bzacedehfvezsptagb66ivap2c6ktdiknptrvubploxih2t7koou4mtca]
2024-06-23T12:16:15.426Z	INFO	chain	chain/sync_manager.go:316	worker 4987 syncing in [bafy2bzacedehfvezsptagb66ivap2c6ktdiknptrvubploxih2t7koou4mtca]
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
[DEBUG]<StoragePower::4> ProofValidationBatch was nil, quitting verification
2024-06-23T12:16:15.439Z	INFO	consensus-common	consensus/compute_state.go:304	ApplyBlocks stats	{"early": 0.00000415, "earlyCronGas": 0, "vmMsg": 0.006857646, "msgGas": 1215863, "vmCron": 0.002987156, "cronGas": 16207103, "vmFlush": 0.001608986, "epoch": "5036", "tsk": "{bafy2bzacecw2hbqzdh3ziwaowtqiblq5chl262qq2zkaszny7lfwk4tgqmj6s}"}
2024-06-23T12:16:15.440Z	INFO	chain	chain/sync.go:625	block validation	{"took": 0.013133186, "height": "5037", "age": 393112.440197126}
2024-06-23T12:16:15.440Z	INFO	chainstore	store/store.go:683	New heaviest tipset! [bafy2bzacedehfvezsptagb66ivap2c6ktdiknptrvubploxih2t7koou4mtca] (height=5037)
2024-06-23T12:16:15.441Z	INFO	chain	chain/sync_manager.go:324	worker 4987 done; took 14.65569ms
2024-06-23T12:16:17.756Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzaceaqgp6jc7xloekiajudf72wa6325anfpshtisbsvdqyxifm3yjez2", "delay": 393110, "miner": "t01000"}
2024-06-23T12:16:17.760Z	INFO	chain	chain/sync_manager.go:234	selected sync target: [bafy2bzaceaqgp6jc7xloekiajudf72wa6325anfpshtisbsvdqyxifm3yjez2]
2024-06-23T12:16:17.760Z	INFO	chain	chain/sync_manager.go:316	worker 4988 syncing in [bafy2bzaceaqgp6jc7xloekiajudf72wa6325anfpshtisbsvdqyxifm3yjez2]
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
[DEBUG]<StoragePower::4> ProofValidationBatch was nil, quitting verification
[DEBUG]<StorageMiner::1000> storage provider f01000 penalized 0.0 for expired pre commits
[DEBUG]<StorageMiner::1000> storage provider f01000 penalized 0.0 for continued fault
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
2024-06-23T12:16:17.774Z	INFO	consensus-common	consensus/compute_state.go:304	ApplyBlocks stats	{"early": 0.000005261, "earlyCronGas": 0, "vmMsg": 0.005881467, "msgGas": 2431726, "vmCron": 0.005526878, "cronGas": 28547584, "vmFlush": 0.001553875, "epoch": "5037", "tsk": "{bafy2bzacedehfvezsptagb66ivap2c6ktdiknptrvubploxih2t7koou4mtca}"}
2024-06-23T12:16:17.775Z	INFO	chain	chain/sync.go:625	block validation	{"took": 0.014684139, "height": "5038", "age": 393110.775533409}
2024-06-23T12:16:17.775Z	INFO	chainstore	store/store.go:683	New heaviest tipset! [bafy2bzaceaqgp6jc7xloekiajudf72wa6325anfpshtisbsvdqyxifm3yjez2] (height=5038)
2024-06-23T12:16:17.776Z	INFO	chain	chain/sync_manager.go:324	worker 4988 done; took 16.059799ms
2024-06-23T12:16:20.103Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzacedds5e34xunnh4kkz42pirwhfrixrfod67s6swshcaploqsvfkb7e", "delay": 393109, "miner": "t01000"}
2024-06-23T12:16:20.105Z	INFO	chain	chain/sync_manager.go:234	selected sync target: [bafy2bzacedds5e34xunnh4kkz42pirwhfrixrfod67s6swshcaploqsvfkb7e]
2024-06-23T12:16:20.105Z	INFO	chain	chain/sync_manager.go:316	worker 4989 syncing in [bafy2bzacedds5e34xunnh4kkz42pirwhfrixrfod67s6swshcaploqsvfkb7e]
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
[DEBUG]<StoragePower::4> ProofValidationBatch was nil, quitting verification
2024-06-23T12:16:20.117Z	INFO	consensus-common	consensus/compute_state.go:304	ApplyBlocks stats	{"early": 0.00000424, "earlyCronGas": 0, "vmMsg": 0.00628364, "msgGas": 2431726, "vmCron": 0.002290285, "cronGas": 16206736, "vmFlush": 0.001700089, "epoch": "5038", "tsk": "{bafy2bzaceaqgp6jc7xloekiajudf72wa6325anfpshtisbsvdqyxifm3yjez2}"}
2024-06-23T12:16:20.118Z	INFO	chain	chain/sync.go:625	block validation	{"took": 0.012152107, "height": "5039", "age": 393109.118473705}
2024-06-23T12:16:20.119Z	INFO	chainstore	store/store.go:683	New heaviest tipset! [bafy2bzacedds5e34xunnh4kkz42pirwhfrixrfod67s6swshcaploqsvfkb7e] (height=5039)
2024-06-23T12:16:20.119Z	INFO	chain	chain/sync_manager.go:324	worker 4989 done; took 13.945119ms
2024-06-23T12:16:22.473Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzacedrg2ffhti6x23dnplqzejeauaawuv7yec4c2iowodvum5iqgdnn4", "delay": 393107, "miner": "t01000"}
2024-06-23T12:16:22.478Z	INFO	chain	chain/sync_manager.go:234	selected sync target: [bafy2bzacedrg2ffhti6x23dnplqzejeauaawuv7yec4c2iowodvum5iqgdnn4]
2024-06-23T12:16:22.478Z	INFO	chain	chain/sync_manager.go:316	worker 4990 syncing in [bafy2bzacedrg2ffhti6x23dnplqzejeauaawuv7yec4c2iowodvum5iqgdnn4]
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
[DEBUG]<StoragePower::4> ProofValidationBatch was nil, quitting verification
2024-06-23T12:16:22.490Z	INFO	consensus-common	consensus/compute_state.go:304	ApplyBlocks stats	{"early": 0.00000487, "earlyCronGas": 0, "vmMsg": 0.00769324, "msgGas": 2431726, "vmCron": 0.00211064, "cronGas": 16206736, "vmFlush": 0.001587616, "epoch": "5039", "tsk": "{bafy2bzacedds5e34xunnh4kkz42pirwhfrixrfod67s6swshcaploqsvfkb7e}"}
2024-06-23T12:16:22.491Z	INFO	chain	chain/sync.go:625	block validation	{"took": 0.013070543, "height": "5040", "age": 393107.491569559}
2024-06-23T12:16:22.492Z	INFO	chainstore	store/store.go:683	New heaviest tipset! [bafy2bzacedrg2ffhti6x23dnplqzejeauaawuv7yec4c2iowodvum5iqgdnn4] (height=5040)
2024-06-23T12:16:22.493Z	INFO	chain	chain/sync_manager.go:324	worker 4990 done; took 14.804503ms
2024-06-23T12:16:24.793Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzaced2nbu6i32iiewm54e5fp7jj3xfafmjyagkywyj3cvyav5qpxntay", "delay": 393105, "miner": "t01000"}
2024-06-23T12:16:24.796Z	INFO	chain	chain/sync_manager.go:234	selected sync target: [bafy2bzaced2nbu6i32iiewm54e5fp7jj3xfafmjyagkywyj3cvyav5qpxntay]
2024-06-23T12:16:24.796Z	INFO	chain	chain/sync_manager.go:316	worker 4991 syncing in [bafy2bzaced2nbu6i32iiewm54e5fp7jj3xfafmjyagkywyj3cvyav5qpxntay]
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
[DEBUG]<StoragePower::4> ProofValidationBatch was nil, quitting verification
2024-06-23T12:16:24.809Z	INFO	consensus-common	consensus/compute_state.go:304	ApplyBlocks stats	{"early": 0.00000448, "earlyCronGas": 0, "vmMsg": 0.006948799, "msgGas": 2431726, "vmCron": 0.003032557, "cronGas": 16206836, "vmFlush": 0.001689508, "epoch": "5040", "tsk": "{bafy2bzacedrg2ffhti6x23dnplqzejeauaawuv7yec4c2iowodvum5iqgdnn4}"}
2024-06-23T12:16:24.810Z	INFO	chain	chain/sync.go:625	block validation	{"took": 0.013519617, "height": "5041", "age": 393105.810655913}
2024-06-23T12:16:24.810Z	INFO	chainstore	store/store.go:683	New heaviest tipset! [bafy2bzaced2nbu6i32iiewm54e5fp7jj3xfafmjyagkywyj3cvyav5qpxntay] (height=5041)
2024-06-23T12:16:24.812Z	INFO	chain	chain/sync_manager.go:324	worker 4991 done; took 15.38236ms
[DEBUG]<StorageMiner::1000> storage provder f01000 burning 0.0
[DEBUG]<StoragePower::4> ProofValidationBatch was nil, quitting verification
2024-06-23T12:16:26.924Z	INFO	consensus-common	consensus/compute_state.go:304	ApplyBlocks stats	{"early": 0.00000409, "earlyCronGas": 0, "vmMsg": 0.008145533, "msgGas": 2431726, "vmCron": 0.002756889, "cronGas": 16206736, "vmFlush": 0.001330978, "epoch": "5041", "tsk": "{bafy2bzaced2nbu6i32iiewm54e5fp7jj3xfafmjyagkywyj3cvyav5qpxntay}"}
2024-06-23T12:16:27.121Z	WARN	sub	sub/incoming.go:102	received block with large delay from miner	{"block": "bafy2bzaceb76unix3kpdp232vecm2fbwri5muih5cr5rltbkpzn7x2abeesb4", "delay": 393104, "miner": "t01000"}
2024-06-23T12:16:27.125Z	INFO	chain	chain/sync_manager.go:234	selected sync target: [bafy2bzaceb76unix3kpdp232vecm2fbwri5muih5cr5rltbkpzn7x2abeesb4]
2024-06-23T12:16:27.125Z	INFO	chain	chain/sync_manager.go:316	worker 4992 syncing in [bafy2bzaceb76unix3kpdp232vecm2fbwri5muih5cr5rltbkpzn7x2abeesb4]
2024-06-23T12:16:27.134Z	INFO	chain	chain/sync.go:625	block validation	{"took": 0.007776372, "height": "5042", "age": 393104.134211619}
2024-06-23T12:16:27.135Z	INFO	chainstore	store/store.go:683	New heaviest tipset! [bafy2bzaceb76unix3kpdp232vecm2fbwri5muih5cr5rltbkpzn7x2abeesb4] (height=5042)
2024-06-23T12:16:27.136Z	INFO	chain	chain/sync_manager.go:324	worker 4992 done; took 10.529971ms
SIGSEGV: segmentation violation
PC=0x7ffe3f163a16 m=37 sigcode=1
@frystal frystal added the kind/bug Kind: Bug label Jun 26, 2024
@TippyFlitsUK
Copy link
Contributor

It looks like you are running a dirty build @frystal. Have you changed any code?

@Stebalien
Copy link
Member

Also make sure you're using the correct FFI version (I'd just checkout a clean copy).

@frystal
Copy link
Author

frystal commented Jun 28, 2024

It looks like you are running a dirty build @frystal. Have you changed any code?

No, I think the dirty tag was added because I included the config.toml file in the base folder for building the Docker image.

Also make sure you're using the correct FFI version (I'd just checkout a clean copy).

I have rebuilt the 'lotus-local-net' with the latest tag, but I still have the same issues. Here is the new goroutine dump.

go-routines_new.txt

@TippyFlitsUK
Copy link
Contributor

Can you test building and running Lotus outside of a Docker container?

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
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@Stebalien @TippyFlitsUK @frystal