From 41e0e74dec06743e69dbd06afdad8d3d1529823d Mon Sep 17 00:00:00 2001 From: CryptoWhizzard <36404435+cryptowhizzard@users.noreply.github.com> Date: Wed, 22 May 2024 11:40:57 +0200 Subject: [PATCH] Fix panic when recovering broken sector. Fixes : 2024-05-22T10:00:57.990+0200 DEBUG boostd/recover.go:698 successfully processed sector {"sector": "24242", "took": "2m10.444991835s", "deals": [54737806]} 2024-05-22T10:00:57.990+0200 DEBUG boostd/recover.go:685 processing sector {"sector": "24245", "deals": [54737803]} 2024-05-22T10:00:57.991+0200 WARN boostd/recover.go:714 deal present in sector, but not in market actor state, so probably expired {"sector": "24245", "deal": 54737803, "err": "deal 54737803 not found - deal may not have completed sealing before deal proposal start epoch, or deal may have been slashed"} 2024-05-22T10:00:57.991+0200 DEBUG boostd/recover.go:698 successfully processed sector {"sector": "24245", "took": "1.1293ms", "deals": [54737803]} 2024-05-22T10:00:57.991+0200 DEBUG boostd/recover.go:685 processing sector {"sector": "24246", "deals": [54737805]} 2024-05-22T10:00:58.005+0200 DEBUG boostd/recover.go:544 processing piece {"sector": "24246", "piececid": "baga6ea4seaqofw6a4qv6toolne2rhobfdblq7mss5cwhffjaa47dedg3wxcs6pq", "piecesize": 34359738368, "offset": 0, "label": "bafybeifo6wh22ydwxf2eio4a6larmd4hj7kl2vz6esuwvymcu5gxyh4nmq"} 2024-05-22T10:00:58.135+0200 ERROR boostd/recover.go:507 isUnsealed(24246, 0, 34091302912) returned false, but `storage find` returns an unsealed copy; most probably unsealed copy is full of 0x00 and is corrupted (confirm with xxd) {"sector": "24246"} 2024-05-22T10:00:58.136+0200 DEBUG boostd/recover.go:586 processed piece {"took": "130.805405ms", "sector": "24246", "piececid": "baga6ea4seaqofw6a4qv6toolne2rhobfdblq7mss5cwhffjaa47dedg3wxcs6pq", "piecesize": 34359738368, "offset": 0, "label": "bafybeifo6wh22ydwxf2eio4a6larmd4hj7kl2vz6esuwvymcu5gxyh4nmq"} 2024-05-22T10:00:58.136+0200 DEBUG boostd/recover.go:698 successfully processed sector {"sector": "24246", "took": "144.511317ms", "deals": [54737805]} panic: runtime error: invalid memory address or nil pointer dereference [signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x2aad42f] goroutine 74 [running]: main.processPiece({0x7c5d8e8, 0xc00035f900}, 0x5eb6, 0x3433b8d, {{0xc008743770?, 0x0?}}, 0x800000000, 0x0, {0xc000794180, 0x3b}) /root/build/boost/cmd/boostd/recover.go:593 +0x6af main.processSector({0x7c5d8e8, 0xc00035f900}, {{0xc0001509a0?, 0xc0001151a0?}}, 0xc001d3b710) /root/build/boost/cmd/boostd/recover.go:737 +0x472 main.action(0x0?) /root/build/boost/cmd/boostd/recover.go:270 +0xfdf main.glob..func23.1() /root/build/boost/cmd/boostd/recover.go:130 +0x25 created by main.glob..func23 in goroutine 1 /root/build/boost/cmd/boostd/recover.go:129 +0xf9 --- cmd/boostd/recover.go | 438 ++++++++++++++++++++++-------------------- 1 file changed, 231 insertions(+), 207 deletions(-) diff --git a/cmd/boostd/recover.go b/cmd/boostd/recover.go index 094d77483..ef363eef7 100644 --- a/cmd/boostd/recover.go +++ b/cmd/boostd/recover.go @@ -541,216 +541,240 @@ func safeUnsealSector(ctx context.Context, sectorid abi.SectorNumber, offset abi } func processPiece(ctx context.Context, sectorid abi.SectorNumber, chainDealID abi.DealID, piececid cid.Cid, piecesize abi.PaddedPieceSize, offset abi.UnpaddedPieceSize, l string) error { - logger.Debugw("processing piece", "sector", sectorid, "piececid", piececid, "piecesize", piecesize, "offset", offset, "label", l) - - cdi := uint64(chainDealID) - sid := uint64(sectorid) - - dr.Sectors[sid].Deals[cdi] = &PieceStatus{ - PieceCID: piececid, - PieceSize: piecesize, - PieceOffset: offset, - IsUnsealed: false, - } - - if dr.HaveBoostDealsAndPieceStore { // sanity check on piece store / piece info vs chain data and infered piece size / offset data - pi, err := ps.GetPieceInfo(piececid) - if err != nil { - logger.Errorw("cant get piece info from piece store", "piececid", piececid, "sector", sid, "err", err) - } else { - var found bool - for _, di := range pi.Deals { - if di.DealID == chainDealID { - found = true - - if di.SectorID != sectorid { - logger.Errorw("sector mismatch", "sector", sid, "piececid", piececid, "chain-deal-id", chainDealID, "got", di.SectorID) - } - if di.Offset != offset.Padded() { - logger.Errorw("offset mismatch", "sector", sid, "piececid", piececid, "chain-deal-id", chainDealID, "calculated", offset.Padded(), "got from ps", di.Offset) - } - if di.Length != piecesize { - logger.Errorw("length/piece size mismatch", "sector", sid, "piececid", piececid, "chain-deal-id", chainDealID, "expected", piecesize, "got from ps", di.Length) - } - } - } - if !found { - logger.Errorw("chain deal not found in piece info", "sector", sid, "piececid", piececid, "chain-deal-id", chainDealID, "pi", spew.Sdump(pi)) - } - } - } - - defer func(start time.Time) { - took := time.Since(start) - dr.Sectors[sid].Deals[cdi].ProcessingTook = took - logger.Debugw("processed piece", "took", took, "sector", sectorid, "piececid", piececid, "piecesize", piecesize, "offset", offset, "label", l) - }(time.Now()) - - reader, isUnsealed, err := safeUnsealSector(ctx, sectorid, offset, piecesize) - if err != nil { - return err - } - defer reader.Close() - if !isUnsealed { - return fmt.Errorf("sector %d is not unsealed", sid) - } - - dr.Sectors[sid].Deals[cdi].IsUnsealed = true - dr.Sectors[sid].Deals[cdi].GotDataReader = true - - if !ignoreLID { // populate LID - var shouldGenerateNewDeal bool - - var di model.DealInfo - - if dr.HaveBoostDealsAndPieceStore { // successfully loaded boost sqlite db and piece store => try to infer dealinfo - // find the deal corresponding to the deal info's DealID - proposalCid, okLegacy := dr.PropCidByChainDealID[chainDealID] - uuid, okBoost := dr.BoostDeals[chainDealID] - - if !okLegacy && !okBoost { - logger.Errorw("cant find boost deal or legacy deal", - "piececid", piececid, "chain-deal-id", chainDealID, "err", err) - - shouldGenerateNewDeal = true - } else { - isLegacy := false - if uuid == "" { - uuid = proposalCid.String() - isLegacy = true - } - - di = model.DealInfo{ - DealUuid: uuid, - IsLegacy: isLegacy, - ChainDealID: chainDealID, - MinerAddr: maddr, - SectorID: sectorid, - PieceOffset: offset.Padded(), - PieceLength: piecesize, - } - } - } - - if !dr.HaveBoostDealsAndPieceStore || shouldGenerateNewDeal { // missing boost sqlite db and piece store, so generate new dealinfo - // in the future we could also regenerate boost db sqlite?? - - di = model.DealInfo{ - DealUuid: uuid.NewString(), - IsLegacy: false, - ChainDealID: chainDealID, - MinerAddr: maddr, - SectorID: sectorid, - PieceOffset: offset.Padded(), - PieceLength: piecesize, - } - } - - timeAddIndex := time.Now() - - err = pd.AddDealForPiece(ctx, piececid, di) - if err != nil { - logger.Errorw("cant add deal info for piece", "piececid", piececid, "chain-deal-id", chainDealID, "err", err) - - return err - } - - logger.Infow("added index", "took", time.Since(timeAddIndex), "sector", di.SectorID, "piececid", piececid, "chain-deal-id", di.ChainDealID, "uuid", di.DealUuid) - } - - if !ignoreCommp { // commp over data reader - w := &writer.Writer{} - _, err = io.CopyBuffer(w, reader, make([]byte, writer.CommPBuf)) - if err != nil { - return fmt.Errorf("copy into commp writer: %w", err) - } - - commp, err := w.Sum() - if err != nil { - return fmt.Errorf("computing commP failed: %w", err) - } - - encoder := cidenc.Encoder{Base: multibase.MustNewEncoder(multibase.Base32)} - _ = encoder - - if !commp.PieceCID.Equals(piececid) { - return fmt.Errorf("calculated commp doesnt match on-chain data, expected %s, got %s", piececid, commp.PieceCID) - } - } - - return nil + logger.Debugw("processing piece", "sector", sectorid, "piececid", piececid, "piecesize", piecesize, "offset", offset, "label", l) + + cdi := uint64(chainDealID) + sid := uint64(sectorid) + + // Ensure the SectorStatus and PieceStatus maps are initialized + if dr.Sectors[sid] == nil { + dr.Sectors[sid] = &SectorStatus{Deals: make(map[uint64]*PieceStatus)} + } + if dr.Sectors[sid].Deals == nil { + dr.Sectors[sid].Deals = make(map[uint64]*PieceStatus) + } + + dr.Sectors[sid].Deals[cdi] = &PieceStatus{ + PieceCID: piececid, + PieceSize: piecesize, + PieceOffset: offset, + IsUnsealed: false, + } + + if dr.HaveBoostDealsAndPieceStore { // sanity check on piece store / piece info vs chain data and inferred piece size / offset data + pi, err := ps.GetPieceInfo(piececid) + if err != nil { + logger.Errorw("can't get piece info from piece store", "piececid", piececid, "sector", sid, "err", err) + } else { + var found bool + for _, di := range pi.Deals { + if di.DealID == chainDealID { + found = true + + if di.SectorID != sectorid { + logger.Errorw("sector mismatch", "sector", sid, "piececid", piececid, "chain-deal-id", chainDealID, "got", di.SectorID) + } + if di.Offset != offset.Padded() { + logger.Errorw("offset mismatch", "sector", sid, "piececid", piececid, "chain-deal-id", chainDealID, "calculated", offset.Padded(), "got from ps", di.Offset) + } + if di.Length != piecesize { + logger.Errorw("length/piece size mismatch", "sector", sid, "piececid", piececid, "chain-deal-id", chainDealID, "expected", piecesize, "got from ps", di.Length) + } + } + } + if !found { + logger.Errorw("chain deal not found in piece info", "sector", sid, "piececid", piececid, "chain-deal-id", chainDealID, "pi", spew.Sdump(pi)) + } + } + } + + defer func(start time.Time) { + took := time.Since(start) + dr.Sectors[sid].Deals[cdi].ProcessingTook = took + logger.Debugw("processed piece", "took", took, "sector", sectorid, "piececid", piececid, "piecesize", piecesize, "offset", offset, "label", l) + }(time.Now()) + + reader, isUnsealed, err := safeUnsealSector(ctx, sectorid, offset, piecesize) + if err != nil { + return err + } + defer func() { + if reader != nil { + reader.Close() + } + }() + if !isUnsealed { + return fmt.Errorf("sector %d is not unsealed", sid) + } + + dr.Sectors[sid].Deals[cdi].IsUnsealed = true + dr.Sectors[sid].Deals[cdi].GotDataReader = true + + if !ignoreLID { // populate LID + var shouldGenerateNewDeal bool + + var di model.DealInfo + + if dr.HaveBoostDealsAndPieceStore { // successfully loaded boost sqlite db and piece store => try to infer dealinfo + // find the deal corresponding to the deal info's DealID + proposalCid, okLegacy := dr.PropCidByChainDealID[chainDealID] + uuid, okBoost := dr.BoostDeals[chainDealID] + + if !okLegacy && !okBoost { + logger.Errorw("can't find boost deal or legacy deal", + "piececid", piececid, "chain-deal-id", chainDealID) + + shouldGenerateNewDeal = true + } else { + isLegacy := false + if uuid == "" { + uuid = proposalCid.String() + isLegacy = true + } + + di = model.DealInfo{ + DealUuid: uuid, + IsLegacy: isLegacy, + ChainDealID: chainDealID, + MinerAddr: maddr, + SectorID: sectorid, + PieceOffset: offset.Padded(), + PieceLength: piecesize, + } + } + } + + if !dr.HaveBoostDealsAndPieceStore || shouldGenerateNewDeal { // missing boost sqlite db and piece store, so generate new dealinfo + // in the future we could also regenerate boost db sqlite?? + + di = model.DealInfo{ + DealUuid: uuid.NewString(), + IsLegacy: false, + ChainDealID: chainDealID, + MinerAddr: maddr, + SectorID: sectorid, + PieceOffset: offset.Padded(), + PieceLength: piecesize, + } + } + + timeAddIndex := time.Now() + + err = pd.AddDealForPiece(ctx, piececid, di) + if err != nil { + logger.Errorw("can't add deal info for piece", "piececid", piececid, "chain-deal-id", chainDealID, "err", err) + + return err + } + + logger.Infow("added index", "took", time.Since(timeAddIndex), "sector", di.SectorID, "piececid", piececid, "chain-deal-id", di.ChainDealID, "uuid", di.DealUuid) + } + + if !ignoreCommp { // commp over data reader + w := &writer.Writer{} + _, err = io.CopyBuffer(w, reader, make([]byte, writer.CommPBuf)) + if err != nil { + return fmt.Errorf("copy into commp writer: %w", err) + } + + commp, err := w.Sum() + if err != nil { + return fmt.Errorf("computing commP failed: %w", err) + } + + encoder := cidenc.Encoder{Base: multibase.MustNewEncoder(multibase.Base32)} + _ = encoder + + if !commp.PieceCID.Equals(piececid) { + return fmt.Errorf("calculated commp doesn't match on-chain data, expected %s, got %s", piececid, commp.PieceCID) + } + } + + return nil } func processSector(ctx context.Context, key types.TipSetKey, info *miner.SectorOnChainInfo) (bool, bool, error) { // ok, isUnsealed, error - logger.Debugw("processing sector", "sector", info.SectorNumber, "deals", info.DealIDs) - - sectorid := info.SectorNumber - sid := uint64(sectorid) - - var gotErr bool - - defer func(start time.Time) { - took := time.Since(start) - dr.Sectors[sid].ProcessingTook = took - if gotErr { - logger.Debugw("processed sector with errors", "sector", sectorid, "took", took, "deals", info.DealIDs) - } else { - logger.Debugw("successfully processed sector", "sector", sectorid, "took", took, "deals", info.DealIDs) - } - }(time.Now()) - - err := dr.MarkSectorInProgress(sectorid) - if err != nil { - return false, false, err - } - - dr.Sectors[sid].Deals = make(map[uint64]*PieceStatus) - - nextoffset := uint64(0) - for _, did := range info.DealIDs { - marketDeal, err := fullnodeApi.StateMarketStorageDeal(ctx, did, key) - if err != nil { - if strings.Contains(err.Error(), "not found") { - logger.Warnw("deal present in sector, but not in market actor state, so probably expired", "sector", sectorid, "deal", did, "err", err) - break - } else { - return false, false, err - } - } - - l := "(not a string)" - if marketDeal.Proposal.Label.IsString() { - l, err = marketDeal.Proposal.Label.ToString() - if err != nil { - return false, false, err - } - } - - if nextoffset%uint64(marketDeal.Proposal.PieceSize.Unpadded()) != 0 { - currentoffset := nextoffset - nextoffset = 0 - for nextoffset < currentoffset { - nextoffset += uint64(marketDeal.Proposal.PieceSize.Unpadded()) - } - } - - err = processPiece(ctx, sectorid, did, marketDeal.Proposal.PieceCID, marketDeal.Proposal.PieceSize, abi.UnpaddedPieceSize(nextoffset), l) - nextoffset += uint64(marketDeal.Proposal.PieceSize.Unpadded()) - if err != nil { - dr.Sectors[sid].Deals[uint64(did)].Error = err.Error() - dr.PieceErrors++ - gotErr = true - logger.Errorw("got piece error", "sector", sectorid, "deal", did, "err", err) - continue - } - } - - err = dr.CompleteSector(sectorid) - if err != nil { - return false, false, err - } - - return true, true, nil + logger.Debugw("processing sector", "sector", info.SectorNumber, "deals", info.DealIDs) + + sectorid := info.SectorNumber + sid := uint64(sectorid) + + var gotErr bool + + // Ensure the SectorStatus map is initialized + if dr.Sectors[sid] == nil { + dr.Sectors[sid] = &SectorStatus{Deals: make(map[uint64]*PieceStatus)} + } + if dr.Sectors[sid].Deals == nil { + dr.Sectors[sid].Deals = make(map[uint64]*PieceStatus) + } + + // Start time for deferred function + start := time.Now() + + defer func() { + took := time.Since(start) + dr.Sectors[sid].ProcessingTook = took + if gotErr { + logger.Debugw("processed sector with errors", "sector", sectorid, "took", took, "deals", info.DealIDs) + } else { + logger.Debugw("successfully processed sector", "sector", sectorid, "took", took, "deals", info.DealIDs) + } + }() + + err := dr.MarkSectorInProgress(sectorid) + if err != nil { + return false, false, err + } + + nextoffset := uint64(0) + for _, did := range info.DealIDs { + marketDeal, err := fullnodeApi.StateMarketStorageDeal(ctx, did, key) + if err != nil { + if strings.Contains(err.Error(), "not found") { + logger.Warnw("deal present in sector, but not in market actor state, so probably expired", "sector", sectorid, "deal", did, "err", err) + break + } else { + return false, false, err + } + } + + l := "(not a string)" + if marketDeal.Proposal.Label.IsString() { + l, err = marketDeal.Proposal.Label.ToString() + if err != nil { + return false, false, err + } + } + + if nextoffset%uint64(marketDeal.Proposal.PieceSize.Unpadded()) != 0 { + currentoffset := nextoffset + nextoffset = 0 + for nextoffset < currentoffset { + nextoffset += uint64(marketDeal.Proposal.PieceSize.Unpadded()) + } + } + + err = processPiece(ctx, sectorid, did, marketDeal.Proposal.PieceCID, marketDeal.Proposal.PieceSize, abi.UnpaddedPieceSize(nextoffset), l) + nextoffset += uint64(marketDeal.Proposal.PieceSize.Unpadded()) + if err != nil { + if dr.Sectors[sid].Deals[uint64(did)] == nil { + dr.Sectors[sid].Deals[uint64(did)] = &PieceStatus{} + } + dr.Sectors[sid].Deals[uint64(did)].Error = err.Error() + dr.PieceErrors++ + gotErr = true + logger.Errorw("got piece error", "sector", sectorid, "deal", did, "err", err) + continue + } + } + + err = dr.CompleteSector(sectorid) + if err != nil { + return false, false, err + } + + return true, true, nil } func getActorAddress(ctx context.Context, cctx *cli.Context) (maddr address.Address, err error) {