estuary
estuary copied to clipboard
application-research
data-transfer failed: http req failed: code: 401, status: 401 Unauthorized
As an SP receiving deals from Estuary I have been seeing many of these errors in the last few days.
Daemon: 1.17.0+mainnet+git.2830429ad+api1.5.0 Local: lotus-miner version 1.17.0+mainnet+git.2830429ad boostd version 1.3.0-rc1+git.b85d1b9
| Field | Data |
|---|---|
| Deal | 24c89adb-f23e-458c-b071-ee64bb6a6fd4 |
| CreatedAt | 2022-08-05 06:43:40.209 (1h ago) |
| Client Address | f3vnq2cmwig3qjisnx5hobxvsd4drn4f54xfxnv4tciw6vnjdsf5xipgafreprh5riwmgtcirpcdmi3urbg36a |
| Client Peer ID | 12D3KooWCVXs8P7iq6ao4XhfAmKWrEeuKFWCJgqe9jGDMTqHYBjw |
| Signed Proposal CID | bafyreiepmq34ryqpwavtslwfxzfllxcn4abffnfc6ihamuihyyolzbrszy |
| Deal Data Root CID | bafybeih6jt6sxph4zttdil3rhygjryzieur4szgqnhi5ppvc5nvoelmkxi |
| Verified | Yes |
| Piece CID | baga6ea4seaqenmfsgsodpki5twrtphghr6wdr3zjjl6ludoizqxy3rbnc33x4fq |
| Piece Size | 128 MiB (134,217,728 bytes) |
| Client Collateral | 0 atto |
| Provider Collateral | 27,995.4 nano |
| Storage Price / epoch / GiB | 0 atto |
| Current Epoch | 2,046,504 |
| Start Epoch | 2,066,487 (in 7 days) |
| End Epoch | 3,561,207 (in a year) |
| Duration | 1,494,720 (518 days) |
| Storage Fee | 0 atto (Price per epoch x Piece Size x Duration) |
| Transfer Mode | Online |
| Transfer Type | libp2p |
| Transfer Size | 66.6 MiB (69,875,850 bytes) |
| Transfer Params | URL: libp2p:///ip4/35.74.45.12/udp/6746/quic/p2p/12D3KooWLV128pddyvoG6NBvoZw7sSrgpMTPtjnpu3mSmENqhtL7 |
| Transferred | 0 B (0 bytes) |
| Inbound File Path | /market/.boost/incoming/24c89adb-f23e-458c-b071-ee64bb6a6fd4.download |
| Checkpoint | Accepted (1h ago) |
| Status | Paused at 'Transfer Queued': data-transfer failed: http req failed: code: 401, status: 401 Unauthorized |
| Deal Logs | ||
|---|---|---|
| 2022-08-05 | 06:43:39.200 | executing deal proposal received from network peer: |
| 12D3KooWCVXs8P7iq6ao4XhfAmKWrEeuKFWCJgqe9jGDMTqHYBjw | ||
| 2022-08-05 06:43:39.316 | 116ms | processing deal acceptance request |
| 2022-08-05 06:43:40.107 | 791ms | tagged funds for deal |
| tagged for deal collateral: 27,995,369,767,473 | ||
| tagged for deal publish: 150,000,000,000,000,000 | ||
| total available for collateral: 28,369,691,800,760,554,273 | ||
| total available for publish: 15,506,346,279,880,261,657 | ||
| total tagged for collateral: 8,788,278,085,992,157 | ||
| total tagged for publish: 2,550,000,000,000,000,000 | ||
| 2022-08-05 06:43:40.184 | 77ms | created deal download staging file |
| path: /market/.boost/incoming/24c89adb-f23e-458c-b071-ee64bb6a6fd4.download | ||
| 2022-08-05 06:43:40.235 | 51ms | inserted deal into deals DB |
| 2022-08-05 06:43:40.265 | 30ms | deal accepted and scheduled for execution |
| 2022-08-05 06:43:40.265 | 0ms | deal execution initiated |
| deal state: | ||
| 2022-08-05 06:43:40.351 | 86ms | size of downloaded file |
| filepath: /market/.boost/incoming/24c89adb-f23e-458c-b071-ee64bb6a6fd4.download | ||
| size: 0 | ||
| 2022-08-05 06:43:40.377 | 26ms | deal execution in progress |
| 2022-08-05 06:43:40.406 | 29ms | transferring deal data |
| transfer client id: 902,473 | ||
| 2022-08-05 06:43:40.429 | 23ms | http-transport: execute transfer |
| deal size: 69,875,850 | ||
| output file: /market/.boost/incoming/24c89adb-f23e-458c-b071-ee64bb6a6fd4.download | ||
| time before context deadline: 23h59m59.999985162s | ||
| 2022-08-05 06:43:40.454 | 25ms | http-transport: existing file size |
| deal size: 69,875,850 | ||
| file size: 0 | ||
| 2022-08-05 06:43:40.479 | 25ms | http-transport: libp2p-http url |
| multiaddr: /ip4/35.74.45.12/udp/6746/quic | ||
| peer id: 12D3KooWLV128pddyvoG6NBvoZw7sSrgpMTPtjnpu3mSmENqhtL7 | ||
| url: libp2p://12D3KooWLV128pddyvoG6NBvoZw7sSrgpMTPtjnpu3mSmENqhtL7 | ||
| 2022-08-05 06:43:40.504 | 25ms | http-transport: started async http transfer |
| 2022-08-05 06:43:40.504 | 0ms | http-transport: sending http request |
| range-rq: bytes=0- | ||
| received: 0 | ||
| remaining: 69,875,850 | ||
| 2022-08-05 06:43:40.739 | 235ms | http-transport: http request error |
| http code: 401 | ||
| outputErr: http req failed: code: 401, status: 401 Unauthorized | ||
| 2022-08-05 06:43:40.767 | 28ms | http-transport: terminating http request: received 401 response from server |
| err: http req failed: code: 401, status: 401 Unauthorized | ||
| 2022-08-05 06:43:40.792 | 25ms | deal paused because of recoverable error |
| checkpoint: Accepted | ||
| err: data-transfer failed: http req failed: code: 401, status: 401 Unauthorized | ||
| retry: manual | ||
| 2022-08-05 06:43:40.843 | 51ms | deal go-routine finished execution |
| 2022-08-05 06:44:54.609 | 1m | user initiated deal retry |
| checkpoint: 0 | ||
| 2022-08-05 06:44:54.609 | 0ms | deal execution initiated |
| deal state: | ||
| 2022-08-05 06:44:54.703 | 94ms | size of downloaded file |
| filepath: /market/.boost/incoming/24c89adb-f23e-458c-b071-ee64bb6a6fd4.download | ||
| size: 0 | ||
| 2022-08-05 06:44:54.730 | 27ms | deal execution in progress |
| 2022-08-05 06:44:54.759 | 29ms | transferring deal data |
| transfer client id: | ||
| 2022-08-05 06:44:54.790 | 31ms | http-transport: execute transfer |
| deal size: 69,875,850 | ||
| output file: /market/.boost/incoming/24c89adb-f23e-458c-b071-ee64bb6a6fd4.download | ||
| time before context deadline: 23h59m59.999991534s | ||
| 2022-08-05 06:44:54.823 | 33ms | http-transport: existing file size |
| deal size: 69,875,850 | ||
| file size: 0 | ||
| 2022-08-05 06:44:54.851 | 28ms | http-transport: libp2p-http url |
| multiaddr: /ip4/35.74.45.12/udp/6746/quic | ||
| peer id: 12D3KooWLV128pddyvoG6NBvoZw7sSrgpMTPtjnpu3mSmENqhtL7 | ||
| url: libp2p://12D3KooWLV128pddyvoG6NBvoZw7sSrgpMTPtjnpu3mSmENqhtL7 | ||
| 2022-08-05 06:44:54.876 | 25ms | http-transport: started async http transfer |
| 2022-08-05 06:44:54.876 | 0ms | http-transport: sending http request |
| range-rq: bytes=0- | ||
| received: 0 | ||
| remaining: 69,875,850 | ||
| 2022-08-05 06:44:55.095 | 219ms | http-transport: http request error |
| http code: 401 | ||
| outputErr: http req failed: code: 401, status: 401 Unauthorized | ||
| 2022-08-05 06:44:55.125 | 30ms | http-transport: terminating http request: received 401 response from server |
| err: http req failed: code: 401, status: 401 Unauthorized | ||
| 2022-08-05 06:44:55.151 | 26ms | deal paused because of recoverable error |
| checkpoint: Accepted | ||
| err: data-transfer failed: http req failed: code: 401, status: 401 Unauthorized | ||
| retry: manual | ||
| 2022-08-05 06:44:55.202 | 51ms | deal go-routine finished execution |
@stuberman this is expected behavior. Every boost <-> estuary deal data transfer is valid for 24h, if not downloaded before it expires, it throws 401. And Given the slow data transfer rate from some of the shuttles, that will explain why many of your transfers expire before they are complete.
Look at the time stamps: Deal created 2022-08-05 06:43:40.209 Transfer started: 2022-08-05 06:44:54.876 (1 minute later) Deal failed: 2022-08-05 06:44:55.095 (1 second later)
@stuberman you are right, I was looking at the wrong place.
I have looked deeper and this happens when a deal proposal was sent out to a miner; if anything goes wrong while trying to complete the deal process on the client side just after the proposal is sent, boost does a cleanup to remove the deal auth token and cancel any data transfer associated with that deal.
If the miner then tries to start the data transfer, the auth token will not be found, the HTTP request fails with a 401 error. While this is expected behavior and not a bug, it will be nice if boost can add the feature where;
- Boost should not only remove auth token and cancel transfers (since most times, data transfer might not have started), it should notify the miner to cancel/stop the deal
So I think we should close this and add a feature/improvement request in the boost repo.
The above is one way the auth token will be missing, but I have tried to recreate this and I can conclude this is not what is happening here.
What is happening is that, when Estuary makes boost deals for shuttles, it sends an RPC command to the shuttle to add an auth token to the shuttle auth token cache (depending on the size of queued RPC messages, they might be some delay before this command is processed and the auth token added to the cache), and It sends a boost deal proposal to miner just after the RPC command is sent.
If the deal download is started before the auth token hits the cache, then a 401 error will happen. I think the code has to be refactored to only send the proposal after the auth token is added