What is the problem you are having with rclone?
Hi,
I'm trying to copy files from a S3 bucket on wasabi to a bucket on Backblaze. For large files, the multipart upload is used, and often (I would say, 80% chance of fail for small files, 100% chances for files > 2GB), the copy fail with the same behaviour :
- a POST request is sent to backblaze API to upload a chunk
- I got this error during the response : "Error: context canceled"
- Sometimes, this kind of error just after : "Reopening on read failure after offset 6610223104 bytes: retry 1/10: context canceled"
In the logs section below, I pasted the logs from 3 copy attempts of one large file.
I also tried to copy from Wasabi to local storage, and got quite the same error, see the log section below.
I also tried to use the S3-compatible API from backblaze, still the same error.
I feel that during the reception of the octet-stream response from wasabi, there is some kind of a connection lost that causes this problem. And I don't understand why rclone does not try to re-attempt the download by re-connecting with Wasabi.
Do you have any clue to solve that ?
Thanks for the help !
Run the command 'rclone version' and share the full output of the command.
rclone v1.65.0
- os/version: ubuntu 22.04 (64 bit)
- os/kernel: 5.15.0-1046-oracle (x86_64)
- os/type: linux
- os/arch: amd64
- go/version: go1.21.4
- go/linking: static
- go/tags: none
Which cloud storage system are you using? (eg Google Drive)
Source : S3 (Wasabi)
Destination : Backblaze (B2 API)
The command you were trying to run (eg rclone copy /tmp remote:tmp)
A systemd service is running with this command:
rclone \
--config=/etc/rclone/rclone.conf \
--rc-addr ":****" \
--rc-enable-metrics \
--rc-web-gui \
--rc-user ********** \
--rc-pass ************ \
--log-level DEBUG \
--log-file /***************** \
--dump headers \
--s3-no-check-bucket \
--transfers 1 \
--s3-list-chunk 10000 \
rcd
Then we run these commands to configure:
rclone rc --user ****** --pass ********** options/set --json '{"main": {"MaxDelete": 1000}}'
rclone rc --user ****** --pass ********** options/set --json '{"main": {"BwLimit": "2M"}}'
rclone rc --user ****** --pass ********** options/set --json '{"main": {"MultiThreadStreams": 0}}'
And this env file:
RCLONE_B2_CHUNK_SIZE=50Mi
RCLONE_B2_UPLOAD_CONCURRENCY=1
RCLONE_S3_CHUNK_SIZE=50Mi
RCLONE_S3_UPLOAD_CUTOFF=1Gi
RCLONE_S3_UPLOAD_CONCURRENCY=1
To help the debugging, I disable all parallelism and concurrency. I also tried to limit bandwith, but it does not work, all available bandwith is used.
Finally, I run the following command:
rclone rc \
--user ************ \
--pass ************ \
sync/copy \
srcFs=wasabi:mybucket \
dstFs=backblaze:mybucket \
_filter="{\"FilesFrom\": [\"/video_list.txt\"]}" \
_config='{"NoTraverse": true}'
With video_list.txt containing:
myfile.txt
The rclone config contents with secrets removed.
[wasabi]
type = s3
provider = Wasabi
region =
env_auth = false
access_key_id = **************
secret_access_key = **************
endpoint = s3.us-east-1.wasabisys.com
acl = private
[backblaze]
type = b2
account = **************
key = **************
[backblazes3]
type = s3
provider = Other
access_key_id = **************
secret_access_key = **************
endpoint = s3.us-east-005.backblazeb2.com
acl = private
[local]
type = local
A log from the command with the -vv flag
s3 to backlaze attempts:
2024/01/08 09:26:09 DEBUG : mybucket/myfile.txt: Done sending chunk 124
2024/01/08 09:26:10 DEBUG : mybucket/myfile.txt: multipart upload: starting chunk 125 size 50Mi offset 6.104Gi/17.460Gi
2024/01/08 09:26:10 DEBUG : mybucket/myfile.txt: Sending chunk 125 length 52428800
2024/01/08 09:26:10 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/01/08 09:26:10 DEBUG : HTTP REQUEST (req 0xc00079a100)
2024/01/08 09:26:10 DEBUG : POST /b2api/v1/b2_upload_part/**********************************************/**** HTTP/1.1
Host: pod-050-1015-00.backblaze.com
User-Agent: rclone/v1.65.0
Content-Length: 52428840
Authorization: XXXX
X-Bz-Content-Sha1: hex_digits_at_end
X-Bz-Part-Number: 126
Accept-Encoding: gzip
2024/01/08 09:26:10 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/01/08 09:26:10 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/01/08 09:26:10 DEBUG : HTTP RESPONSE (req 0xc00079a100)
2024/01/08 09:26:10 DEBUG : Error: context canceled
2024/01/08 09:26:10 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/01/08 09:26:10 DEBUG : mybucket/myfile.txt: Reopening on read failure after offset 6610223104 bytes: retry 1/10: context canceled
2024/01/08 09:26:10 DEBUG : mybucket/myfile.txt: Error sending chunk 125 (retry=false): Post "https://pod-050-1015-00.backblaze.com/b2api/v1/b2_upload_part/**********************************************/****": context canceled: &url.Error{Op:"Post", URL:"https://pod-050-1015-00.backblaze.com/b2api/v1/b2_upload_part/**********************************************/****", Err:(*errors.errorString)(0x3ab9e50)}
2024/01/08 09:26:10 DEBUG : mybucket/myfile.txt: Error sending chunk 125: Post "https://pod-050-1015-00.backblaze.com/b2api/v1/b2_upload_part/**********************************************/****": context canceled
2024/01/08 09:26:10 DEBUG : mybucket/myfile.txt: Cancelling multipart upload
2024/01/08 09:26:10 DEBUG : mybucket/myfile.txt: Cancelling large file upload
2024/01/08 09:26:10 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/01/08 09:26:10 DEBUG : HTTP REQUEST (req 0xc0009cc100)
2024/01/08 09:26:10 DEBUG :
2024/01/08 09:26:10 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/01/08 09:26:10 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/01/08 09:26:10 DEBUG : HTTP RESPONSE (req 0xc0009cc100)
2024/01/08 09:26:10 DEBUG : Error: context canceled
2024/01/08 09:26:10 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/01/08 09:26:10 ERROR : mybucket/myfile.txt: Failed to cancel large file upload: Post "https://api005.backblazeb2.com/b2api/v1/b2_cancel_large_file": context canceled
2024/01/08 09:26:10 DEBUG : mybucket/myfile.txt: Failed to cancel multipart upload: Post "https://api005.backblazeb2.com/b2api/v1/b2_cancel_large_file": context canceled
2024/01/08 09:26:10 DEBUG : mybucket/myfile.txt: Reopen failed after offset 6610223104 bytes read: RequestCanceled: request context canceled
caused by: context canceled
2024/01/08 09:26:10 ERROR : mybucket/myfile.txt: Failed to copy: Post "https://pod-050-1015-00.backblaze.com/b2api/v1/b2_upload_part/**********************************************/****": context canceled
2024/01/08 09:26:10 ERROR : rc: "sync/copy": error: Post "https://pod-050-1015-00.backblaze.com/b2api/v1/b2_upload_part/**********************************************/****": context canceled
---
2024/01/08 09:49:09 DEBUG : mybucket/myfile.txt: Done sending chunk 216
2024/01/08 09:49:10 DEBUG : mybucket/myfile.txt: multipart upload: starting chunk 217 size 50Mi offset 10.596Gi/17.460Gi
2024/01/08 09:49:10 DEBUG : mybucket/myfile.txt: Sending chunk 217 length 52428800
2024/01/08 09:49:10 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/01/08 09:49:10 DEBUG : HTTP REQUEST (req 0xc000ada800)
2024/01/08 09:49:10 DEBUG : POST /b2api/v1/b2_upload_part/********************************************/**** HTTP/1.1
Host: pod-050-1009-10.backblaze.com
User-Agent: rclone/v1.65.0
Content-Length: 52428840
Authorization: XXXX
X-Bz-Content-Sha1: hex_digits_at_end
X-Bz-Part-Number: 218
Accept-Encoding: gzip
2024/01/08 09:49:10 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/01/08 09:49:10 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/01/08 09:49:10 DEBUG : HTTP RESPONSE (req 0xc000ada800)
2024/01/08 09:49:10 DEBUG : Error: context canceled
2024/01/08 09:49:10 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/01/08 09:49:10 DEBUG : mybucket/myfile.txt: Error sending chunk 217 (retry=false): Post "https://pod-050-1009-10.backblaze.com/b2api/v1/b2_upload_part/********************************************/****": context canceled: &url.Error{Op:"Post", URL:"https://pod-050-1009-10.backblaze.com/b2api/v1/b2_upload_part/********************************************/****", Err:(*errors.errorString)(0x3ab9e50)}
2024/01/08 09:49:10 DEBUG : mybucket/myfile.txt: Reopening on read failure after offset 11441012736 bytes: retry 1/10: context canceled
2024/01/08 09:49:10 DEBUG : mybucket/myfile.txt: Error sending chunk 217: Post "https://pod-050-1009-10.backblaze.com/b2api/v1/b2_upload_part/********************************************/****": context canceled
2024/01/08 09:49:10 DEBUG : mybucket/myfile.txt: Cancelling multipart upload
2024/01/08 09:49:10 DEBUG : mybucket/myfile.txt: Cancelling large file upload
2024/01/08 09:49:10 DEBUG : mybucket/myfile.txt: Reopen failed after offset 11441012736 bytes read: RequestCanceled: request context canceled
caused by: context canceled
2024/01/08 09:49:10 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/01/08 09:49:10 DEBUG : HTTP REQUEST (req 0xc000adad00)
2024/01/08 09:49:10 DEBUG :
2024/01/08 09:49:10 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/01/08 09:49:10 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/01/08 09:49:10 DEBUG : HTTP RESPONSE (req 0xc000adad00)
2024/01/08 09:49:10 DEBUG : Error: context canceled
2024/01/08 09:49:10 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/01/08 09:49:10 ERROR : mybucket/myfile.txt: Failed to cancel large file upload: Post "https://api005.backblazeb2.com/b2api/v1/b2_cancel_large_file": context canceled
2024/01/08 09:49:10 DEBUG : mybucket/myfile.txt: Failed to cancel multipart upload: Post "https://api005.backblazeb2.com/b2api/v1/b2_cancel_large_file": context canceled
2024/01/08 09:49:10 ERROR : mybucket/myfile.txt: Failed to copy: Post "https://pod-050-1009-10.backblaze.com/b2api/v1/b2_upload_part/********************************************/****": context canceled
2024/01/08 09:49:10 ERROR : rc: "sync/copy": error: Post "https://pod-050-1009-10.backblaze.com/b2api/v1/b2_upload_part/********************************************/****": context canceled
---
2024/01/08 09:57:07 DEBUG : mybucket/myfile.txt: Done sending chunk 188
2024/01/08 09:57:07 DEBUG : mybucket/myfile.txt: multipart upload: starting chunk 189 size 50Mi offset 9.229Gi/17.460Gi
2024/01/08 09:57:07 DEBUG : mybucket/myfile.txt: Sending chunk 189 length 52428800
2024/01/08 09:57:07 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/01/08 09:57:07 DEBUG : HTTP REQUEST (req 0xc0009cc000)
2024/01/08 09:57:07 DEBUG : POST /b2api/v1/b2_upload_part/***************************************************/**** HTTP/1.1
Host: pod-050-1008-00.backblaze.com
User-Agent: rclone/v1.65.0
Content-Length: 52428840
Authorization: XXXX
X-Bz-Content-Sha1: hex_digits_at_end
X-Bz-Part-Number: 190
Accept-Encoding: gzip
2024/01/08 09:57:07 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/01/08 09:57:08 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/01/08 09:57:08 DEBUG : HTTP RESPONSE (req 0xc0009cc000)
2024/01/08 09:57:08 DEBUG : Error: context canceled
2024/01/08 09:57:08 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/01/08 09:57:08 DEBUG : mybucket/myfile.txt: Error sending chunk 189 (retry=false): Post "https://pod-050-1008-00.backblaze.com/b2api/v1/b2_upload_part/***************************************************/****": context canceled: &url.Error{Op:"Post", URL:"https://pod-050-1008-00.backblaze.com/b2api/v1/b2_upload_part/***************************************************/****", Err:(*errors.errorString)(0x3ab9e50)}
2024/01/08 09:57:08 DEBUG : mybucket/myfile.txt: Error sending chunk 189: Post "https://pod-050-1008-00.backblaze.com/b2api/v1/b2_upload_part/***************************************************/****": context canceled
2024/01/08 09:57:08 DEBUG : mybucket/myfile.txt: Cancelling multipart upload
2024/01/08 09:57:08 DEBUG : mybucket/myfile.txt: Cancelling large file upload
2024/01/08 09:57:08 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/01/08 09:57:08 DEBUG : HTTP REQUEST (req 0xc000f78000)
2024/01/08 09:57:08 DEBUG :
2024/01/08 09:57:08 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/01/08 09:57:08 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/01/08 09:57:08 DEBUG : HTTP RESPONSE (req 0xc000f78000)
2024/01/08 09:57:08 DEBUG : Error: context canceled
2024/01/08 09:57:08 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/01/08 09:57:08 ERROR : mybucket/myfile.txt: Failed to cancel large file upload: Post "https://api005.backblazeb2.com/b2api/v1/b2_cancel_large_file": context canceled
2024/01/08 09:57:08 DEBUG : mybucket/myfile.txt: Failed to cancel multipart upload: Post "https://api005.backblazeb2.com/b2api/v1/b2_cancel_large_file": context canceled
2024/01/08 09:57:08 ERROR : mybucket/myfile.txt: Failed to copy: Post "https://pod-050-1008-00.backblaze.com/b2api/v1/b2_upload_part/***************************************************/****": context canceled
2024/01/08 09:57:08 ERROR : rc: "sync/copy": error: Post "https://pod-050-1008-00.backblaze.com/b2api/v1/b2_upload_part/***************************************************/****": context canceled
s3 to local attempt:
2024/01/08 10:13:11 DEBUG : myfile.txt: Need to transfer - File not found at Destination
2024/01/08 10:13:11 DEBUG : Local file system at /local_bucket: Waiting for checks to finish
2024/01/08 10:13:11 DEBUG : Local file system at /local_bucket: Waiting for transfers to finish
2024/01/08 10:13:11 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/01/08 10:13:11 DEBUG : HTTP REQUEST (req 0xc0009cd700)
2024/01/08 10:13:11 DEBUG : GET /myfile.txt HTTP/1.1
Host: mybucket.s3.us-east-1.wasabisys.com
User-Agent: rclone/v1.65.0
Accept-Encoding: gzip
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20240108T101311Z
2024/01/08 10:13:11 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/01/08 10:13:11 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/01/08 10:13:11 DEBUG : HTTP RESPONSE (req 0xc0009cd700)
2024/01/08 10:13:11 DEBUG : HTTP/1.1 200 OK
Content-Length: 18747314827
Accept-Ranges: bytes
Content-Type: application/octet-stream
Date: Mon, 08 Jan 2024 10:13:11 GMT
Etag: "29025e9108a241dce3e44a4115a19221-1118"
Last-Modified: Wed, 13 Dec 2023 17:54:15 GMT
Server: WasabiS3/***********
X-Amz-Id-2: **************************
X-Amz-Request-Id: ********************
2024/01/08 10:13:11 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/01/08 10:18:11 DEBUG : myfile.txt: Reopening on read failure after offset 12549357568 bytes: retry 1/10: context canceled
2024/01/08 10:18:11 DEBUG : myfile.txt: Reopen failed after offset 12549357568 bytes read: RequestCanceled: request context canceled
caused by: context canceled
2024/01/08 10:18:11 NOTICE: myfile.txt.hoceraf7.partial: Removing partially written file on error: context canceled
2024/01/08 10:18:12 ERROR : myfile.txt: Failed to copy: context canceled
2024/01/08 10:18:12 ERROR : rc: "sync/copy": error: context canceled