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

WaitForPublishDeals getting deal info errored: Deal proposals for publish message bafy... did not match #1992

Open
7 of 12 tasks
f8-ptrk opened this issue Dec 16, 2024 · 2 comments
Assignees
Labels
kind/bug Kind: Bug

Comments

@f8-ptrk
Copy link
Contributor

f8-ptrk commented Dec 16, 2024

Checklist

  • This is not a question or a support request. If you have any boost related questions, please ask in the discussion 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 discussion 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 boost.

Boost component

  • boost daemon - storage providers
  • boost client
  • boost UI
  • boost data-transfer
  • boost index-provider
  • Other

Boost Version

boostd version 2.4.0+calibnet+git.3965a2c

Describe the Bug

https://calibration.filfox.info/en/message/bafy2bzacebjz4lyzadhznktgroddnm6l7mdk52mbtgmzhry4axxmqs7b6jsew?t=4

this msg seems to go on chain fine but it fails to be recognized by boost. we suspect its the hex encoding oif the params.
(the only visible thing different from other msgs, eg. https://calibration.filfox.info/en/message/bafy2bzacea67ocy4ex373mmlkza735tn3mtf4yrg3a7jstvlvmfq4mdbooipo?t=4)

Logging Information

=== Deal cb5a1a0c-3c97-42f2-9210-ff23422e1989 ===

CreatedAt: 2024-12-16 03:44:47.963 (6h ago)
Client Address: t410f3j75wv4q4eekz44e345re4syma4nzprfabhpagy (Contract)
Client Peer ID: 12D3KooWSdbqZpFA7XRfFMtSo4U9SqBKmqy3REZLBUb8PX8fjmoa
Signed Proposal CID: bafyreidkpisjbqvkt2inrmerv6jus5avpuynjrvddklu5s276b353csqsq
Label: baga6ea4seaqknmo53ymcvgnwyesyb6muftyxaoslh7fzewojiqmy2nzumm6w6jq
Verified: No
Keep Unsealed Copy: Yes
Announce To IPNI: Yes
Piece CID: baga6ea4seaqknmo53ymcvgnwyesyb6muftyxaoslh7fzewojiqmy2nzumm6w6jq
Piece Size: 8 MiB (8,388,608 bytes)
Client Collateral: 0 atto
Provider Collateral: 0 atto
Storage Price / epoch / GiB: 0 atto
Current Epoch: 2233793
Start Epoch: 2236973 (in a day)
End Epoch: 2755373 (in 6 months)
Duration:  (180 days)
Storage Fee: 0 atto (Price per epoch x Piece Size x Duration)
Transfer Mode: Online
Transfer Type: http
Transfer Size: 7.9 MiB (8,323,072 bytes)
Transfer Params: URL: https://gateway.lighthouse.storage/ipfs/bafybeigxlkesjqaercjbhjznhixesgpqseus4fogneujhjbfggalb7mjfa
Transferred: 0 B (0 bytes)
Inbound File Path: /root/.boost/incoming/cb5a1a0c-3c97-42f2-9210-ff23422e1989.download
Delete After Add Piece: Yes
Publish Message CID: bafy2bzacebjz4lyzadhznktgroddnm6l7mdk52mbtgmzhry4axxmqs7b6jsew
Chain Deal ID: 
Checkpoint: Complete (6h ago)
Status: Error: user manually terminated the dealThe deal can be in one of the following states:Transfer QueuedThe storage deal proposal has been accepted, and Boost is about to start the data transfer.Awaiting Offline Data ImportThe client has made an offline deal proposal, and Boost is waiting for the Storage Provider operator to import the deal data.TransferringThe data for the deal is transferring.Transfer CompleteThe data transfer is complete and Boost is verifying the data matches commp.Ready to PublishThe deal is in the batch publish queue, ready to be published.Awaiting Publish ConfirmationBoost sent a publish deal message for the deal and is waiting for on-chain confirmation.Adding to SectorBoost is handing the deal off to the lotus-miner sealing subsystem to be added to a sector.IndexingBoost is indexing the deal in the Local Index Directory(LID) and will be announcing the deal to the network so that clients know where to retrieve it from.IndexedAndAnnouncedThe deal has been indexed locally and announced to the network indexers.CompleteThe deal has reached its duration and expired.CancelledThe deal was cancelled.

=== Logs ===
2024-12-16 03:44:47.882: executing deal proposal received from network
{
  "peer": "12D3KooWSdbqZpFA7XRfFMtSo4U9SqBKmqy3REZLBUb8PX8fjmoa"
}
2024-12-16 03:44:47.906: processing deal acceptance request
2024-12-16 03:44:47.943: tagged funds for deal
{
  "tagged for deal publish": "50000000000000000",
  "tagged for deal collateral": "0",
  "total tagged for publish": "150000000000000000",
  "total tagged for collateral": "0",
  "total available for publish": "200205139777251756850",
  "total available for collateral": "150000000000000000000"
}
2024-12-16 03:44:47.958: created deal download staging file
{
  "path": "/root/.boost/incoming/cb5a1a0c-3c97-42f2-9210-ff23422e1989.download"
}
2024-12-16 03:44:47.969: inserted deal into deals DB
2024-12-16 03:44:47.974: deal accepted and scheduled for execution
2024-12-16 03:44:47.974: deal execution initiated
{
  "deal state": {
    "DealUuid": "cb5a1a0c-3c97-42f2-9210-ff23422e1989",
    "CreatedAt": "2024-12-16T03:44:47.96397459+01:00",
    "ClientDealProposal": {
      "Proposal": {
        "PieceCID": {
          "/": "baga6ea4seaqknmo53ymcvgnwyesyb6muftyxaoslh7fzewojiqmy2nzumm6w6jq"
        },
        "PieceSize": 8388608,
        "VerifiedDeal": false,
        "Client": "t410f3j75wv4q4eekz44e345re4syma4nzprfabhpagy",
        "Provider": "t0150406",
        "Label": "",
        "StartEpoch": 2236973,
        "EndEpoch": 2755373,
        "StoragePricePerEpoch": "0",
        "ProviderCollateral": "0",
        "ClientCollateral": "0"
      },
      "ClientSignature": {
        "Type": 0,
        "Data": null
      }
    },
    "IsOffline": false,
    "CleanupData": true,
    "ClientPeerID": "12D3KooWSdbqZpFA7XRfFMtSo4U9SqBKmqy3REZLBUb8PX8fjmoa",
    "DealDataRoot": {
      "/": "baga6ea4seaqknmo53ymcvgnwyesyb6muftyxaoslh7fzewojiqmy2nzumm6w6jq"
    },
    "InboundFilePath": "/root/.boost/incoming/cb5a1a0c-3c97-42f2-9210-ff23422e1989.download",
    "Transfer": {
      "Type": "http",
      "ClientID": "",
      "Params": null,
      "Size": 8323072
    },
    "ChainDealID": 0,
    "PublishCID": null,
    "SectorID": 0,
    "Offset": 0,
    "Length": 0,
    "Checkpoint": 0,
    "CheckpointAt": "2024-12-16T03:44:47.963974691+01:00",
    "Err": "",
    "Retry": "auto",
    "NBytesReceived": 0,
    "FastRetrieval": true,
    "AnnounceToIPNI": true
  }
}
2024-12-16 03:44:47.993: size of downloaded file
{
  "filepath": "/root/.boost/incoming/cb5a1a0c-3c97-42f2-9210-ff23422e1989.download",
  "size": 0
}
2024-12-16 03:44:47.998: deal execution in progress
2024-12-16 03:44:48.003: deal queued for transfer
{
  "transfer client id": ""
}
2024-12-16 03:45:17.561: start deal data transfer
{
  "transfer client id": ""
}
2024-12-16 03:45:17.571 [http-transport]: execute transfer
{
  "deal size": 8323072,
  "output file": "/root/.boost/incoming/cb5a1a0c-3c97-42f2-9210-ff23422e1989.download",
  "time before context deadline": "23h59m59.999993769s"
}
2024-12-16 03:45:17.575 [http-transport]: existing file size
{
  "file size": 0,
  "deal size": 8323072
}
2024-12-16 03:45:17.580 [http-transport]: http url
{
  "url": "https://gateway.lighthouse.storage/ipfs/bafybeigxlkesjqaercjbhjznhixesgpqseus4fogneujhjbfggalb7mjfa"
}
2024-12-16 03:45:17.585 [http-transport]: started async http transfer
2024-12-16 03:45:19.431 [http-transport]: sending http request
{
  "toRead": 8323072,
  "range-rq": "bytes=0-8323072"
}
2024-12-16 03:45:21.294: transfer progress
{
  "bytes received": 833270,
  "deal size": 8323072,
  "percent complete": 10
}
2024-12-16 03:45:22.903: transfer progress
{
  "bytes received": 1668188,
  "deal size": 8323072,
  "percent complete": 20
}
2024-12-16 03:45:24.381: transfer progress
{
  "bytes received": 2497848,
  "deal size": 8323072,
  "percent complete": 30
}
2024-12-16 03:45:25.859: transfer progress
{
  "bytes received": 3342190,
  "deal size": 8323072,
  "percent complete": 40
}
2024-12-16 03:45:27.338: transfer progress
{
  "bytes received": 4163366,
  "deal size": 8323072,
  "percent complete": 50
}
2024-12-16 03:45:28.948: transfer progress
{
  "bytes received": 5000174,
  "deal size": 8323072,
  "percent complete": 60
}
2024-12-16 03:45:30.427: transfer progress
{
  "bytes received": 5827328,
  "deal size": 8323072,
  "percent complete": 70
}
2024-12-16 03:45:31.903: transfer progress
{
  "bytes received": 6662366,
  "deal size": 8323072,
  "percent complete": 80
}
2024-12-16 03:45:33.509: transfer progress
{
  "bytes received": 7498798,
  "deal size": 8323072,
  "percent complete": 90
}
2024-12-16 03:45:34.721 [http-transport]: http server sent EOF
{
  "toRead": 8323072,
  "received": 8323072,
  "deal-size": 8323072
}
2024-12-16 03:45:34.721: transfer progress
{
  "bytes received": 8323072,
  "deal size": 8323072,
  "percent complete": 100
}
2024-12-16 03:45:34.732 [http-transport]: http transfer completed successfully, joining chunks
2024-12-16 03:45:34.742 [http-transport]: http request finished successfully
{
  "nBytesReceived": 8323072,
  "file size": 8323072
}
2024-12-16 03:45:34.746: deal data-transfer completed successfully
{
  "bytes received": 8323072,
  "time taken": "17.175675919s"
}
2024-12-16 03:45:34.751: checking commP
2024-12-16 03:45:35.348: commP matched successfully: deal-data verified
2024-12-16 03:45:35.358: updated deal checkpoint in DB
{
  "old checkpoint": "Accepted",
  "new checkpoint": "Transferred"
}
2024-12-16 03:45:35.363: deal data transfer finished successfully
2024-12-16 03:45:35.367: deal data-transfer can no longer be cancelled
2024-12-16 03:45:35.372: sending deal to deal publisher
2024-12-16 04:33:01.526: updated deal checkpoint in DB
{
  "old checkpoint": "Transferred",
  "new checkpoint": "Published"
}
2024-12-16 04:33:01.545: deal published successfully, will await deal publish confirmation
2024-12-16 04:33:01.556: awaiting deal publish confirmation
2024-12-16 04:39:01.502: error while waiting for publish confirm
{
  "err": "WaitForPublishDeals getting deal info errored: Deal proposals for publish message bafy2bzacebjz4lyzadhznktgroddnm6l7mdk52mbtgmzhry4axxmqs7b6jsew did not match"
}
2024-12-16 04:39:01.509: deal paused because of recoverable error
{
  "err": "wait for confirmation of publish message bafy2bzacebjz4lyzadhznktgroddnm6l7mdk52mbtgmzhry4axxmqs7b6jsew failed: WaitForPublishDeals getting deal info errored: Deal proposals for publish message bafy2bzacebjz4lyzadhznktgroddnm6l7mdk52mbtgmzhry4axxmqs7b6jsew did not match",
  "checkpoint": "Published",
  "retry": "auto"
}
2024-12-16 04:39:01.527: deal go-routine finished execution
2024-12-16 06:31:20.454: user manually terminated the deal
{
  "err": "wait for confirmation of publish message bafy2bzacebjz4lyzadhznktgroddnm6l7mdk52mbtgmzhry4axxmqs7b6jsew failed: WaitForPublishDeals getting deal info errored: Deal proposals for publish message bafy2bzacebjz4lyzadhznktgroddnm6l7mdk52mbtgmzhry4axxmqs7b6jsew did not match"
}
2024-12-16 06:31:20.473: cleaning up deal
2024-12-16 06:31:20.483: deal finished
2024-12-16 06:31:20.496: untagged funds for deal as deal finished
{
  "untagged publish": "50000000000000000",
  "untagged collateral": "0",
  "err": null
}
2024-12-16 06:31:20.510: untagged storage space for deal
2024-12-16 06:31:20.516: finished cleaning up deal


### Repo Steps

not sure, @lordforever on slack is working on a smart contract. group dm us if needed
@lordshashank
Copy link

The issue is due to label field in proposal, I tried putting label as bytes in the above cases leading to eternal wait for publishstoragedeals , but when I encode the same bytes as string and send it, the deal goes on successfully.
I think the issue might come down to compatibility with https://github.com/filecoin-project/FIPs/blob/master/FIPS/fip-0027.md

@LexLuthr LexLuthr self-assigned this Dec 18, 2024
@LexLuthr
Copy link
Collaborator

The issue seems to be the market state and the deal state being returned from Lotus. The message https://calibration.filfox.info/en/message/bafy2bzacebjz4lyzadhznktgroddnm6l7mdk52mbtgmzhry4axxmqs7b6jsew?t=4 has correct params and can be verified that DealLabel is indeed bytes. But once PSD is sent and we get back the dealID, if I lookup the gapi.StateMarketStorageDeal(ctx, abi.DealID(208281), types.EmptyTSK), I do not get a DealLabel of types byte. This points to mismatch between what's expected and what is on chain leading to deal failure.

Code to verify. Using manual params instead of StateSearchMessage to avoid failure as Gateway allows upto 2000 epoch look back only.

package main

import (
	"bytes"
	"context"
	"encoding/hex"
	"errors"
	"fmt"

	"github.com/filecoin-project/go-state-types/abi"
	market9 "github.com/filecoin-project/go-state-types/builtin/v9/market"
	"github.com/filecoin-project/lotus/api/client"
	"github.com/filecoin-project/lotus/chain/types"
	cliutil "github.com/filecoin-project/lotus/cli/util"
)

func CheckDealEquality(p1, p2 market9.DealProposal) error {
	if !p1.PieceCID.Equals(p2.PieceCID) {
		return errors.New("piece CID")
	}

	if !(p1.PieceSize == p2.PieceSize) {
		return errors.New("piece Size")
	}

	if !(p1.VerifiedDeal == p2.VerifiedDeal) {
		return errors.New("verified")
	}

	if !(p1.Label.Equals(p2.Label)) {
		return errors.New("label")
	}

	if !(p1.StartEpoch == p2.StartEpoch) {
		return errors.New("start")
	}

	if !(p1.EndEpoch == p2.EndEpoch) {
		return errors.New("end")
	}

	if !(p1.StoragePricePerEpoch.Equals(p2.StoragePricePerEpoch)) {
		return errors.New("price")
	}

	if !(p1.ProviderCollateral.Equals(p2.ProviderCollateral)) {
		return errors.New("collateral")
	}

	if !(p1.ClientCollateral.Equals(p2.ClientCollateral)) {
		return errors.New("collateral")
	}
	if !(p1.Provider == p2.Provider) {
		return errors.New("provider")
	}

	return nil
}

func main() {
	hexString := "8183828bd82a5828000181e203922020a6b1ddde182a99b6c12580f9942cf1703a4b3fcb9259c944198d3734633d6f261a00800000f456040a0edd69386024014a3766e917b8833e954ede03fa440086970958400000000000000000000000000000000000000000000000000000000000aa37dc000000000000000000000000b1dc8fd9c65d810521a9b676eeccebc203d364d21a0022222d1a002a0b2d40404058420145af7bbde70d356cc1e433ce179915ea55564bc347448f8bc8432fbf94bcb50111197a56f18e3d92e9e3728c4e0ff8569ccdc638b2986936ae1f68060226cf3300828bd82a5828000181e203922020a6b1ddde182a99b6c12580f9942cf1703a4b3fcb9259c944198d3734633d6f261a00800000f456040a716f42ab81f80ec9c94b337fc9f8cb1c9038b4d9440086970958400000000000000000000000000000000000000000000000000000000000aa37dc000000000000000000000000b1dc8fd9c65d810521a9b676eeccebc203d364d21a0022222d1a002a0b2d40404058420145af7bbde70d356cc1e433ce179915ea55564bc347448f8bc8432fbf94bcb50111197a56f18e3d92e9e3728c4e0ff8569ccdc638b2986936ae1f68060226cf3300828bd82a5828000181e203922020a6b1ddde182a99b6c12580f9942cf1703a4b3fcb9259c944198d3734633d6f261a00800000f456040ada7fdb5790e108acf384df3b1272586038dcbe25440086970958400000000000000000000000000000000000000000000000000000000000aa37dc000000000000000000000000b1dc8fd9c65d810521a9b676eeccebc203d364d21a0022222d1a002a0b2d40404058420145af7bbde70d356cc1e433ce179915ea55564bc347448f8bc8432fbf94bcb50111197a56f18e3d92e9e3728c4e0ff8569ccdc638b2986936ae1f68060226cf3300"

	decodedBytes, err := hex.DecodeString(hexString)
	if err != nil {
		fmt.Println(err)
		return
	}

	var retval market9.PublishStorageDealsParams
	if err := retval.UnmarshalCBOR(bytes.NewReader(decodedBytes)); err != nil {
		fmt.Printf("failed to unmarshal PublishStorageDealsReturn: %s", err)
		return
	}

	encodedLabel, err := hex.DecodeString("0000000000000000000000000000000000000000000000000000000000aa37dc000000000000000000000000b1dc8fd9c65d810521a9b676eeccebc203d364d2")
	if err != nil {
		fmt.Printf("failed to unmarshal PublishStorageDealsReturn: %s", err)
		return
	}

	label, err := market9.NewLabelFromBytes(encodedLabel)
	if err != nil {
		fmt.Println(err)
		return
	}

	for i := range retval.Deals {
		if retval.Deals[i].Proposal.Label.IsBytes() {
			fmt.Println("Params Label is bytes")
		} else {
			fmt.Println("Params Label is string")
		}

		if retval.Deals[i].Proposal.Label.Equals(label) {
			fmt.Println("Found matching deal in params with Label")
		}
	}
	ctx := context.Background()

	a := cliutil.APIInfo{
		Addr: "https://api.calibration.node.glif.io",
	}
	addr, err := a.DialArgs("v1")
	gapi, closer, err := client.NewGatewayRPCV1(ctx, addr, a.AuthHeader())
	if err != nil {
		fmt.Println("can't setup gateway connection:", err)
		return
	}
	defer closer()

	deal, err := gapi.StateMarketStorageDeal(ctx, abi.DealID(208281), types.EmptyTSK)
	if err != nil {
		fmt.Println("There getting market deal: ", err)
		return
	}

	if deal.Proposal.Label.IsBytes() {
		fmt.Println("StateMarketStorageDeal Label is bytes")
	} else {
		fmt.Println("StateMarketStorageDeal Label is string")
	}

	err = CheckDealEquality(deal.Proposal, retval.Deals[2].Proposal)
	if err != nil {
		fmt.Println("Error in proposal match:", err)
		return
	}

	if deal.Proposal.Label.Equals(label) {
		fmt.Println("Label match")
	}
}

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
kind/bug Kind: Bug
Projects
Status: No status
Development

No branches or pull requests

3 participants