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.

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

how to delete ststus log message and sector remove? #8376

Closed
9 of 18 tasks
ssim-itaz opened this issue Mar 26, 2022 · 3 comments
Closed
9 of 18 tasks

how to delete ststus log message and sector remove? #8376

ssim-itaz opened this issue Mar 26, 2022 · 3 comments
Assignees
Labels

Comments

@ssim-itaz
Copy link

Checklist

  • This is not a security-related bug/issue. If it is, please follow please follow the security policy.
  • This is not a question or a support request. If you have any lotus related questions, please ask in the lotus forum.
  • This is not a new feature request. If it is, please file a feature request instead.
  • This is not an enhancement request. If it is, please file a improvement suggestion instead.
  • 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, or 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 miner - mining and block production
  • lotus miner/worker - sealing
  • lotus miner - proving(WindowPoSt)
  • lotus miner/market - storage deal
  • lotus miner/market - retrieval deal
  • lotus miner/market - data transfer
  • lotus client
  • lotus JSON-RPC API
  • lotus message management (mpool)
  • Other

Lotus Version

Daemon:  1.15.2-dev+mainnet+git.3c1edca90+api1.5.0
Local: lotus-miner version 1.15.2-dev+mainnet+git.3c1edca90

Describe the Bug

kvlog file size increases rapidly.

Logging Information

6638.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorRemoved]	{"User":{}}
6639.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorTerminate]	{"User":{}}
6640.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removed"}}
6641.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6642.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6643.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removing"}}
6644.	2022-03-26 22:17:36 +0900 KST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}} {User:{}} {User:{State:Removed}} {User:{State:Empty}} {User:{State:Empty}} {User:{State:Removing}}]
6645.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorRemoved]	{"User":{}}
6646.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorTerminate]	{"User":{}}
6647.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removed"}}
6648.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6649.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6650.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removing"}}
6651.	2022-03-26 22:17:36 +0900 KST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}} {User:{}} {User:{State:Removed}} {User:{State:Empty}} {User:{State:Empty}} {User:{State:Removing}}]
6652.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorRemoved]	{"User":{}}
6653.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorTerminate]	{"User":{}}
6654.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removed"}}
6655.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6656.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6657.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removing"}}
6658.	2022-03-26 22:17:36 +0900 KST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}} {User:{}} {User:{State:Removed}} {User:{State:Empty}} {User:{State:Empty}} {User:{State:Removing}}]
6659.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorRemoved]	{"User":{}}
6660.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorTerminate]	{"User":{}}
6661.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removed"}}
6662.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6663.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6664.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removing"}}
6665.	2022-03-26 22:17:36 +0900 KST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}} {User:{}} {User:{State:Removed}} {User:{State:Empty}} {User:{State:Empty}} {User:{State:Removing}}]
6666.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorRemoved]	{"User":{}}
6667.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorTerminate]	{"User":{}}
6668.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removed"}}
6669.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6670.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6671.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removing"}}
6672.	2022-03-26 22:17:36 +0900 KST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}} {User:{}} {User:{State:Removed}} {User:{State:Empty}} {User:{State:Empty}} {User:{State:Removing}}]
6673.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorRemoved]	{"User":{}}
6674.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorTerminate]	{"User":{}}
6675.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removed"}}
6676.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6677.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6678.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removing"}}
6679.	2022-03-26 22:17:36 +0900 KST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}} {User:{}} {User:{State:Removed}} {User:{State:Empty}} {User:{State:Empty}} {User:{State:Removing}}]
6680.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorRemoved]	{"User":{}}
6681.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorTerminate]	{"User":{}}
6682.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removed"}}
6683.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6684.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6685.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removing"}}
6686.	2022-03-26 22:17:36 +0900 KST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}} {User:{}} {User:{State:Removed}} {User:{State:Empty}} {User:{State:Empty}} {User:{State:Removing}}]
6687.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorRemoved]	{"User":{}}
6688.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorTerminate]	{"User":{}}
6689.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removed"}}
6690.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6691.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6692.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removing"}}
6693.	2022-03-26 22:17:36 +0900 KST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}} {User:{}} {User:{State:Removed}} {User:{State:Empty}} {User:{State:Empty}} {User:{State:Removing}}]
6694.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorRemoved]	{"User":{}}
6695.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorTerminate]	{"User":{}}
6696.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removed"}}
6697.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6698.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6699.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removing"}}
6700.	2022-03-26 22:17:36 +0900 KST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}} {User:{}} {User:{State:Removed}} {User:{State:Empty}} {User:{State:Empty}} {User:{State:Removing}}]
6701.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorRemoved]	{"User":{}}
6702.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorTerminate]	{"User":{}}
6703.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removed"}}
6704.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6705.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6706.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removing"}}
6707.	2022-03-26 22:17:36 +0900 KST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}} {User:{}} {User:{State:Removed}} {User:{State:Empty}} {User:{State:Empty}} {User:{State:Removing}}]
6708.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorRemoved]	{"User":{}}
6709.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorTerminate]	{"User":{}}
6710.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removed"}}
6711.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6712.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6713.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removing"}}
6714.	2022-03-26 22:17:36 +0900 KST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}} {User:{}} {User:{State:Removed}} {User:{State:Empty}} {User:{State:Empty}} {User:{State:Removing}}]
6715.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorRemoved]	{"User":{}}
6716.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorTerminate]	{"User":{}}
6717.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removed"}}
6718.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6719.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6720.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removing"}}
6721.	2022-03-26 22:17:36 +0900 KST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}} {User:{}} {User:{State:Removed}} {User:{State:Empty}} {User:{State:Empty}} {User:{State:Removing}}]
6722.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorRemoved]	{"User":{}}
6723.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorTerminate]	{"User":{}}
6724.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removed"}}
6725.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6726.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6727.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removing"}}
6728.	2022-03-26 22:17:36 +0900 KST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}} {User:{}} {User:{State:Removed}} {User:{State:Empty}} {User:{State:Empty}} {User:{State:Removing}}]
6729.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorRemoved]	{"User":{}}
6730.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorTerminate]	{"User":{}}
6731.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removed"}}
6732.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6733.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6734.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removing"}}
6735.	2022-03-26 22:17:36 +0900 KST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}} {User:{}} {User:{State:Removed}} {User:{State:Empty}} {User:{State:Empty}} {User:{State:Removing}}]
6736.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorRemoved]	{"User":{}}
6737.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorTerminate]	{"User":{}}
6738.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removed"}}
6739.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6740.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6741.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removing"}}
6742.	2022-03-26 22:17:36 +0900 KST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}} {User:{}} {User:{State:Removed}} {User:{State:Empty}} {User:{State:Empty}} {User:{State:Removing}}]
6743.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorRemoved]	{"User":{}}
6744.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorTerminate]	{"User":{}}
6745.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removed"}}
6746.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6747.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Empty"}}
6748.	2022-03-26 22:17:36 +0900 KST:	[event;sealing.SectorForceState]	{"User":{"State":"Removing"}}
6749.	2022-03-26 22:17:36 +0900 KST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}} {User:{}} {User:{State:Removed}} {User:{State:Empty}} {User:{State:Empty}} {User:{State:Removing}}]

Repo Steps

  1. lotus-miner proving faults
  2. lotus-miner sectors terminate --really-do-it xxxxx
  3. lotus-miner sectors remove --really-do-it xxxx
@Reiers Reiers self-assigned this Mar 28, 2022
@Reiers
Copy link

Reiers commented Mar 29, 2022

Hi @ssim-itaz

Thanks for the report. I have added labels and will assign it to the right team for analysis.
I reproduced the issue on latest tag v1.15.1-rc3.

  • lotus-miner sealing abort ID
  • lotus-miner sectors remove --really do-it sectornum

That will result in these messages below in the miner log, over and over again:

2022-03-29T16:21:42.049+0200	WARN	sectors	storage-sealing/fsm.go:330	truncating sector log	{"sector": "49988"}
2022-03-29T16:21:50.714+0200	WARN	sectors	storage-sealing/fsm.go:330	truncating sector log	{"sector": "49989"}
2022-03-29T16:22:00.668+0200	WARN	sectors	storage-sealing/fsm.go:330	truncating sector log	{"sector": "49988"}

and kvlog(miner path), will fill up fast - in less than 6 hours it was at 1.9TB in size.

Sector log for the ones I removed, it will just loop the log:

SectorID:	49988
Status:		Removed
CIDcommD:	baga6ea4seaqhynjykigpbjjash5wzdtyvvmuklwhlfgjj7poqjim5khyilposlq
CIDcommR:	bagboea4b5abca2rplftrrzipbi7ojay6nfayartamqxsljrojdawc2elaftx362g
Ticket:		eecd0fc5978e4ce7f34888ab08186c8231ea79d9a904965bf79525c82175c0cf
TicketH:	1672767
Seed:		fe0797a4f31957304bec82cc5d548616ef407caf7498e2528fa76ca1acd0b0f7
SeedH:		1674383
Precommit:	bafy2bzaceduxgjzq44jsy5uvzbfexp72ji4ajy7h66pgcvhnox6f3nkzcrcne
Commit:		<nil>
Deals:		[5004008]
Retries:	0
--------
Event Log:
0.	2022-03-29 03:09:59 +0200 CEST:	[event;sealing.SectorStart]	{"User":{"ID":49988,"SectorType":8}}
1.	2022-03-29 03:09:59 +0200 CEST:	[event;sealing.SectorAddPiece]	{"User":{}}
2.	2022-03-29 03:13:45 +0200 CEST:	[event;sealing.SectorPieceAdded]	{"User":{"NewPieces":[{"Piece":{"Size":34359738368,"PieceCID":{"/":"baga6ea4seaqhynjykigpbjjash5wzdtyvvmuklwhlfgjj7poqjim5khyilposlq"}},"DealInfo":{"PublishCid":{"/":"bafy2bzaceddmmaisxvfy7xeg4cirgpdz3tlkuge25nj3u6p467jwnj5ffrktu"},"DealID":5004008,"DealProposal":{"PieceCID":{"/":"baga6ea4seaqhynjykigpbjjash5wzdtyvvmuklwhlfgjj7poqjim5khyilposlq"},"PieceSize":34359738368,"VerifiedDeal":true,"Client":"f17ia7m5mvizrdug3sqtevqw3tifiqvxqr3kdaeuq","Provider":"f022352","Label":"QmXBdKZhzyVDvziZnFisrHWin3atDCRxzrjb9mF5obqWNh","StartEpoch":1688014,"EndEpoch":3135910,"StoragePricePerEpoch":"0","ProviderCollateral":"5674702903693411","ClientCollateral":"0"},"DealSchedule":{"StartEpoch":1688014,"EndEpoch":3135910},"KeepUnsealed":true}}]}}
3.	2022-03-29 03:13:45 +0200 CEST:	[event;sealing.SectorStartPacking]	{"User":{}}
4.	2022-03-29 03:13:45 +0200 CEST:	[event;sealing.SectorPacked]	{"User":{"FillerPieces":null}}
5.	2022-03-29 03:13:45 +0200 CEST:	[event;sealing.SectorTicket]	{"User":{"TicketValue":"7s0PxZeOTOfzSIirCBhsgjHqedmpBJZb95UlyCF1wM8=","TicketEpoch":1672767}}
6.	2022-03-29 07:18:48 +0200 CEST:	[event;sealing.SectorPreCommit1]	{"User":{"PreCommit1Out":"eyJfbG90dXNfU2VhbFJhbmRvbW5lc3MiOiI3czBQeFplT1RPZnpTSWlyQ0Joc2dqSHFlZG1wQkpaYjk1VWx5Q0Yxd004PSIsImNvbW1fZCI6WzEyNCw1Myw1Niw4MiwxMiwyNDAsMTY1LDMyLDE0NSwyNTEsMTA4LDE0MiwxMjAsMTczLDg5LDY5LDQ2LDE5OSw4OSw3NiwxNDgsMjUzLDIzOCwxMzAsODAsMjA2LDE2OCwyNDgsNjYsMjIyLDIzMyw0Nl0sImNvbmZpZyI6eyJpZCI6InRyZWUtZCIsInBhdGgiOiIvbG90dXNfd29ya19yYWlkL2NhY2hlL3MtdDAyMjM1Mi00OTk4OCIsInJvd3NfdG9fZGlzY2FyZCI6Nywic2l6ZSI6MjE0NzQ4MzY0N30sImxhYmVscyI6eyJTdGFja2VkRHJnMzJHaUJWMSI6eyJfaCI6bnVsbCwibGFiZWxzIjpbeyJpZCI6ImxheWVyLTEiLCJwYXRoIjoiL2xvdHVzX3dvcmtfcmFpZC9jYWNoZS9zLXQwMjIzNTItNDk5ODgiLCJyb3dzX3RvX2Rpc2NhcmQiOjcsInNpemUiOjEwNzM3NDE4MjR9LHsiaWQiOiJsYXllci0yIiwicGF0aCI6Ii9sb3R1c193b3JrX3JhaWQvY2FjaGUvcy10MDIyMzUyLTQ5OTg4Iiwicm93c190b19kaXNjYXJkIjo3LCJzaXplIjoxMDczNzQxODI0fSx7ImlkIjoibGF5ZXItMyIsInBhdGgiOiIvbG90dXNfd29ya19yYWlkL2NhY2hlL3MtdDAyMjM1Mi00OTk4OCIsInJvd3NfdG9fZGlzY2FyZCI6Nywic2l6ZSI6MTA3Mzc0MTgyNH0seyJpZCI6ImxheWVyLTQiLCJwYXRoIjoiL2xvdHVzX3dvcmtfcmFpZC9jYWNoZS9zLXQwMjIzNTItNDk5ODgiLCJyb3dzX3RvX2Rpc2NhcmQiOjcsInNpemUiOjEwNzM3NDE4MjR9LHsiaWQiOiJsYXllci01IiwicGF0aCI6Ii9sb3R1c193b3JrX3JhaWQvY2FjaGUvcy10MDIyMzUyLTQ5OTg4Iiwicm93c190b19kaXNjYXJkIjo3LCJzaXplIjoxMDczNzQxODI0fSx7ImlkIjoibGF5ZXItNiIsInBhdGgiOiIvbG90dXNfd29ya19yYWlkL2NhY2hlL3MtdDAyMjM1Mi00OTk4OCIsInJvd3NfdG9fZGlzY2FyZCI6Nywic2l6ZSI6MTA3Mzc0MTgyNH0seyJpZCI6ImxheWVyLTciLCJwYXRoIjoiL2xvdHVzX3dvcmtfcmFpZC9jYWNoZS9zLXQwMjIzNTItNDk5ODgiLCJyb3dzX3RvX2Rpc2NhcmQiOjcsInNpemUiOjEwNzM3NDE4MjR9LHsiaWQiOiJsYXllci04IiwicGF0aCI6Ii9sb3R1c193b3JrX3JhaWQvY2FjaGUvcy10MDIyMzUyLTQ5OTg4Iiwicm93c190b19kaXNjYXJkIjo3LCJzaXplIjoxMDczNzQxODI0fSx7ImlkIjoibGF5ZXItOSIsInBhdGgiOiIvbG90dXNfd29ya19yYWlkL2NhY2hlL3MtdDAyMjM1Mi00OTk4OCIsInJvd3NfdG9fZGlzY2FyZCI6Nywic2l6ZSI6MTA3Mzc0MTgyNH0seyJpZCI6ImxheWVyLTEwIiwicGF0aCI6Ii9sb3R1c193b3JrX3JhaWQvY2FjaGUvcy10MDIyMzUyLTQ5OTg4Iiwicm93c190b19kaXNjYXJkIjo3LCJzaXplIjoxMDczNzQxODI0fSx7ImlkIjoibGF5ZXItMTEiLCJwYXRoIjoiL2xvdHVzX3dvcmtfcmFpZC9jYWNoZS9zLXQwMjIzNTItNDk5ODgiLCJyb3dzX3RvX2Rpc2NhcmQiOjcsInNpemUiOjEwNzM3NDE4MjR9XX19LCJyZWdpc3RlcmVkX3Byb29mIjoiU3RhY2tlZERyZzMyR2lCVjFfMSJ9"}}
7.	2022-03-29 07:56:17 +0200 CEST:	[event;sealing.SectorPreCommit2]	{"User":{"Sealed":{"/":"bagboea4b5abca2rplftrrzipbi7ojay6nfayartamqxsljrojdawc2elaftx362g"},"Unsealed":{"/":"baga6ea4seaqhynjykigpbjjash5wzdtyvvmuklwhlfgjj7poqjim5khyilposlq"}}}
8.	2022-03-29 07:56:17 +0200 CEST:	[event;sealing.SectorPreCommitted]	{"User":{"Message":{"/":"bafy2bzaceduxgjzq44jsy5uvzbfexp72ji4ajy7h66pgcvhnox6f3nkzcrcne"},"PreCommitDeposit":"124818564689449034","PreCommitInfo":{"SealProof":8,"SectorNumber":49988,"SealedCID":{"/":"bagboea4b5abca2rplftrrzipbi7ojay6nfayartamqxsljrojdawc2elaftx362g"},"SealRandEpoch":1672767,"DealIDs":[5004008],"Expiration":3135910,"ReplaceCapacity":false,"ReplaceSectorDeadline":0,"ReplaceSectorPartition":0,"ReplaceSectorNumber":0}}}
9.	2022-03-29 07:59:30 +0200 CEST:	[event;sealing.SectorPreCommitLanded]	{"User":{"TipSet":"AXGg5AIg0oKDuHPLtP1IIs+bPTs9hdxA40EYGOiz811b6Ap5TQMBcaDkAiBk7ZCkkmawZ8CoHjQwF/2vaJXCOwinL/CokEpMDHwngg=="}}
10.	2022-03-29 09:14:30 +0200 CEST:	[event;sealing.SectorSeedReady]	{"User":{"SeedValue":"/geXpPMZVzBL7ILMXVSGFu9AfK90mOJSj6dsoazQsPc=","SeedEpoch":1674383}}
11.	2022-03-29 09:19:16 +0200 CEST:	[event;sealing.SectorComputeProofFailed]	{"User":{}}
	computing seal proof failed(2): storage call error 0: %!w(Rust panic: Once instance has previously been poisoned [Hostname: homer-intel-worker])
12.	2022-03-29 09:20:16 +0200 CEST:	[event;sealing.SectorRetryComputeProof]	{"User":{}}
13.	2022-03-29 09:25:01 +0200 CEST:	[event;sealing.SectorComputeProofFailed]	{"User":{}}
	computing seal proof failed(2): storage call error 0: %!w(Rust panic: Once instance has previously been poisoned [Hostname: homer-intel-worker])
14.	2022-03-29 09:26:01 +0200 CEST:	[event;sealing.SectorRetryComputeProof]	{"User":{}}
15.	2022-03-29 09:34:36 +0200 CEST:	[event;sealing.SectorComputeProofFailed]	{"User":{}}
	computing seal proof failed(2): storage call error 0: %!w(Rust panic: Once instance has previously been poisoned [Hostname: homer-intel-worker])
16.	2022-03-29 09:35:36 +0200 CEST:	[event;sealing.SectorSealPreCommit1Failed]	{"User":{}}
	consecutive compute fails
17.	2022-03-29 09:36:36 +0200 CEST:	[event;sealing.SectorRetrySealPreCommit1]	{"User":{}}
18.	2022-03-29 14:09:01 +0200 CEST:	[event;sealing.SectorPreCommit1]	{"User":{"PreCommit1Out":"eyJfbG90dXNfU2VhbFJhbmRvbW5lc3MiOiI3czBQeFplT1RPZnpTSWlyQ0Joc2dqSHFlZG1wQkpaYjk1VWx5Q0Yxd004PSIsImNvbW1fZCI6WzEyNCw1Myw1Niw4MiwxMiwyNDAsMTY1LDMyLDE0NSwyNTEsMTA4LDE0MiwxMjAsMTczLDg5LDY5LDQ2LDE5OSw4OSw3NiwxNDgsMjUzLDIzOCwxMzAsODAsMjA2LDE2OCwyNDgsNjYsMjIyLDIzMyw0Nl0sImNvbmZpZyI6eyJpZCI6InRyZWUtZCIsInBhdGgiOiIvbW50L1BjMVN0b3JlL2NhY2hlL3MtdDAyMjM1Mi00OTk4OCIsInJvd3NfdG9fZGlzY2FyZCI6Nywic2l6ZSI6MjE0NzQ4MzY0N30sImxhYmVscyI6eyJTdGFja2VkRHJnMzJHaUJWMSI6eyJfaCI6bnVsbCwibGFiZWxzIjpbeyJpZCI6ImxheWVyLTEiLCJwYXRoIjoiL21udC9QYzFTdG9yZS9jYWNoZS9zLXQwMjIzNTItNDk5ODgiLCJyb3dzX3RvX2Rpc2NhcmQiOjcsInNpemUiOjEwNzM3NDE4MjR9LHsiaWQiOiJsYXllci0yIiwicGF0aCI6Ii9tbnQvUGMxU3RvcmUvY2FjaGUvcy10MDIyMzUyLTQ5OTg4Iiwicm93c190b19kaXNjYXJkIjo3LCJzaXplIjoxMDczNzQxODI0fSx7ImlkIjoibGF5ZXItMyIsInBhdGgiOiIvbW50L1BjMVN0b3JlL2NhY2hlL3MtdDAyMjM1Mi00OTk4OCIsInJvd3NfdG9fZGlzY2FyZCI6Nywic2l6ZSI6MTA3Mzc0MTgyNH0seyJpZCI6ImxheWVyLTQiLCJwYXRoIjoiL21udC9QYzFTdG9yZS9jYWNoZS9zLXQwMjIzNTItNDk5ODgiLCJyb3dzX3RvX2Rpc2NhcmQiOjcsInNpemUiOjEwNzM3NDE4MjR9LHsiaWQiOiJsYXllci01IiwicGF0aCI6Ii9tbnQvUGMxU3RvcmUvY2FjaGUvcy10MDIyMzUyLTQ5OTg4Iiwicm93c190b19kaXNjYXJkIjo3LCJzaXplIjoxMDczNzQxODI0fSx7ImlkIjoibGF5ZXItNiIsInBhdGgiOiIvbW50L1BjMVN0b3JlL2NhY2hlL3MtdDAyMjM1Mi00OTk4OCIsInJvd3NfdG9fZGlzY2FyZCI6Nywic2l6ZSI6MTA3Mzc0MTgyNH0seyJpZCI6ImxheWVyLTciLCJwYXRoIjoiL21udC9QYzFTdG9yZS9jYWNoZS9zLXQwMjIzNTItNDk5ODgiLCJyb3dzX3RvX2Rpc2NhcmQiOjcsInNpemUiOjEwNzM3NDE4MjR9LHsiaWQiOiJsYXllci04IiwicGF0aCI6Ii9tbnQvUGMxU3RvcmUvY2FjaGUvcy10MDIyMzUyLTQ5OTg4Iiwicm93c190b19kaXNjYXJkIjo3LCJzaXplIjoxMDczNzQxODI0fSx7ImlkIjoibGF5ZXItOSIsInBhdGgiOiIvbW50L1BjMVN0b3JlL2NhY2hlL3MtdDAyMjM1Mi00OTk4OCIsInJvd3NfdG9fZGlzY2FyZCI6Nywic2l6ZSI6MTA3Mzc0MTgyNH0seyJpZCI6ImxheWVyLTEwIiwicGF0aCI6Ii9tbnQvUGMxU3RvcmUvY2FjaGUvcy10MDIyMzUyLTQ5OTg4Iiwicm93c190b19kaXNjYXJkIjo3LCJzaXplIjoxMDczNzQxODI0fSx7ImlkIjoibGF5ZXItMTEiLCJwYXRoIjoiL21udC9QYzFTdG9yZS9jYWNoZS9zLXQwMjIzNTItNDk5ODgiLCJyb3dzX3RvX2Rpc2NhcmQiOjcsInNpemUiOjEwNzM3NDE4MjR9XX19LCJyZWdpc3RlcmVkX3Byb29mIjoiU3RhY2tlZERyZzMyR2lCVjFfMSJ9"}}
19.	2022-03-29 14:34:13 +0200 CEST:	[event;sealing.SectorPreCommit2]	{"User":{"Sealed":{"/":"bagboea4b5abca2rplftrrzipbi7ojay6nfayartamqxsljrojdawc2elaftx362g"},"Unsealed":{"/":"baga6ea4seaqhynjykigpbjjash5wzdtyvvmuklwhlfgjj7poqjim5khyilposlq"}}}
20.	2022-03-29 14:34:13 +0200 CEST:	[event;sealing.SectorPreCommitLanded]	{"User":{"TipSet":"AXGg5AIgAROMMja92+U+Gps4+clDyCzFaiI/Lx+xQu+BLthIaIEBcaDkAiAJN553034CNUSRWsHnEXxnokL69bdHncyOjKTAXGad2gFxoOQCIG94jaZl9L9HJtSp9AmVSuGnyluS+8KUey4Ug1zPGcw7"}}
21.	2022-03-29 14:34:13 +0200 CEST:	[event;sealing.SectorSeedReady]	{"User":{"SeedValue":"/geXpPMZVzBL7ILMXVSGFu9AfK90mOJSj6dsoazQsPc=","SeedEpoch":1674383}}
22.	2022-03-29 14:53:48 +0200 CEST:	[event;sealing.SectorComputeProofFailed]	{"User":{}}
	computing seal proof failed(2): storage call error 0: %!w(Rust panic: Once instance has previously been poisoned [Hostname: homer-intel-worker])
23.	2022-03-29 14:54:48 +0200 CEST:	[event;sealing.SectorRetryComputeProof]	{"User":{}}
24.	2022-03-29 15:08:23 +0200 CEST:	[event;sealing.SectorComputeProofFailed]	{"User":{}}
	computing seal proof failed(2): storage call error 0: %!w(Rust panic: Once instance has previously been poisoned [Hostname: homer-intel-worker])
25.	2022-03-29 15:09:23 +0200 CEST:	[event;sealing.SectorRetryComputeProof]	{"User":{}}
26.	2022-03-29 15:27:18 +0200 CEST:	[event;sealing.SectorComputeProofFailed]	{"User":{}}
	computing seal proof failed(2): storage call error 0: %!w(Rust panic: Once instance has previously been poisoned [Hostname: homer-intel-worker])
27.	2022-03-29 15:28:18 +0200 CEST:	[event;sealing.SectorSealPreCommit1Failed]	{"User":{}}
	consecutive compute fails
28.	2022-03-29 15:29:18 +0200 CEST:	[event;sealing.SectorRetrySealPreCommit1]	{"User":{}}
29.	2022-03-29 16:19:26 +0200 CEST:	[event;sealing.SectorSealPreCommit1Failed]	{"User":{}}
	seal pre commit(1) failed: storage call error 0: task aborted
30.	2022-03-29 16:20:26 +0200 CEST:	[event;sealing.SectorRemove]	{"User":{}}
31.	2022-03-29 16:20:26 +0200 CEST:	[event;sealing.SectorRetrySealPreCommit1]	{"User":{}}
32.	2022-03-29 16:20:26 +0200 CEST:	[event;sealing.SectorRetrySealPreCommit1]	{"User":{}}
33.	2022-03-29 16:20:26 +0200 CEST:	[event;sealing.SectorRemoved]	{"User":{}}
34.	2022-03-29 16:20:26 +0200 CEST:	[event;sealing.SectorRemoved]	{"User":{}}
35.	2022-03-29 16:20:26 +0200 CEST:	[event;sealing.SectorRemoved]	{"User":{}}
36.	2022-03-29 16:20:26 +0200 CEST:	[error;<nil>]	state machine error: %!s(<nil>)
37.	2022-03-29 16:20:26 +0200 CEST:	[event;sealing.SectorRemoved]	{"User":{}}
38.	2022-03-29 16:20:26 +0200 CEST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}}]
39.	2022-03-29 16:20:26 +0200 CEST:	[event;sealing.SectorRemoved]	{"User":{}}
40.	2022-03-29 16:20:26 +0200 CEST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}}]
41.	2022-03-29 16:20:26 +0200 CEST:	[event;sealing.SectorRemoved]	{"User":{}}
42.	2022-03-29 16:20:26 +0200 CEST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}}]
43.	2022-03-29 16:20:26 +0200 CEST:	[event;sealing.SectorRemoved]	{"User":{}}
44.	2022-03-29 16:20:26 +0200 CEST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}}]
45.	2022-03-29 16:20:26 +0200 CEST:	[event;sealing.SectorRemoved]	{"User":{}}
46.	2022-03-29 16:20:26 +0200 CEST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}}]
47.	2022-03-29 16:20:26 +0200 CEST:	[event;sealing.SectorRemoved]	{"User":{}}
------------------
6531.	2022-03-29 16:22:11 +0200 CEST:	[event;sealing.SectorRemoved]	{"User":{}}
6532.	2022-03-29 16:22:11 +0200 CEST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}}]
6533.	2022-03-29 16:22:11 +0200 CEST:	[event;sealing.SectorRemoved]	{"User":{}}
6534.	2022-03-29 16:22:11 +0200 CEST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}}]
6535.	2022-03-29 16:22:11 +0200 CEST:	[event;sealing.SectorRemoved]	{"User":{}}
6536.	2022-03-29 16:22:11 +0200 CEST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}}]
6537.	2022-03-29 16:22:11 +0200 CEST:	[event;sealing.SectorRemoved]	{"User":{}}
6538.	2022-03-29 16:22:11 +0200 CEST:	[error;*xerrors.wrapError]	state machine error: running planner for state Removed failed: didn't expect any events in state Removed, got [{User:{}}]
6539.	2022-03-29 16:25:25 +0200 CEST:	[error;<nil>]	state machine error: %!s(<nil>

I did the repro on a sector that was in Precommit state, and Commit State - both sectors are on a loop, until you restart the miner process.

This can be big issue if you have a sector stuck in a state from the early days.

@magik6k
Copy link
Contributor

magik6k commented Mar 31, 2022

Should be fixed with #8386

@rjan90
Copy link
Contributor

rjan90 commented May 11, 2022

Closing as the dead loop when removing the sector has been fixed.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

4 participants