B2 Multipart Upload - net/http: timeout awaiting response headers

What is the problem you are having with rclone?

Backblaze B2 is timing out when rclone is trying to set the modification time on a multi-part upload. I don't believe this is on all multi-part uploads but I am seeing it on more than one file within my nightly sync.

I didn't flag this as a bug but I was wondering if there was an argument that would be helpful here without being too detrimental to my runtime length.

What is your rclone version (output from rclone version)

rclone v1.54.1
- os/arch: linux/amd64
- go version: go1.15.8

Which cloud storage system are you using? (eg Google Drive)

Backblaze B2

The command you were trying to run (eg rclone copy /tmp remote:tmp)

rclone sync "${src_path}/" "${dst_path}/" --exclude="._*" --exclude=".DS_Store" --transfers 32 --checkers 32 --links --no-unicode-normalization --local-case-sensitive --order-by="size,mixed,50" --low-level-retries 20 --retries 2 --progress --log-level DEBUG --log-file "${logfile}" --bwlimit "07:00,125M 10:00,62M 19:30,125M 22:00,off"

The rclone config contents with secrets removed.

[backblaze]
type = b2
account = XXX
key = YYY

A log from the command with the -vv flag

2021/03/31 01:41:45 DEBUG : .../dirA/Another_Movie_File.mov: Cancelling large file copy
2021/03/31 01:41:45 DEBUG : .../dirB/My_Movie_File.mov: Error copying chunk 2 (retry=true): Post "https://api000.backblazeb2.com/b2api/v1/b2_copy_part": net/http: timeout awaiting response headers: &url.Error{Op:"Post", URL:"https://api000.backblazeb2.com/b2api/v1/b2_copy_part", Err:(*http.httpError)(0x2b1de10)}
2021/03/31 01:41:45 DEBUG : pacer: low level retry 20/20 (error Post "https://api000.backblazeb2.com/b2api/v1/b2_copy_part": net/http: timeout awaiting response headers)
2021/03/31 01:41:45 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2021/03/31 01:41:45 DEBUG : .../dirB/My_Movie_File.mov: Error copying chunk 2: Post "https://api000.backblazeb2.com/b2api/v1/b2_copy_part": net/http: timeout awaiting response headers
2021/03/31 01:41:45 DEBUG : .../dirB/My_Movie_File.mov: Error copying chunk 1 (retry=false): Post "https://api000.backblazeb2.com/b2api/v1/b2_copy_part": context canceled: &url.Error{Op:"Post", URL:"https://api000.backblazeb2.com/b2api/v1/b2_copy_part", Err:(*errors.errorString)(0xc0001160b0)}
2021/03/31 01:41:45 DEBUG : pacer: Reducing sleep to 10ms
2021/03/31 01:41:45 DEBUG : .../dirB/My_Movie_File.mov: Error copying chunk 1: Post "https://api000.backblazeb2.com/b2api/v1/b2_copy_part": context canceled
2021/03/31 01:41:45 DEBUG : .../dirB/My_Movie_File.mov: Cancelling large file copy
2021/03/31 01:41:45 DEBUG : .../dirC/ImageA.1083.dpx: SHA-1 = 73377523d7cbd59db0b270ae63f8df6323c17ed6 OK
2021/03/31 01:41:46 ERROR : .../dirB/My_Movie_File.mov: Failed to set modification time: Post "https://api000.backblazeb2.com/b2api/v1/b2_copy_part": net/http: timeout awaiting response headers
2021/03/31 01:41:46 DEBUG : .../dirB/My_Movie_File.mov: Unchanged skipping
2021/03/31 01:41:46 DEBUG : .../dirD/ImageB.1384.dpx: Modification times differ by -27.188446ms: 2021-03-11 11:23:07.027188446 -0500 EST, 2021-03-11 16:23:07 +0000 UTC
2021/03/31 01:41:46 INFO  : .../dirE/ImageC.03_0143.png: Updated modification time in destination

I think you probably want to increase this

  --contimeout duration   Connect timeout (default 1m0s)

Or possibly this

  --timeout duration                   IO idle timeout (default 5m0s)

Setting the modification time involves doing a server side copy which can be time consuming.

It might be worth trying v1.55 where we fixed some bugs with setting modification times when we didn't need to.

1 Like

This topic was automatically closed 3 days after the last reply. New replies are no longer allowed.