boost
boost copied to clipboard
flaky TestMultipleDealsConcurrent
https://app.circleci.com/pipelines/github/filecoin-project/boost/2470/workflows/fc0e1c49-b324-4c8e-ac3d-0bb18f692b49/jobs/21387/parallel-runs/0/steps/0-114
2022-10-18T14:54:30.059Z ERROR boost-storage-deal logs/log.go:53 deal failed {"id": "08e86119-d83b-4298-8eeb-1e50700462c6", "err": "failed to verify CommP: commP mismatch, expected=baga6ea4seaqd5zcgjmj4oeonxknvhf2wpfbgtoojntqf4mumiydk7wvhyg3qoli, actual=baga6ea4seaqke7qzenku5qlf4xwci4rrriyie72ea5lpw7ct2tvf5pwnd2gdscy"}
2022-10-18T14:54:30.125Z ERROR boost-storage-deal logs/log.go:53 deal failed {"id": "07162fac-d6c4-4e0f-a8d4-d735cb1d1700", "err": "failed to verify CommP: commP mismatch, expected=baga6ea4seaqj2y2swvi6vssdogmklh3llnkrrpkw45xles5ghoj4kb5jm3ldimy, actual=baga6ea4seaqd5zcgjmj4oeonxknvhf2wpfbgtoojntqf4mumiydk7wvhyg3qoli"}
2022-10-18T14:54:30.170Z ERROR boost-storage-deal logs/log.go:53 deal failed {"id": "f6a2dead-9d3e-4471-85ae-6d8e72bf4b30", "err": "failed to verify CommP: commP mismatch, expected=baga6ea4seaqke7qzenku5qlf4xwci4rrriyie72ea5lpw7ct2tvf5pwnd2gdscy, actual=baga6ea4seaqj2y2swvi6vssdogmklh3llnkrrpkw45xles5ghoj4kb5jm3ldimy"}
provider_test.go:1048:
Error Trace: /home/circleci/project/storagemarket/provider_test.go:1048
/home/circleci/project/storagemarket/provider_test.go:151
Error: Received unexpected error:
failed to verify CommP: commP mismatch, expected=baga6ea4seaqd5zcgjmj4oeonxknvhf2wpfbgtoojntqf4mumiydk7wvhyg3qoli, actual=baga6ea4seaqke7qzenku5qlf4xwci4rrriyie72ea5lpw7ct2tvf5pwnd2gdscy
Test: TestMultipleDealsConcurrent
2022-10-18T14:54:30.202Z ERROR boost-storage-deal logs/log.go:53 failed to untag funds {"id": "f6a2dead-9d3e-4471-85ae-6d8e72bf4b30", "err": "persisting untag funds log to DB: inserting funds log: sql: database is closed"}
2022-10-18T14:54:30.202Z ERROR boost-storage-deal logs/log.go:53 failed to untag storage {"id": "f6a2dead-9d3e-4471-85ae-6d8e72bf4b30", "err": "persisting untag storage for deal to DB: getting untagged amount: sql: database is closed"}
2022-10-18T14:54:30.202Z ERROR boost-storage-deal logs/log.go:53 failed to untag storage space {"id": "56981315-5cfa-4ba2-bec7-7b1069d6a9c4", "err": "persisting untag storage for deal to DB: getting untagged amount: sql: database is closed"}
controller.go:269: missing call(s) to *mock_types.MockChainDealManager.WaitForPublishDeals(is anything, is equal to QmXenrv93GUvaqpqdcKEXVz8SJJgLbbqqw9JCdRrA4Cm5J (cid.Cid), is equal to {baga6ea4seaqke7qzenku5qlf4xwci4rrriyie72ea5lpw7ct2tvf5pwnd2gdscy 4194304 false t01014 t01011 {[] false} 50000 800000 1 1 1} (market.DealProposal)) /home/circleci/project/storagemarket/smtestutil/mocks.go:217
controller.go:269: missing call(s) to *mock_types.MockChainDealManager.WaitForPublishDeals(is anything, is equal to QmVaPTddRyjLjMoZnYufWc5M5CjyGNPmFEpp5HtPKEqZFG (cid.Cid), is equal to {baga6ea4seaqd5zcgjmj4oeonxknvhf2wpfbgtoojntqf4mumiydk7wvhyg3qoli 4194304 false t01014 t01011 {[] false} 50000 800000 1 1 1} (market.DealProposal)) /home/circleci/project/storagemarket/smtestutil/mocks.go:217
controller.go:269: missing call(s) to *mock_types.MockChainDealManager.WaitForPublishDeals(is anything, is equal to QmTbEvXabndtyFm6zYZBvYg82jy9Po9bX8dXbyPAEWYh1f (cid.Cid), is equal to {baga6ea4seaqj2y2swvi6vssdogmklh3llnkrrpkw45xles5ghoj4kb5jm3ldimy 4194304 false t01014 t01011 {[] false} 50000 800000 1 1 1} (market.DealProposal)) /home/circleci/project/storagemarket/smtestutil/mocks.go:217
controller.go:269: missing call(s) to *mock_types.MockPieceAdder.AddPiece(is anything, is equal to 4161536 (abi.UnpaddedPieceSize), is anything, is equal to {QmUo6yRfuCzKY9tJDCLEH8ytTh3Y9jbCG5RbbYgnt1JFWQ 34 0xc000902d98 {50000 800000} true} (api.PieceDealInfo)) /home/circleci/project/storagemarket/smtestutil/mocks.go:269
controller.go:269: missing call(s) to *mock_types.MockPieceAdder.AddPiece(is anything, is equal to 4161536 (abi.UnpaddedPieceSize), is anything, is equal to {QmcdyB29uHtqMRZy47MrhaqFqHpHuPr7eUxWWPJbGpSRxg 59 0xc000902eb8 {50000 800000} true} (api.PieceDealInfo)) /home/circleci/project/storagemarket/smtestutil/mocks.go:269
controller.go:269: missing call(s) to *mock_types.MockPieceAdder.AddPiece(is anything, is equal to 4161536 (abi.UnpaddedPieceSize), is anything, is equal to {QmTPwmaQtBLq9RXbvNyfj46X65YShYzMzn62FFbNYcieEm 68 0xc000902fd8 {50000 800000} true} (api.PieceDealInfo)) /home/circleci/project/storagemarket/smtestutil/mocks.go:269
controller.go:269: missing call(s) to *mock_types.MockDealPublisher.Publish(is anything, is equal to {{baga6ea4seaqke7qzenku5qlf4xwci4rrriyie72ea5lpw7ct2tvf5pwnd2gdscy 4194304 false t01014 t01011 {[] false} 50000 800000 1 1 1} {2 [115 105 103]}} (market.ClientDealProposal)) /home/circleci/project/storagemarket/smtestutil/mocks.go:180
controller.go:269: missing call(s) to *mock_types.MockDealPublisher.Publish(is anything, is equal to {{baga6ea4seaqd5zcgjmj4oeonxknvhf2wpfbgtoojntqf4mumiydk7wvhyg3qoli 4194304 false t01014 t01011 {[] false} 50000 800000 1 1 1} {2 [115 105 103]}} (market.ClientDealProposal)) /home/circleci/project/storagemarket/smtestutil/mocks.go:180
controller.go:269: missing call(s) to *mock_types.MockDealPublisher.Publish(is anything, is equal to {{baga6ea4seaqj2y2swvi6vssdogmklh3llnkrrpkw45xles5ghoj4kb5jm3ldimy 4194304 false t01014 t01011 {[] false} 50000 800000 1 1 1} {2 [115 105 103]}} (market.ClientDealProposal)) /home/circleci/project/storagemarket/smtestutil/mocks.go:180
controller.go:269: aborting test due to missing call(s)
2022-10-18T14:54:30.203Z ERROR boost-storage-deal logs/log.go:53 deal failed {"id": "56981315-5cfa-4ba2-bec7-7b1069d6a9c4", "err": "failed to add index and announce deal: failed to persist deal state: sql: database is closed"}
2022-10-18T14:54:30.203Z ERROR boost-storage-deal logs/log.go:53 failed to update deal state in DB {"id": "56981315-5cfa-4ba2-bec7-7b1069d6a9c4", "err": "sql: database is closed"}
2022-10-18T14:54:30.203Z ERROR boost-storage-deal logs/log.go:53 failed to untag funds {"id": "56981315-5cfa-4ba2-bec7-7b1069d6a9c4", "err": "persisting untag funds for deal to DB: getting untagged amount: sql: database is closed"}
2022-10-18T14:54:30.203Z ERROR boost-storage-deal logs/log.go:53 failed to untag storage {"id": "56981315-5cfa-4ba2-bec7-7b1069d6a9c4", "err": "persisting untag storage for deal to DB: getting untagged amount: sql: database is closed"}
--- FAIL: TestMultipleDealsConcurrent (2.56s)
Started looking into this a bit more as it's been popping up pretty frequently. The interesting bit here is that the commp mismatches are showing expected and actual commp from the other deals, so it's not an incorrect computation. I expect that the wires are getting crossed in the test somewhere and we're seeing some collision in data prep.