Pieces failed to migrate v0 piece. Piece may not be recoverable

mtone · August 25, 2024, 3:51am

On my end I checked today’s log from a node that is on 1.111.4. No errors and a few WARN in this log area:

2024-08-24T20:48:17Z	INFO	retain	Prepared to run a Retain request.	{"Process": "storagenode", "cachePath": "config/retain", "Created Before": "2024-08-18T17:59:59Z", "Filter Size": 9981182, "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S"}
2024-08-24T20:48:17Z	INFO	lazyfilewalker.gc-filewalker	starting subprocess	{"Process": "storagenode", "satelliteID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S"}
2024-08-24T20:48:17Z	INFO	lazyfilewalker.gc-filewalker	subprocess started	{"Process": "storagenode", "satelliteID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S"}
2024-08-24T20:48:17Z	INFO	lazyfilewalker.gc-filewalker.subprocess	Database started	{"Process": "storagenode", "satelliteID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Process": "storagenode"}
2024-08-24T20:48:17Z	INFO	lazyfilewalker.gc-filewalker.subprocess	gc-filewalker started	{"Process": "storagenode", "satelliteID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Process": "storagenode", "createdBefore": "2024-08-18T17:59:59Z", "bloomFilterSize": 9981182}
2024-08-24T20:56:56Z	INFO	bandwidth	Persisting bandwidth usage cache to db	{"Process": "storagenode"}
2024-08-24T20:56:56Z	INFO	piecestore:monitor	readability check done	{"Process": "storagenode", "Duration": "38.32µs"}
2024-08-24T20:56:56Z	INFO	piecestore:monitor	writability check done	{"Process": "storagenode", "Duration": "93.6µs"}
2024-08-24T20:57:00Z	WARN	pieces	failed to migrate v0 piece. Piece may not be recoverable	{"Process": "storagenode"}
2024-08-24T20:57:00Z	WARN	retain	failed to trash piece	{"Process": "storagenode", "cachePath": "config/retain", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Piece ID": "KV4CFX6XPV6EYWA7VMLMCE27MQQKYBCBO3G3QSK53NB625HI5GCQ", "error": "pieces error: filestore error: file does not exist", "errorVerbose": "pieces error: filestore error: file does not exist\n\tstorj.io/storj/storagenode/blobstore/filestore.(*blobStore).Stat:126\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).pieceSizes:340\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).TrashWithStorageFormat:406\n\tstorj.io/storj/storagenode/pieces.(*Store).Trash:425\n\tstorj.io/storj/storagenode/retain.(*Service).retainPieces.func1:389\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).processTrashPiece:112\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).writeLine:99\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).Write:78\n\tio.copyBuffer:431\n\tio.Copy:388\n\tos.genericWriteTo:269\n\tos.(*File).WriteTo:247\n\tio.copyBuffer:411\n\tio.Copy:388\n\tos/exec.(*Cmd).writerDescriptor.func1:578\n\tos/exec.(*Cmd).Start.func2:728"}
2024-08-24T20:57:00Z	WARN	pieces	failed to migrate v0 piece. Piece may not be recoverable	{"Process": "storagenode"}
2024-08-24T20:57:00Z	WARN	retain	failed to trash piece	{"Process": "storagenode", "cachePath": "config/retain", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Piece ID": "KW4OHVJQ76KVWLHFIWSAWFTFFPX4C647OXIHZ6ROPEZO4SYEFCSA", "error": "pieces error: filestore error: file does not exist", "errorVerbose": "pieces error: filestore error: file does not exist\n\tstorj.io/storj/storagenode/blobstore/filestore.(*blobStore).Stat:126\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).pieceSizes:340\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).TrashWithStorageFormat:406\n\tstorj.io/storj/storagenode/pieces.(*Store).Trash:425\n\tstorj.io/storj/storagenode/retain.(*Service).retainPieces.func1:389\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).processTrashPiece:112\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).writeLine:99\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).Write:78\n\tio.copyBuffer:431\n\tio.Copy:388\n\tos.genericWriteTo:269\n\tos.(*File).WriteTo:247\n\tio.copyBuffer:411\n\tio.Copy:388\n\tos/exec.(*Cmd).writerDescriptor.func1:578\n\tos/exec.(*Cmd).Start.func2:728"}
2024-08-24T20:57:00Z	WARN	pieces	failed to migrate v0 piece. Piece may not be recoverable	{"Process": "storagenode"}
2024-08-24T20:57:00Z	WARN	retain	failed to trash piece	{"Process": "storagenode", "cachePath": "config/retain", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Piece ID": "KXHPIVXIVSHVE3YJZKSTEOU63XDGGNW3RXJIRMWQXRT2N5TO6MYA", "error": "pieces error: filestore error: file does not exist", "errorVerbose": "pieces error: filestore error: file does not exist\n\tstorj.io/storj/storagenode/blobstore/filestore.(*blobStore).Stat:126\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).pieceSizes:340\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).TrashWithStorageFormat:406\n\tstorj.io/storj/storagenode/pieces.(*Store).Trash:425\n\tstorj.io/storj/storagenode/retain.(*Service).retainPieces.func1:389\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).processTrashPiece:112\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).writeLine:99\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).Write:78\n\tio.copyBuffer:431\n\tio.Copy:388\n\tos.genericWriteTo:269\n\tos.(*File).WriteTo:247\n\tio.copyBuffer:411\n\tio.Copy:388\n\tos/exec.(*Cmd).writerDescriptor.func1:578\n\tos/exec.(*Cmd).Start.func2:728"}
2024-08-24T20:57:00Z	WARN	pieces	failed to migrate v0 piece. Piece may not be recoverable	{"Process": "storagenode"}
2024-08-24T20:57:00Z	WARN	retain	failed to trash piece	{"Process": "storagenode", "cachePath": "config/retain", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Piece ID": "KZ6A7UYD6BNVUHBATJBYPXK6HNR7YA6JJPQOYW5EZX6CAB65XPUA", "error": "pieces error: filestore error: file does not exist", "errorVerbose": "pieces error: filestore error: file does not exist\n\tstorj.io/storj/storagenode/blobstore/filestore.(*blobStore).Stat:126\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).pieceSizes:340\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).TrashWithStorageFormat:406\n\tstorj.io/storj/storagenode/pieces.(*Store).Trash:425\n\tstorj.io/storj/storagenode/retain.(*Service).retainPieces.func1:389\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).processTrashPiece:112\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).writeLine:99\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).Write:78\n\tio.copyBuffer:431\n\tio.Copy:388\n\tos.genericWriteTo:269\n\tos.(*File).WriteTo:247\n\tio.copyBuffer:411\n\tio.Copy:388\n\tos/exec.(*Cmd).writerDescriptor.func1:578\n\tos/exec.(*Cmd).Start.func2:728"}
2024-08-24T20:57:00Z	WARN	pieces	failed to migrate v0 piece. Piece may not be recoverable	{"Process": "storagenode"}
2024-08-24T20:57:00Z	WARN	retain	failed to trash piece	{"Process": "storagenode", "cachePath": "config/retain", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Piece ID": "K3WEP5PRPUG34GFELELHKMKT7JWK6BDJFLK5PGC6TOSHYBF66I2Q", "error": "pieces error: filestore error: file does not exist", "errorVerbose": "pieces error: filestore error: file does not exist\n\tstorj.io/storj/storagenode/blobstore/filestore.(*blobStore).Stat:126\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).pieceSizes:340\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).TrashWithStorageFormat:406\n\tstorj.io/storj/storagenode/pieces.(*Store).Trash:425\n\tstorj.io/storj/storagenode/retain.(*Service).retainPieces.func1:389\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).processTrashPiece:112\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).writeLine:99\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).Write:78\n\tio.copyBuffer:431\n\tio.Copy:388\n\tos.genericWriteTo:269\n\tos.(*File).WriteTo:247\n\tio.copyBuffer:411\n\tio.Copy:388\n\tos/exec.(*Cmd).writerDescriptor.func1:578\n\tos/exec.(*Cmd).Start.func2:728"}
2024-08-24T21:04:13Z	INFO	trust	Scheduling next refresh	{"Process": "storagenode", "after": "8h14m49.159111322s"}
2024-08-24T21:13:30Z	INFO	lazyfilewalker.gc-filewalker.subprocess	gc-filewalker completed	{"Process": "storagenode", "satelliteID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Process": "storagenode", "piecesCount": 17245536, "Total Pieces To Trash": 107973, "Trashed Pieces": 107973, "Pieces Skipped": 0}
2024-08-24T21:13:30Z	INFO	lazyfilewalker.gc-filewalker	subprocess finished successfully	{"Process": "storagenode", "satelliteID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S"}
2024-08-24T21:13:30Z	INFO	retain	Moved pieces to trash during retain	{"Process": "storagenode", "cachePath": "config/retain", "Deleted pieces": 107968, "Failed to delete": 5, "Pieces failed to read": 0, "Pieces count": 17245536, "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Duration": "25m13.507853372s", "Retain Status": "enabled"}

Mark · August 25, 2024, 4:26am

Same on mine:
file does not exist

Alexey · August 25, 2024, 4:48am

With the same previous error from a description?

Mark · August 25, 2024, 5:12am

Yeah, mine looks just like the log that Mtone posted

2024-08-16T02:12:08Z	WARN	retain	failed to trash piece	{"Process": "storagenode", "cachePath": "config/retain", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Piece ID": "7YT6SV6KRKUNVDQV6S4EUWG2TXBEV37AJSXEMPVXK4OTTOZAOPNQ", "error": "pieces error: filestore error: file does not exist", "errorVerbose": "pieces error: filestore error: file does not exist\n\tstorj.io/storj/storagenode/blobstore/filestore.(*blobStore).Stat:124\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).pieceSizes:340\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).TrashWithStorageFormat:406\n\tstorj.io/storj/storagenode/pieces.(*Store).Trash:422\n\tstorj.io/storj/storagenode/retain.(*Service).trash:428\n\tstorj.io/storj/storagenode/retain.(*Service).retainPieces.func1:387\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).processTrashPiece:112\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).writeLine:99\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).Write:78\n\tio.copyBuffer:431\n\tio.Copy:388\n\tos.genericWriteTo:269\n\tos.(*File).WriteTo:247\n\tio.copyBuffer:411\n\tio.Copy:388\n\tos/exec.(*Cmd).writerDescriptor.func1:578\n\tos/exec.(*Cmd).Start.func2:728"}
2024-08-16T02:12:08Z	WARN	pieces	failed to migrate v0 piece. Piece may not be recoverable	{"Process": "storagenode"}
2024-08-16T02:12:08Z	WARN	retain	failed to trash piece	{"Process": "storagenode", "cachePath": "config/retain", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Piece ID": "7Y4PQRGACBNZYBV3BYVPLP3GGKQJM6YONPLSQZIXHTKCHCZPLTHA", "error": "pieces error: filestore error: file does not exist", "errorVerbose": "pieces error: filestore error: file does not exist\n\tstorj.io/storj/storagenode/blobstore/filestore.(*blobStore).Stat:124\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).pieceSizes:340\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).TrashWithStorageFormat:406\n\tstorj.io/storj/storagenode/pieces.(*Store).Trash:422\n\tstorj.io/storj/storagenode/retain.(*Service).trash:428\n\tstorj.io/storj/storagenode/retain.(*Service).retainPieces.func1:387\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).processTrashPiece:112\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).writeLine:99\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).Write:78\n\tio.copyBuffer:431\n\tio.Copy:388\n\tos.genericWriteTo:269\n\tos.(*File).WriteTo:247\n\tio.copyBuffer:411\n\tio.Copy:388\n\tos/exec.(*Cmd).writerDescriptor.func1:578\n\tos/exec.(*Cmd).Start.func2:728"}
2024-08-16T02:12:08Z	WARN	pieces	failed to migrate v0 piece. Piece may not be recoverable	{"Process": "storagenode"}
2024-08-16T02:12:08Z	WARN	retain	failed to trash piece	{"Process": "storagenode", "cachePath": "config/retain", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Piece ID": "7YGK2WQMSYAUZNSTDK2TDQRJUO6JOPSOYLGVTKNRAHNBAVPBYX3A", "error": "pieces error: filestore error: file does not exist", "errorVerbose": "pieces error: filestore error: file does not exist\n\tstorj.io/storj/storagenode/blobstore/filestore.(*blobStore).Stat:124\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).pieceSizes:340\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).TrashWithStorageFormat:406\n\tstorj.io/storj/storagenode/pieces.(*Store).Trash:422\n\tstorj.io/storj/storagenode/retain.(*Service).trash:428\n\tstorj.io/storj/storagenode/retain.(*Service).retainPieces.func1:387\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).processTrashPiece:112\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).writeLine:99\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).Write:78\n\tio.copyBuffer:431\n\tio.Copy:388\n\tos.genericWriteTo:269\n\tos.(*File).WriteTo:247\n\tio.copyBuffer:411\n\tio.Copy:388\n\tos/exec.(*Cmd).writerDescriptor.func1:578\n\tos/exec.(*Cmd).Start.func2:728"}
2024-08-16T02:12:08Z	WARN	pieces	failed to migrate v0 piece. Piece may not be recoverable	{"Process": "storagenode"}
2024-08-16T02:12:08Z	WARN	retain	failed to trash piece	{"Process": "storagenode", "cachePath": "config/retain", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Piece ID": "7YP7FIWKBEB37LY5BJYLDFJPEXVSLHF233KJOWLW3JI53T5O4VIQ", "error": "pieces error: filestore error: file does not exist", "errorVerbose": "pieces error: filestore error: file does not exist\n\tstorj.io/storj/storagenode/blobstore/filestore.(*blobStore).Stat:124\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).pieceSizes:340\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).TrashWithStorageFormat:406\n\tstorj.io/storj/storagenode/pieces.(*Store).Trash:422\n\tstorj.io/storj/storagenode/retain.(*Service).trash:428\n\tstorj.io/storj/storagenode/retain.(*Service).retainPieces.func1:387\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).processTrashPiece:112\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).writeLine:99\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).Write:78\n\tio.copyBuffer:431\n\tio.Copy:388\n\tos.genericWriteTo:269\n\tos.(*File).WriteTo:247\n\tio.copyBuffer:411\n\tio.Copy:388\n\tos/exec.(*Cmd).writerDescriptor.func1:578\n\tos/exec.(*Cmd).Start.func2:728"}
2024-08-16T02:12:21Z	INFO	piecestore	download started	{"Process": "storagenode", "Piece ID": "7E6HKD6I53M2KEFLEY4NPYYSV63BPHTIZC5LERA4AA27FWDQLPJQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET", "Offset": 0, "Size": 11520, "Remote Address": "109.61.92.65:35666"}
2024-08-16T02:12:21Z	INFO	piecestore	downloaded	{"Process": "storagenode", "Piece ID": "7E6HKD6I53M2KEFLEY4NPYYSV63BPHTIZC5LERA4AA27FWDQLPJQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET", "Offset": 0, "Size": 11520, "Remote Address": "109.61.92.65:35666"}
2024-08-16T02:12:24Z	INFO	lazyfilewalker.gc-filewalker	subprocess finished successfully	{"Process": "storagenode", "satelliteID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S"}
2024-08-16T02:12:24Z	INFO	retain	Moved pieces to trash during retain	{"Process": "storagenode", "cachePath": "config/retain", "Deleted pieces": 102729, "Failed to delete": -102729, "Pieces failed to read": 0, "Pieces count": 3737899, "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Duration": "57m57.583758772s", "Retain Status": "enabled"}

github.com

storj/storj/blob/34a102064f0b8362622b58754dd7faea57626a12/storagenode/pieces/store.go#L420


      
          		return Error.Wrap(err)
          	}
          
          	if errs.IsFunc(err, os.IsNotExist) {
          		// MaxFormatVersionSupported does not exist, migrate.
          		err = store.MigrateV0ToV1(ctx, satellite, pieceID)
          		if err != nil {
          			if !errs.Is(err, sql.ErrNoRows) {
          				return Error.Wrap(err)
          			}
          			store.log.Warn("failed to migrate v0 piece. Piece may not be recoverable")
          		}
          	}
          
          	// if V0 pieces was found we just migrated it so we can trash piece using specific storage format
          	return Error.Wrap(store.blobs.TrashWithStorageFormat(ctx, blobstore.BlobRef{
          		Namespace: satellite.Bytes(),
          		Key:       pieceID.Bytes(),
          	}, filestore.MaxFormatVersionSupported, timestamp))
          }

I don’t understand Go code. Does this code make logical sense? To me it almost looks like it checks to see if it’s missing and then tries to migrate it if it is?

Alexey · August 25, 2024, 7:03am

Not exactly, this code means that if the OS returns that the piece with a new format does not exist, it’s trying to migrate the piece in the old v0 format. And if it’s doesn’t exist too (actually - any error in the conversion process), this error message has been printed.
Perhaps an additional condition may be added here, but it would slow down this process a little bit. With millions of pieces it will become a noticeable amount of time. Perhaps not worth it.

victorelec14 · August 25, 2024, 10:00am

+1 I have 2 affected nodes (for now). It seems to have started when the Filewalker started operating.

storagenode2        | 2024-08-25T09:57:34Z      WARN    pieces  failed to migrate v0 piece. Piece may not be recoverable        {"Process": "storagenode"}
storagenode2        | 2024-08-25T09:57:34Z      WARN    retain  failed to trash piece   {"Process": "storagenode", "cachePath": "config/retain", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Piece ID": "AZDKF3AQRT2FAYAF2Z4RN6LK3YFR55SE7CMQZWGEMEH25QMPQURA", "error": "pieces error: filestore error: file does not exist", "errorVerbose": "pieces error: filestore error: file does not exist\n\tstorj.io/storj/storagenode/blobstore/filestore.(*blobStore).Stat:124\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).pieceSizes:340\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).TrashWithStorageFormat:406\n\tstorj.io/storj/storagenode/pieces.(*Store).Trash:422\n\tstorj.io/storj/storagenode/retain.(*Service).trash:428\n\tstorj.io/storj/storagenode/retain.(*Service).retainPieces.func1:387\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).processTrashPiece:112\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).writeLine:99\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).Write:78\n\tio.copyBuffer:431\n\tio.Copy:388\n\tos.genericWriteTo:269\n\tos.(*File).WriteTo:247\n\tio.copyBuffer:411\n\tio.Copy:388\n\tos/exec.(*Cmd).writerDescriptor.func1:578\n\tos/exec.(*Cmd).Start.func2:728"}
storagenode2        | 2024-08-25T09:57:34Z      WARN    pieces  failed to migrate v0 piece. Piece may not be recoverable        {"Process": "storagenode"}
storagenode2        | 2024-08-25T09:57:34Z      WARN    retain  failed to trash piece   {"Process": "storagenode", "cachePath": "config/retain", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Piece ID": "AZQJRYFZ4KWU4DHGZBGLQNLK3YFOAFOBRJAWZGMSXBYI646KNBDQ", "error": "pieces error: filestore error: file does not exist", "errorVerbose": "pieces error: filestore error: file does not exist\n\tstorj.io/storj/storagenode/blobstore/filestore.(*blobStore).Stat:124\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).pieceSizes:340\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).TrashWithStorageFormat:406\n\tstorj.io/storj/storagenode/pieces.(*Store).Trash:422\n\tstorj.io/storj/storagenode/retain.(*Service).trash:428\n\tstorj.io/storj/storagenode/retain.(*Service).retainPieces.func1:387\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).processTrashPiece:112\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).writeLine:99\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).Write:78\n\tio.copyBuffer:431\n\tio.Copy:388\n\tos.genericWriteTo:269\n\tos.(*File).WriteTo:247\n\tio.copyBuffer:411\n\tio.Copy:388\n\tos/exec.(*Cmd).writerDescriptor.func1:578\n\tos/exec.(*Cmd).Start.func2:728"}
storagenode2        | 2024-08-25T09:57:34Z      WARN    pieces  failed to migrate v0 piece. Piece may not be recoverable        {"Process": "storagenode"}
storagenode2        | 2024-08-25T09:57:34Z      WARN    retain  failed to trash piece   {"Process": "storagenode", "cachePath": "config/retain", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Piece ID": "AZPJFGAUTNC2LMBXLG7AXFVUBMO5BLOIPOKETZ7UUR3TDOACEOMA", "error": "pieces error: filestore error: file does not exist", "errorVerbose": "pieces error: filestore error: file does not exist\n\tstorj.io/storj/storagenode/blobstore/filestore.(*blobStore).Stat:124\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).pieceSizes:340\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).TrashWithStorageFormat:406\n\tstorj.io/storj/storagenode/pieces.(*Store).Trash:422\n\tstorj.io/storj/storagenode/retain.(*Service).trash:428\n\tstorj.io/storj/storagenode/retain.(*Service).retainPieces.func1:387\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).processTrashPiece:112\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).writeLine:99\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*TrashHandler).Write:78\n\tio.copyBuffer:431\n\tio.Copy:388\n\tos.genericWriteTo:269\n\tos.(*File).WriteTo:247\n\tio.copyBuffer:411\n\tio.Copy:388\n\tos/exec.(*Cmd).writerDescriptor.func1:578\n\tos/exec.(*Cmd).Start.func2:728"}
storagenode2        | 2024-08-25T09:57:34Z      WARN    pieces  failed to migrate v0 piece. Piece may not be recoverable        {"Process": "storagenode"}

Alexey · August 25, 2024, 10:42am

Hello @victorelec14,
Welcome back!

If this is just for the garbage or TTL collectors, then, perhaps no issues.
But if you have this error for GET_AUDIT or GET_REPAIR, then you have a problem.

Mitsos · August 25, 2024, 3:46pm

A node of mine suddenly started throwing hundreds of thousands of lines of “Pieces failed to migrate v0 piece. Piece may not be recoverable” in the past 24 hours. It’s a very good way to test the node under load, since the logs are about 25x the write load of the actual customer load on this node.

I think this the best way to benchmark nodes, we should put up a dashboard of log-lines/sec and the satellite node selection algorithm should choose based on how high they score.

Alexey · August 26, 2024, 4:39am

It’s better to use a specialized benchmark tools:

Alexey · September 1, 2024, 5:50am

A post was split to a new topic: The audit score went down again