filecoin-project / lotus

Reference implementation of the Filecoin protocol, written in Go
https://lotus.filecoin.io/
Other
2.83k stars 1.25k forks source link

StorageDealError #5063

Closed 2019jack closed 2 years ago

2019jack commented 3 years ago

2020-11-30T22:48:36.504+0800 INFO miner miner/miner.go:384 Time delta between now and our mining base: 6s (nulls: 0) 2020-11-30T22:48:43.845+0800 ERROR storagemarket_impl dtutils/dtutils.go:152 attempting to configure data store: %!w(errors.errorString=&{already registerd a persistence option with this name}) 2020-11-30T22:48:43.846+0800 INFO markets loggers/loggers.go:20 storage event {"name": "ProviderEventDataTransferRestarted", "proposal CID": "bafyreihwcuxr6gkwkeifkhz7p27htdrq7mr3rxu3cyrqd7to2hiilaakcq", "state": "StorageDealTransferring", "message": ""} 2020-11-30T22:48:43.897+0800 WARN dt_graphsync graphsync/graphsync.go:150 graphsync request context cancelled, channel Id: 12D3KooWKFJnq2Fsypw2gRToY1SfCGb4b5GxaUojF58ECTJ5yToy-12D3KooWHWK6GGMcp1D7BcF4hKxrkyTBF6mCtobBSQUgUjnhYhz8-6 2020-11-30T22:48:43.897+0800 WARN dt-impl impl/events.go:196 channel 12D3KooWKFJnq2Fsypw2gRToY1SfCGb4b5GxaUojF58ECTJ5yToy-12D3KooWHWK6GGMcp1D7BcF4hKxrkyTBF6mCtobBSQUgUjnhYhz8-6 has timed out 2020-11-30T22:49:04.024+0800 ERROR storagemarket_impl dtutils/dtutils.go:152 attempting to configure data store: %!w(errors.errorString=&{already registerd a persistence option with this name}) 2020-11-30T22:49:04.024+0800 INFO markets loggers/loggers.go:20 storage event {"name": "ProviderEventDataTransferRestarted", "proposal CID": "bafyreihwcuxr6gkwkeifkhz7p27htdrq7mr3rxu3cyrqd7to2hiilaakcq", "state": "StorageDealTransferring", "message": ""} 2020-11-30T22:49:04.083+0800 WARN dt_graphsync graphsync/graphsync.go:150 graphsync request context cancelled, channel Id: 12D3KooWKFJnq2Fsypw2gRToY1SfCGb4b5GxaUojF58ECTJ5yToy-12D3KooWHWK6GGMcp1D7BcF4hKxrkyTBF6mCtobBSQUgUjnhYhz8-6 2020-11-30T22:49:04.083+0800 WARN dt-impl impl/events.go:196 channel 12D3KooWKFJnq2Fsypw2gRToY1SfCGb4b5GxaUojF58ECTJ5yToy-12D3KooWHWK6GGMcp1D7BcF4hKxrkyTBF6mCtobBSQUgUjnhYhz8-6 has timed out 2020-11-30T22:49:06.145+0800 INFO miner miner/miner.go:384 Time delta between now and our mining base: 6s (nulls: 0) 2020-11-30T22:49:07.120+0800 INFO graphsync impl/graphsync.go:283 Graphsync ReceiveError: stream reset 2020-11-30T22:49:30.277+0800 ERROR storagemarket_impl dtutils/dtutils.go:152 attempting to configure data store: %!w(errors.errorString=&{already registerd a persistence option with this name}) 2020-11-30T22:49:30.278+0800 INFO markets loggers/loggers.go:20 storage event {"name": "ProviderEventDataTransferRestarted", "proposal CID": "bafyreihwcuxr6gkwkeifkhz7p27htdrq7mr3rxu3cyrqd7to2hiilaakcq", "state": "StorageDealTransferring", "message": ""} 2020-11-30T22:49:30.278+0800 ERROR storagemarket_impl dtutils/dtutils.go:152 attempting to configure data store: %!w(errors.errorString=&{already registerd a persistence option with this name}) 2020-11-30T22:49:30.342+0800 INFO graphsync messagequeue/messagequeue.go:209 graphsync send error: stream reset 2020-11-30T22:49:30.342+0800 WARN dt_graphsync graphsync/graphsync.go:150 graphsync request context cancelled, channel Id: 12D3KooWKFJnq2Fsypw2gRToY1SfCGb4b5GxaUojF58ECTJ5yToy-12D3KooWHWK6GGMcp1D7BcF4hKxrkyTBF6mCtobBSQUgUjnhYhz8-6 2020-11-30T22:49:30.342+0800 WARN dt-impl impl/events.go:196 channel 12D3KooWKFJnq2Fsypw2gRToY1SfCGb4b5GxaUojF58ECTJ5yToy-12D3KooWHWK6GGMcp1D7BcF4hKxrkyTBF6mCtobBSQUgUjnhYhz8-6 has timed out 2020-11-30T22:49:30.343+0800 ERROR dt_graphsync graphsync/graphsync.go:545 cannot unregister while requests are in progress 2020-11-30T22:49:30.346+0800 INFO markets loggers/loggers.go:20 storage event {"name": "ProviderEventDataTransferRestarted", "proposal CID": "bafyreihwcuxr6gkwkeifkhz7p27htdrq7mr3rxu3cyrqd7to2hiilaakcq", "state": "StorageDealTransferring", "message": ""} 2020-11-30T22:49:30.426+0800 INFO markets loggers/loggers.go:20 storage event {"name": "ProviderEventDataTransferCompleted", "proposal CID": "bafyreihwcuxr6gkwkeifkhz7p27htdrq7mr3rxu3cyrqd7to2hiilaakcq", "state": "StorageDealVerifyData", "message": ""} 2020-11-30T22:49:30.442+0800 WARN graphsync messagequeue/messagequeue.go:222 SendMsg errored but neither 'done' nor context.Done() were set 2020-11-30T22:49:31.278+0800 INFO markets loggers/loggers.go:20 storage event {"name": "ProviderEventDataVerificationFailed", "proposal CID": "bafyreihwcuxr6gkwkeifkhz7p27htdrq7mr3rxu3cyrqd7to2hiilaakcq", "state": "StorageDealFailing", "message": "deal data verification failed: error generating CommP: error traversing node at \"Links/0/Hash/Links/323/Hash\": could not load link \"bafk2bzaceamc3ixendqrcitr6sy2jw6hbzw3mxarccz2svevotokopezighje\": blockstore: block not found"} 2020-11-30T22:49:31.279+0800 WARN providerstates providerstates/provider_states.go:513 deal bafyreihwcuxr6gkwkeifkhz7p27htdrq7mr3rxu3cyrqd7to2hiilaakcq failed: deal data verification failed: error generating CommP: error traversing node at "Links/0/Hash/Links/323/Hash": could not load link "bafk2bzaceamc3ixendqrcitr6sy2jw6hbzw3mxarccz2svevotokopezighje": blockstore: block not found 2020-11-30T22:49:31.280+0800 INFO markets loggers/loggers.go:20 storage event {"name": "ProviderEventFailed", "proposal CID": "bafyreihwcuxr6gkwkeifkhz7p27htdrq7mr3rxu3cyrqd7to2hiilaakcq", "state": "StorageDealError", "message": "deal data verification failed: error generating CommP: error traversing node at \"Links/0/Hash/Links/323/Hash\": could not load link \"bafk2bzaceamc3ixendqrcitr6sy2jw6hbzw3mxarccz2svevotokopezighje\": blockstore: block not found"} 2020-11-30T22:49:36.089+0800 INFO miner miner/miner.go:384 Time delta between now and our mining base: 6s (nulls: 0) 2020-11-30T22:50:06.547+0800 WARN dt-impl impl/receiver.go:26 channel is already terminated 2020-11-30T22:50:06.628+0800 INFO miner miner/miner.go:384 Time delta between now and our mining base: 6s (nulls: 0) 2020-11-30T22:50:22.214+0800 INFO graphsync impl/graphsync.go:283 Graphsync ReceiveError: message too large 2020-11-30T22:50:23.203+0800 INFO graphsync impl/graphsync.go:283 Graphsync ReceiveError: stream reset 2020-11-30T22:50:23.622+0800 WARN dt-impl impl/receiver.go:26 channel is already terminated 2020-11-30T22:50:36.463+0800 INFO miner miner/miner.go:384 Time delta between now and our mining base: 6s (nulls: 0) 2020-11-30T22:51:06.238+0800 INFO miner miner/miner.go:384 Time delta between now and our mining base: 6s (nulls: 0)

Daemon: 1.2.1+git.d15d9b0fb.dirty+api1.0.0 Local: lotus version 1.2.1+git.d15d9b0fb

@magik6k @dirkmc this is miner log , deals storagedata is error

dirkmc commented 3 years ago

Thanks for filing this bug report.

Are you seeing this error when you first start the lotus miner? Or did this occur when the miner was already running for a while?

Could you also please check to make sure you are not running out of disk space.

2019jack commented 3 years ago

@dirkmc i disk space have /dev/sda1 44T 13T 32T 29% , have 32T disk space, miner has been running for a while, and the above log error occurred when my miner received deals storage data

2019jack commented 3 years ago

@dirkmc you have method tell me to solve it?

dirkmc commented 3 years ago

It seems this is a bug in lotus. We are working on a fix here: https://github.com/filecoin-project/go-data-transfer/pull/115

2019jack commented 3 years ago

@dirkmc you means is already to fix , right?

2019jack commented 3 years ago

@dirkmc report bug is can have encourage?

Reiers commented 2 years ago

Hi @2019jack

Thanks for the report. This is fixed in the latest release. Please upgrade Lotus.

Link to latest tags here.

Closing Lotus issue ticket.

If you are still experiencing problems, open a new ticket or ask for help in our Discussions forum.