Transfer percentages >100%? Again

What is the problem you are having with rclone?

Hi,
I appear to be having the problem that was already described here: Transfer percentages >100%? , only it is much much worse. I am trying to sync from s3 to dropbox. Every so often, a bunch of transfers get stuck... but they are stuck in the thousands of percent:

Transferred:        6.557 GiB / 6.467 GiB, 101%, 178.625 KiB/s, ETA -
Checks:             37588 / 47604, 79%
Transferred:          157 / 188, 84%
Elapsed time:   2h20m24.7s
Checking:
 * datasets/call-logs/RE2…eeb659ee91e8a11c8243ef: checking
 *                  geo/2017/fcc/tv/1357806.json: checking
 * backup/prod/pricing/zi…tDeepSearchResults.xml: checking
 * datasets/calls/transcr…0a33fc0196e2cd906.json: checking
 * datasets/calls/transcr…4456364943e2d44c3.json: checking
 * datasets/calls/transcr…fccc6852dc00d072b.json: checking
 *             geo/2017/fcc/radio/fm/119832.json: checking
 * backup/prod/insightly/…2-02T03:43:59.jsonl.gz: checking
Transferring:
 * qa/dotloop-activity202…1-9fca-da89e020d578.gz:3511% /145.827Ki, 0/s, -
 * qa/dotloop-activity202…e-a12b-90023154dd43.gz:3611% /141.754Ki, 0/s, -
 * qa/dotloop-activity202…6-8c80-b15bdb32ce77.gz:3498% /146.372Ki, 0/s, -
 * qa/dotloop-activity202…e-8499-8c896e0e165b.gz:3661% /139.838Ki, 0/s, -
 * qa/dotloop-activity202…f-9af2-41a1a91b5e97.gz:3824% /133.874Ki, 0/s, -
 * qa/dotloop-activity202…4-b556-782c2b7d90a1.gz:3674% /139.342Ki, 0/s, -
 * qa/dotloop-activity202…f-af1b-b83966dbcb35.gz:3381% /151.425Ki, 0/s, -
 * qa/dotloop-activity202…e-b527-9a29f09c55ae.gz:3453% /148.264Ki, 0/s, -
 * qa/dotloop-activity202…2-88ad-f5778dfa0075.gz:3442% /148.736Ki, 0/s, -
 * qa/dotloop-activity202…c-b64b-a5f8c82d0142.gz:3271% /156.502Ki, 0/s, -
 * qa/dotloop-activity202…b-9bf0-5828a53422ce.gz:3784% /135.292Ki, 0/s, -
 * qa/dotloop-activity202…b-a9be-175e9be4fb56.gz:3548% /144.293Ki, 0/s, -
 * qa/dotloop-activity202…f-b6a6-0e9a0e5a7759.gz:3500% /146.287Ki, 0/s, -
 * qa/dotloop-activity202…f-be45-a1bede43bc64.gz:3470% /147.513Ki, 0/s, -
 * qa/dotloop-activity202…a-950b-52dc5d73fecd.gz:3660% /139.879Ki, 0/s, -
 * qa/dotloop-activity202…0-baa1-041b7dfd55fe.gz:3508% /145.957Ki, 0/s, -
 * qa/dotloop-activity202…5-ba52-44550653296c.gz:3275% /156.309Ki, 0/s, -
 * qa/dotloop-activity202…a-a2f8-5c9333d94d70.gz:3395% /150.805Ki, 0/s, -
 * qa/dotloop-activity202…2-9705-24e586ccecf4.gz:3257% /154.717Ki, 0/s, -
 * backup/prod/webEvent/2…5-a39f-a81c17cf0e87.gz:1629% /39.922Ki, 0/s, -

Run the command 'rclone version' and share the full output of the command.

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

Syncing from S3 to DropBox

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

~/go/bin/rclone --cache-writes --dropbox-chunk-size 32Mi --low-level-retries 100 --retries 100 --transfers 20 --drive-chunk-size 1048576 --progress --dropbox-batch-mode async sync s3://org-rex-data dropbox://Systems/s3/org-rex-data --tpslimit 5

I have also tried with a batch mode of "sync".

The rclone config contents with secrets removed.

[s3]
type = s3
provider = AWS
env_auth = true

[dropbox]
type = dropbox
token = [...]

A log from the command with the -vv flag

This will be more difficult as it takes an indeterminate amount of time (hour to 4 hours-ish) and tens of thousands of files before the problem appears.

Those retries and a bad connection are going to make those numbers crazy as you'd see it in the log on the retries with debug.

ok, trying without those options... the commandline is meant for something we can leave unchecked for weeks. i'll let you know how it turns out. thanks!

Is the connection bad on the box / server you are running on?

no, this is going directly between an EC2 instance in AWS, pulling from S3, writing to DropBox... but there's still been issues

That seems rather strange then as I wouldn't expect to see a huge number of retries causing that issue.

You do have a hodge podge of things in the command you shared too.

That's for Google Drive.

That's for nothing? I'm not sure what that is.

That's super slow as I can normally do 12 tps on dropbox per an app registration so that would speed things up too.

Unfortunately, even removing those options, I am back where I was with several files thousands of percent complete, and they just sit stuck there forever;

Transferring:
 * backup/prod/webEvent/2…5-a39f-a81c17cf0e87.gz:1629% /39.922Ki, 4/s, -
 * backup/prod/webEvent/2…2-8374-a2c1ccede9fc.gz:1621% /47.695Ki, 5/s, -
 * backup/prod/webEvent/2…8-a189-9e9aaec3c4f0.gz:1736% /41.330Ki, 4/s, -
 * backup/prod/webEvent/2…c-aefb-36840a5b19b6.gz:1606% /42.997Ki, 4/s, -
 * backup/prod/webEvent/2…c-b620-b4290b001854.gz:1616% /46.439Ki, 5/s, -
 * backup/prod/webEvent/2…3-9e37-78ac0f618cfc.gz:1810% /16.840Ki, 2/s, -
 * backup/prod/webEvent/2…f-87c3-a2be2b8996e4.gz:1803% /22.302Ki, 2/s, -
 * backup/prod/webEvent/2…d-aec5-50f0893143b9.gz:1863% /27.693Ki, 3/s, -
 * backup/prod/webEvent/2…a-8818-d7e08c0e1030.gz:1904% /28.660Ki, 3/s, -

... etc.

It took 2 hours and 10 minutes for the sync to get to this point, but once those files go over 100%, they are frozen forever. I've left it for days before and it hasn't completed.

I'm going to re-run with debugging now...

Okay, it has gotten stuck again. And it seems like it is trying to upload more chunks than there are???

2022/07/27 20:40:10 DEBUG : qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-54-58-62ef2705-6509-415a-a2f8-5c9333d94d70.gz: Uploading chunk 6/1
2022/07/27 20:40:11 DEBUG : qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-57-54-0290bf9d-569a-4ac2-9705-24e586ccecf4.gz: Uploading chunk 6/1
2022/07/27 20:40:11 DEBUG : qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-29-17-b8ede84e-b748-4444-b556-782c2b7d90a1.gz: Uploading chunk 7/1
2022/07/27 20:40:11 DEBUG : qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-16-56-84494523-a808-45c1-9fca-da89e020d578.gz: Uploading chunk 7/1
2022/07/27 20:40:11 DEBUG : qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-22-46-f6412b98-def3-4586-8c80-b15bdb32ce77.gz: Uploading chunk 7/1
2022/07/27 20:40:11 DEBUG : qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-31-35-a2410dc4-9b32-4bcf-af1b-b83966dbcb35.gz: Uploading chunk 7/1
2022/07/27 20:40:12 DEBUG : qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-33-48-7d2665da-581d-426e-b527-9a29f09c55ae.gz: Uploading chunk 7/1

Can you share more than a snippet? It's really tough to guess with 8 lines of output.

apparently, "sorry, new users can not upload attachments".

If you DM me your email address I can send it there.

You can use https://pastebin.com or https://gist.github.com/

or any file sharing service (dropbox - share a link).

it is 9 megabytes so I don't think gist is the best choice. one sec.

You still have a bunch of stuff in there that doesn't do anything.

2022/07/27 18:30:00 NOTICE: S3 bucket org-rex-data: Switched region to "us-west-2" from "us-east-1"
2022/07/27 18:30:00 DEBUG : pacer: low level retry 1/2 (error BucketRegionError: incorrect region, the bucket is not in 'us-east-1' region at endpoint ''
        status code: 301, request id: , host id: )

Seems to be pointing to the wrong location.

There are number of these which generally means you have a file or directory named the same and that creates errors so you'd probably want to investigate these in the logs and on the dropbox destination.

2022/07/27 18:30:57 ERROR : attom/mls/rex-cc-1_1_20171206174455.zip: Failed to copy: upload failed: batch upload failed: path/conflict
2022/07/27 18:30:57 ERROR : attom/mls/rex-cc-1_1_20171207070105.zip: Failed to copy: upload failed: batch upload failed: path/conflict
2022/07/27 18:30:57 ERROR : attom/mls/rex-cc-1_1_20171207070105.txt: Failed to copy: upload failed: batch upload failed: path/conflict
2022/07/27 18:30:57 ERROR : attom/mls/rex-cc-1_1_20171208070100.zip: Failed to copy: upload failed: batch upload failed: path/conflict

This part confuses me a bit as I don't see anything obvious around it:

grep "qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-57-54-0290bf9d-569a-4ac2-9705-24e586ccecf4.gz" rclone.log
2022/07/27 20:39:41 DEBUG : qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-57-54-0290bf9d-569a-4ac2-9705-24e586ccecf4.gz: Uploading chunk 1/1
2022/07/27 20:39:47 DEBUG : qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-57-54-0290bf9d-569a-4ac2-9705-24e586ccecf4.gz: Uploading chunk 2/1
2022/07/27 20:39:53 DEBUG : qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-57-54-0290bf9d-569a-4ac2-9705-24e586ccecf4.gz: Uploading chunk 3/1
2022/07/27 20:39:59 DEBUG : qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-57-54-0290bf9d-569a-4ac2-9705-24e586ccecf4.gz: Uploading chunk 4/1
2022/07/27 20:40:05 DEBUG : qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-57-54-0290bf9d-569a-4ac2-9705-24e586ccecf4.gz: Uploading chunk 5/1
2022/07/27 20:40:11 DEBUG : qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-57-54-0290bf9d-569a-4ac2-9705-24e586ccecf4.gz: Uploading chunk 6/1

That keeps going on and on, which I assume is your loop but I'm not sure how you ran into that.

@ncw - any thoughts or something else to grab?

Thanks for looking. The annoying thing is, once a thread gets into that weird loop, it never makes it back out. I've let processes sit around for days and once they are in that state, the upload is frozen and they don't recover until I restart.

When I restart, a few more files will upload and then it will get stuck in that state again...

Is there a specific reason you are using the beta version as well and not the stable?

This definitely looks like a bug.

The unusual thing about the dropbox chunked uploader is that we don't break out of the loop until dropbox says it has received the last part. Rclone is never getting that so it never breaks out.

Why though? That is the question!

The files in question qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-54-58-62ef2705-6509-415a-a2f8-5c9333d94d70.gz are they maybe stored with Content-Encoding: gzip on S3? That might explain it?

Can you try just copying one of those files to local disk and see if that works.

rclone copy -vv --retries 1 --low-level-retries 1 --dump headers s3:org-rex-data/qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-54-58-62ef2705-6509-415a-a2f8-5c9333d94d70.gz .

How big are the files? Does it always go wrong with those ones?

Yes, I checked that invividual file and it is indeed;

Metadata (2)

Metadata is optional information provided as a name-value (key-value) pair. Learn more

Type Key Value
System defined Content-Encoding gzip
System defined Content-Type application/octet-stream

It succeeds, but it looks like there is a size mismatch at the end, yes!

2022/07/28 22:51:58 DEBUG : rclone: Version "v1.58.1" starting with parameters ["rclone" "copy" "-vv" "--retries" "1" "--low-level-retries" "1" "--dump" "headers" "s3:org-rex-data/qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-54-58-62ef2705-6509-415a-a2f8-5c9333d94d70.gz" "."]
2022/07/28 22:51:58 DEBUG : Creating backend with remote "s3:org-rex-data/qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-54-58-62ef2705-6509-415a-a2f8-5c9333d94d70.gz"
2022/07/28 22:51:58 DEBUG : Using config file from "/home/ubuntu/.config/rclone/rclone.conf"
2022/07/28 22:51:58 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2022/07/28 22:51:58 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : HTTP REQUEST (req 0xc00023cc00)
2022/07/28 22:51:58 DEBUG : PUT /latest/api/token HTTP/1.1
Host: 169.254.169.254
User-Agent: rclone/v1.58.1
Content-Length: 0
X-Aws-Ec2-Metadata-Token-Ttl-Seconds: 21600
Accept-Encoding: gzip

2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : HTTP RESPONSE (req 0xc00023cc00)
2022/07/28 22:51:58 DEBUG : HTTP/1.1 200 OK
Connection: close
Content-Length: 56
Content-Type: text/plain
Date: Thu, 28 Jul 2022 22:51:58 GMT
Server: EC2ws
X-Aws-Ec2-Metadata-Token-Ttl-Seconds: 21600

2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : HTTP REQUEST (req 0xc00023cf00)
2022/07/28 22:51:58 DEBUG : GET /latest/meta-data/iam/security-credentials/ HTTP/1.1
Host: 169.254.169.254
User-Agent: rclone/v1.58.1
X-Aws-Ec2-Metadata-Token: AQAEAEGffO-z9pWBgv3dOO3hzcWdKqfbIiqET0JOk4PDKMLQATR13w==
Accept-Encoding: gzip

2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : HTTP RESPONSE (req 0xc00023cf00)
2022/07/28 22:51:58 DEBUG : HTTP/1.1 200 OK
Connection: close
Content-Length: 7
Accept-Ranges: none
Content-Type: text/plain
Date: Thu, 28 Jul 2022 22:51:58 GMT
Last-Modified: Thu, 28 Jul 2022 22:15:11 GMT
Server: EC2ws
X-Aws-Ec2-Metadata-Token-Ttl-Seconds: 21600

2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : HTTP REQUEST (req 0xc00023d300)
2022/07/28 22:51:58 DEBUG : GET /latest/meta-data/iam/security-credentials/s3-sync HTTP/1.1
Host: 169.254.169.254
User-Agent: rclone/v1.58.1
X-Aws-Ec2-Metadata-Token: AQAEAEGffO-z9pWBgv3dOO3hzcWdKqfbIiqET0JOk4PDKMLQATR13w==
Accept-Encoding: gzip

2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : HTTP RESPONSE (req 0xc00023d300)
2022/07/28 22:51:58 DEBUG : HTTP/1.1 200 OK
Connection: close
Content-Length: 1442
Accept-Ranges: none
Content-Type: text/plain
Date: Thu, 28 Jul 2022 22:51:58 GMT
Last-Modified: Thu, 28 Jul 2022 22:15:11 GMT
Server: EC2ws
X-Aws-Ec2-Metadata-Token-Ttl-Seconds: 21600

2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : HTTP REQUEST (req 0xc000632400)
2022/07/28 22:51:58 DEBUG : HEAD /qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-54-58-62ef2705-6509-415a-a2f8-5c9333d94d70.gz HTTP/1.1
Host: org-rex-data.s3.us-east-1.amazonaws.com
User-Agent: rclone/v1.58.1
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20220728T225158Z
X-Amz-Security-Token: IQoJb3JpZ2luX2VjEK7//////////wEaCXVzLXdlc3QtMiJHMEUCIQCoOzfXmRxeRfNbBG26P4/rWhuV2LlKgijpfciK49nziQIgE/li44ZrlhWcEco5hYGs9Yz3LPvpwxYW9osvjB6SPSEq2wQI9///////////ARAAGgwzNTU1MDgwOTIzMDAiDNf1zqhByrla+Mg5YCqvBJIy/z1W0jGjnm1+GybNmQWNOsFHJ5mSFe2SCOFkJ5WTLX022tQmxS/nVBelGUV8H+yztWP5Zt5WwG/ub4nsc9qiuB/inAtTgGWeF0g0pzZ9OhThzrl8P860q3og+6kxi2giGuZDzPT8qDG7ZuktT171ng32O3WC8y0aTrIFeHsTARM209ujNLX3dxfHsjS3fQHOC3doh0OMrIYKSDU0I/n1nijzW6iowHle0JYNIQ3On/UE2KUhDnlWNOU7mYCteoh7xEDCc6Oeed7RuY4W052qBOjPIZ9G8KvJagvhDLolFAkRpD6rHIYjoENKFyv/hls0BixnPH7qbu55eyBolL4RMtU62PlM1bhBJ1M9fbLrrAmcuw0CUbeQGEn/NjTO/gCyacxmNimbVZj7fuMOn1I256IdWLHY8NXAAQi0oM6FbyE2oXeppxiNKy0c9nf8rgwRDGK+AWe730KcXoEacBcJrB/IkgHMFAw6zdlLCY6VWeRNHvdqz1sWYl743+LPAvrw5Qekq+Ef0k0XrbsAWN+n5uaHeBOV2d+Xd9qA9BQ9ebObhb+AFNEgpZqMiV7KCR2IDPconVzkk1j2xxygiH7Wkphx038SlfHFDeofQMd8Xbof6CIJLmStG3shRcBDjG2k3tnImtRj2w35Pv6sEnhqneY99N+yRQR3Q/F4pdQyGnkXPF/Vdi/JQSotHChgBK+d8yx9vczmiZjPNOB6ZyB1c3gjtNXwvvUSmO8Mi5ow75SMlwY6qQEq2r17YMgHFV+Z9e4vVvzsgEJlw5Y7ruzEzmXwH79iQ/lufb7hEVMoGaWqhKGp35caD3no7cAVTwVG8vFKOQcPPiooMCqcPLqC/Am+pIKbf14X4lEy2uUwxGlc2iFX/0F+3rXAgkOBeEGCAk85KMLBNTPPL85MSG1QEH5ypaCn5usS4RMCKkFmkYUYT3ajuXnwY4aQw4wFsxxbRU61LoWTySHIZ0Fe2/GZ

2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : HTTP RESPONSE (req 0xc000632400)
2022/07/28 22:51:58 DEBUG : HTTP/1.1 301 Moved Permanently
Connection: close
Content-Type: application/xml
Date: Thu, 28 Jul 2022 22:51:57 GMT
Server: AmazonS3
X-Amz-Bucket-Region: us-west-2
X-Amz-Id-2: UUTQRc17BA/50XjX9Dj+bZzRfZRM1fBpCF/vW6/2b/3prrfdMHBVy+Zy2irQoxmtKBUX+6ugzx4=
X-Amz-Request-Id: 4DG7J5RRH9W9H84A

2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : HTTP REQUEST (req 0xc000633400)
2022/07/28 22:51:58 DEBUG : GET /org-rex-data?location= HTTP/1.1
Host: s3.us-east-1.amazonaws.com
User-Agent: rclone/v1.58.1
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20220728T225158Z
X-Amz-Security-Token: IQoJb3JpZ2luX2VjEK7//////////wEaCXVzLXdlc3QtMiJHMEUCIQCoOzfXmRxeRfNbBG26P4/rWhuV2LlKgijpfciK49nziQIgE/li44ZrlhWcEco5hYGs9Yz3LPvpwxYW9osvjB6SPSEq2wQI9///////////ARAAGgwzNTU1MDgwOTIzMDAiDNf1zqhByrla+Mg5YCqvBJIy/z1W0jGjnm1+GybNmQWNOsFHJ5mSFe2SCOFkJ5WTLX022tQmxS/nVBelGUV8H+yztWP5Zt5WwG/ub4nsc9qiuB/inAtTgGWeF0g0pzZ9OhThzrl8P860q3og+6kxi2giGuZDzPT8qDG7ZuktT171ng32O3WC8y0aTrIFeHsTARM209ujNLX3dxfHsjS3fQHOC3doh0OMrIYKSDU0I/n1nijzW6iowHle0JYNIQ3On/UE2KUhDnlWNOU7mYCteoh7xEDCc6Oeed7RuY4W052qBOjPIZ9G8KvJagvhDLolFAkRpD6rHIYjoENKFyv/hls0BixnPH7qbu55eyBolL4RMtU62PlM1bhBJ1M9fbLrrAmcuw0CUbeQGEn/NjTO/gCyacxmNimbVZj7fuMOn1I256IdWLHY8NXAAQi0oM6FbyE2oXeppxiNKy0c9nf8rgwRDGK+AWe730KcXoEacBcJrB/IkgHMFAw6zdlLCY6VWeRNHvdqz1sWYl743+LPAvrw5Qekq+Ef0k0XrbsAWN+n5uaHeBOV2d+Xd9qA9BQ9ebObhb+AFNEgpZqMiV7KCR2IDPconVzkk1j2xxygiH7Wkphx038SlfHFDeofQMd8Xbof6CIJLmStG3shRcBDjG2k3tnImtRj2w35Pv6sEnhqneY99N+yRQR3Q/F4pdQyGnkXPF/Vdi/JQSotHChgBK+d8yx9vczmiZjPNOB6ZyB1c3gjtNXwvvUSmO8Mi5ow75SMlwY6qQEq2r17YMgHFV+Z9e4vVvzsgEJlw5Y7ruzEzmXwH79iQ/lufb7hEVMoGaWqhKGp35caD3no7cAVTwVG8vFKOQcPPiooMCqcPLqC/Am+pIKbf14X4lEy2uUwxGlc2iFX/0F+3rXAgkOBeEGCAk85KMLBNTPPL85MSG1QEH5ypaCn5usS4RMCKkFmkYUYT3ajuXnwY4aQw4wFsxxbRU61LoWTySHIZ0Fe2/GZ
Accept-Encoding: gzip

2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : HTTP RESPONSE (req 0xc000633400)
2022/07/28 22:51:58 DEBUG : HTTP/1.1 200 OK
Transfer-Encoding: chunked
Content-Type: application/xml
Date: Thu, 28 Jul 2022 22:51:59 GMT
Server: AmazonS3
X-Amz-Id-2: +ISPOOjTI/HSFikkJCsEfu+t9LjbybFk9XfshOKdSMbsiU+7P3jATUT684jvKmTWz+Q3LsyNeRc=
X-Amz-Request-Id: 4DG6NRB4WHD20J13

2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 NOTICE: S3 bucket org-rex-data path qa/dotloop-activity2020/03/03/03: Switched region to "us-west-2" from "us-east-1"
2022/07/28 22:51:58 DEBUG : pacer: low level retry 1/2 (error BucketRegionError: incorrect region, the bucket is not in 'us-east-1' region at endpoint ''
	status code: 301, request id: , host id: )
2022/07/28 22:51:58 DEBUG : pacer: Rate limited, increasing sleep to 10ms
2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : HTTP REQUEST (req 0xc000794100)
2022/07/28 22:51:58 DEBUG : PUT /latest/api/token HTTP/1.1
Host: 169.254.169.254
User-Agent: rclone/v1.58.1
Content-Length: 0
X-Aws-Ec2-Metadata-Token-Ttl-Seconds: 21600
Accept-Encoding: gzip

2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : HTTP RESPONSE (req 0xc000794100)
2022/07/28 22:51:58 DEBUG : HTTP/1.1 200 OK
Connection: close
Content-Length: 56
Content-Type: text/plain
Date: Thu, 28 Jul 2022 22:51:58 GMT
Server: EC2ws
X-Aws-Ec2-Metadata-Token-Ttl-Seconds: 21600

2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : HTTP REQUEST (req 0xc00023c800)
2022/07/28 22:51:58 DEBUG : GET /latest/meta-data/iam/security-credentials/ HTTP/1.1
Host: 169.254.169.254
User-Agent: rclone/v1.58.1
X-Aws-Ec2-Metadata-Token: AQAEAEGffO9kJ0IkmkDTFTtKvZJXrfv7xe0nZvi4dpo3hQm-zL5GTA==
Accept-Encoding: gzip

2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : HTTP RESPONSE (req 0xc00023c800)
2022/07/28 22:51:58 DEBUG : HTTP/1.1 200 OK
Connection: close
Content-Length: 7
Accept-Ranges: none
Content-Type: text/plain
Date: Thu, 28 Jul 2022 22:51:58 GMT
Last-Modified: Thu, 28 Jul 2022 22:15:11 GMT
Server: EC2ws
X-Aws-Ec2-Metadata-Token-Ttl-Seconds: 21600

2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : HTTP REQUEST (req 0xc000794400)
2022/07/28 22:51:58 DEBUG : GET /latest/meta-data/iam/security-credentials/s3-sync HTTP/1.1
Host: 169.254.169.254
User-Agent: rclone/v1.58.1
X-Aws-Ec2-Metadata-Token: AQAEAEGffO9kJ0IkmkDTFTtKvZJXrfv7xe0nZvi4dpo3hQm-zL5GTA==
Accept-Encoding: gzip

2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : HTTP RESPONSE (req 0xc000794400)
2022/07/28 22:51:58 DEBUG : HTTP/1.1 200 OK
Connection: close
Content-Length: 1442
Accept-Ranges: none
Content-Type: text/plain
Date: Thu, 28 Jul 2022 22:51:58 GMT
Last-Modified: Thu, 28 Jul 2022 22:15:11 GMT
Server: EC2ws
X-Aws-Ec2-Metadata-Token-Ttl-Seconds: 21600

2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : HTTP REQUEST (req 0xc00023cb00)
2022/07/28 22:51:58 DEBUG : HEAD /qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-54-58-62ef2705-6509-415a-a2f8-5c9333d94d70.gz HTTP/1.1
Host: org-rex-data.s3.us-west-2.amazonaws.com
User-Agent: rclone/v1.58.1
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20220728T225158Z
X-Amz-Security-Token: IQoJb3JpZ2luX2VjEK7//////////wEaCXVzLXdlc3QtMiJHMEUCIQCoOzfXmRxeRfNbBG26P4/rWhuV2LlKgijpfciK49nziQIgE/li44ZrlhWcEco5hYGs9Yz3LPvpwxYW9osvjB6SPSEq2wQI9///////////ARAAGgwzNTU1MDgwOTIzMDAiDNf1zqhByrla+Mg5YCqvBJIy/z1W0jGjnm1+GybNmQWNOsFHJ5mSFe2SCOFkJ5WTLX022tQmxS/nVBelGUV8H+yztWP5Zt5WwG/ub4nsc9qiuB/inAtTgGWeF0g0pzZ9OhThzrl8P860q3og+6kxi2giGuZDzPT8qDG7ZuktT171ng32O3WC8y0aTrIFeHsTARM209ujNLX3dxfHsjS3fQHOC3doh0OMrIYKSDU0I/n1nijzW6iowHle0JYNIQ3On/UE2KUhDnlWNOU7mYCteoh7xEDCc6Oeed7RuY4W052qBOjPIZ9G8KvJagvhDLolFAkRpD6rHIYjoENKFyv/hls0BixnPH7qbu55eyBolL4RMtU62PlM1bhBJ1M9fbLrrAmcuw0CUbeQGEn/NjTO/gCyacxmNimbVZj7fuMOn1I256IdWLHY8NXAAQi0oM6FbyE2oXeppxiNKy0c9nf8rgwRDGK+AWe730KcXoEacBcJrB/IkgHMFAw6zdlLCY6VWeRNHvdqz1sWYl743+LPAvrw5Qekq+Ef0k0XrbsAWN+n5uaHeBOV2d+Xd9qA9BQ9ebObhb+AFNEgpZqMiV7KCR2IDPconVzkk1j2xxygiH7Wkphx038SlfHFDeofQMd8Xbof6CIJLmStG3shRcBDjG2k3tnImtRj2w35Pv6sEnhqneY99N+yRQR3Q/F4pdQyGnkXPF/Vdi/JQSotHChgBK+d8yx9vczmiZjPNOB6ZyB1c3gjtNXwvvUSmO8Mi5ow75SMlwY6qQEq2r17YMgHFV+Z9e4vVvzsgEJlw5Y7ruzEzmXwH79iQ/lufb7hEVMoGaWqhKGp35caD3no7cAVTwVG8vFKOQcPPiooMCqcPLqC/Am+pIKbf14X4lEy2uUwxGlc2iFX/0F+3rXAgkOBeEGCAk85KMLBNTPPL85MSG1QEH5ypaCn5usS4RMCKkFmkYUYT3ajuXnwY4aQw4wFsxxbRU61LoWTySHIZ0Fe2/GZ

2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : HTTP RESPONSE (req 0xc00023cb00)
2022/07/28 22:51:58 DEBUG : HTTP/1.1 200 OK
Content-Length: 154424
Accept-Ranges: bytes
Content-Encoding: gzip
Content-Type: application/octet-stream
Date: Thu, 28 Jul 2022 22:51:59 GMT
Etag: "f69f9eeef51c611ad652b9f59e6385ed"
Last-Modified: Tue, 03 Mar 2020 03:57:55 GMT
Server: AmazonS3
X-Amz-Id-2: VIp+qDwLkRyRdUuPRu3Eq2eudFgmhSvl1/qh8xzENTbMnn5GNctnxF+dRgGQpM/msftZKzlgpmA=
X-Amz-Request-Id: 4DGC1AN3K121JGCS
X-Amz-Version-Id: POlo_HYaVHclkLu2hyg9Vj7MIXkA_B11

2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : pacer: Reducing sleep to 0s
2022/07/28 22:51:58 DEBUG : fs cache: adding new entry for parent of "s3:org-rex-data/qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-54-58-62ef2705-6509-415a-a2f8-5c9333d94d70.gz", "s3:org-rex-data/qa/dotloop-activity2020/03/03/03"
2022/07/28 22:51:58 DEBUG : Creating backend with remote "."
2022/07/28 22:51:58 DEBUG : fs cache: renaming cache item "." to be canonical "/home/ubuntu"
2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : HTTP REQUEST (req 0xc000794800)
2022/07/28 22:51:58 DEBUG : HEAD /qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-54-58-62ef2705-6509-415a-a2f8-5c9333d94d70.gz HTTP/1.1
Host: org-rex-data.s3.us-west-2.amazonaws.com
User-Agent: rclone/v1.58.1
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20220728T225158Z
X-Amz-Security-Token: IQoJb3JpZ2luX2VjEK7//////////wEaCXVzLXdlc3QtMiJHMEUCIQCoOzfXmRxeRfNbBG26P4/rWhuV2LlKgijpfciK49nziQIgE/li44ZrlhWcEco5hYGs9Yz3LPvpwxYW9osvjB6SPSEq2wQI9///////////ARAAGgwzNTU1MDgwOTIzMDAiDNf1zqhByrla+Mg5YCqvBJIy/z1W0jGjnm1+GybNmQWNOsFHJ5mSFe2SCOFkJ5WTLX022tQmxS/nVBelGUV8H+yztWP5Zt5WwG/ub4nsc9qiuB/inAtTgGWeF0g0pzZ9OhThzrl8P860q3og+6kxi2giGuZDzPT8qDG7ZuktT171ng32O3WC8y0aTrIFeHsTARM209ujNLX3dxfHsjS3fQHOC3doh0OMrIYKSDU0I/n1nijzW6iowHle0JYNIQ3On/UE2KUhDnlWNOU7mYCteoh7xEDCc6Oeed7RuY4W052qBOjPIZ9G8KvJagvhDLolFAkRpD6rHIYjoENKFyv/hls0BixnPH7qbu55eyBolL4RMtU62PlM1bhBJ1M9fbLrrAmcuw0CUbeQGEn/NjTO/gCyacxmNimbVZj7fuMOn1I256IdWLHY8NXAAQi0oM6FbyE2oXeppxiNKy0c9nf8rgwRDGK+AWe730KcXoEacBcJrB/IkgHMFAw6zdlLCY6VWeRNHvdqz1sWYl743+LPAvrw5Qekq+Ef0k0XrbsAWN+n5uaHeBOV2d+Xd9qA9BQ9ebObhb+AFNEgpZqMiV7KCR2IDPconVzkk1j2xxygiH7Wkphx038SlfHFDeofQMd8Xbof6CIJLmStG3shRcBDjG2k3tnImtRj2w35Pv6sEnhqneY99N+yRQR3Q/F4pdQyGnkXPF/Vdi/JQSotHChgBK+d8yx9vczmiZjPNOB6ZyB1c3gjtNXwvvUSmO8Mi5ow75SMlwY6qQEq2r17YMgHFV+Z9e4vVvzsgEJlw5Y7ruzEzmXwH79iQ/lufb7hEVMoGaWqhKGp35caD3no7cAVTwVG8vFKOQcPPiooMCqcPLqC/Am+pIKbf14X4lEy2uUwxGlc2iFX/0F+3rXAgkOBeEGCAk85KMLBNTPPL85MSG1QEH5ypaCn5usS4RMCKkFmkYUYT3ajuXnwY4aQw4wFsxxbRU61LoWTySHIZ0Fe2/GZ

2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : HTTP RESPONSE (req 0xc000794800)
2022/07/28 22:51:58 DEBUG : HTTP/1.1 200 OK
Content-Length: 154424
Accept-Ranges: bytes
Content-Encoding: gzip
Content-Type: application/octet-stream
Date: Thu, 28 Jul 2022 22:51:59 GMT
Etag: "f69f9eeef51c611ad652b9f59e6385ed"
Last-Modified: Tue, 03 Mar 2020 03:57:55 GMT
Server: AmazonS3
X-Amz-Id-2: uX7LVi4Db/cYfCH0nO8QSyMT44YtmNS64QJ82aaxEVILk7FH7u8fI1U2iK1coikKPdn0J5EdytM=
X-Amz-Request-Id: 4DG3TSB6BSVK29C0
X-Amz-Version-Id: POlo_HYaVHclkLu2hyg9Vj7MIXkA_B11

2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : qa-dotloop-activity-1-2020-03-03-03-54-58-62ef2705-6509-415a-a2f8-5c9333d94d70.gz: Need to transfer - File not found at Destination
2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : HTTP REQUEST (req 0xc000718e00)
2022/07/28 22:51:58 DEBUG : GET /qa/dotloop-activity2020/03/03/03/qa-dotloop-activity-1-2020-03-03-03-54-58-62ef2705-6509-415a-a2f8-5c9333d94d70.gz HTTP/1.1
Host: org-rex-data.s3.us-west-2.amazonaws.com
User-Agent: rclone/v1.58.1
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20220728T225158Z
X-Amz-Security-Token: IQoJb3JpZ2luX2VjEK7//////////wEaCXVzLXdlc3QtMiJHMEUCIQCoOzfXmRxeRfNbBG26P4/rWhuV2LlKgijpfciK49nziQIgE/li44ZrlhWcEco5hYGs9Yz3LPvpwxYW9osvjB6SPSEq2wQI9///////////ARAAGgwzNTU1MDgwOTIzMDAiDNf1zqhByrla+Mg5YCqvBJIy/z1W0jGjnm1+GybNmQWNOsFHJ5mSFe2SCOFkJ5WTLX022tQmxS/nVBelGUV8H+yztWP5Zt5WwG/ub4nsc9qiuB/inAtTgGWeF0g0pzZ9OhThzrl8P860q3og+6kxi2giGuZDzPT8qDG7ZuktT171ng32O3WC8y0aTrIFeHsTARM209ujNLX3dxfHsjS3fQHOC3doh0OMrIYKSDU0I/n1nijzW6iowHle0JYNIQ3On/UE2KUhDnlWNOU7mYCteoh7xEDCc6Oeed7RuY4W052qBOjPIZ9G8KvJagvhDLolFAkRpD6rHIYjoENKFyv/hls0BixnPH7qbu55eyBolL4RMtU62PlM1bhBJ1M9fbLrrAmcuw0CUbeQGEn/NjTO/gCyacxmNimbVZj7fuMOn1I256IdWLHY8NXAAQi0oM6FbyE2oXeppxiNKy0c9nf8rgwRDGK+AWe730KcXoEacBcJrB/IkgHMFAw6zdlLCY6VWeRNHvdqz1sWYl743+LPAvrw5Qekq+Ef0k0XrbsAWN+n5uaHeBOV2d+Xd9qA9BQ9ebObhb+AFNEgpZqMiV7KCR2IDPconVzkk1j2xxygiH7Wkphx038SlfHFDeofQMd8Xbof6CIJLmStG3shRcBDjG2k3tnImtRj2w35Pv6sEnhqneY99N+yRQR3Q/F4pdQyGnkXPF/Vdi/JQSotHChgBK+d8yx9vczmiZjPNOB6ZyB1c3gjtNXwvvUSmO8Mi5ow75SMlwY6qQEq2r17YMgHFV+Z9e4vVvzsgEJlw5Y7ruzEzmXwH79iQ/lufb7hEVMoGaWqhKGp35caD3no7cAVTwVG8vFKOQcPPiooMCqcPLqC/Am+pIKbf14X4lEy2uUwxGlc2iFX/0F+3rXAgkOBeEGCAk85KMLBNTPPL85MSG1QEH5ypaCn5usS4RMCKkFmkYUYT3ajuXnwY4aQw4wFsxxbRU61LoWTySHIZ0Fe2/GZ
Accept-Encoding: gzip

2022/07/28 22:51:58 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 DEBUG : HTTP RESPONSE (req 0xc000718e00)
2022/07/28 22:51:58 DEBUG : HTTP/1.1 200 OK
Accept-Ranges: bytes
Content-Type: application/octet-stream
Date: Thu, 28 Jul 2022 22:51:59 GMT
Etag: "f69f9eeef51c611ad652b9f59e6385ed"
Last-Modified: Tue, 03 Mar 2020 03:57:55 GMT
Server: AmazonS3
X-Amz-Id-2: S32FuKXck/gsiQwukKr3SlRjYC5vZnLQDVH2D4QKHTjewoUu9bUTywf6sUPG+qqZ6BvJmcSzT6A=
X-Amz-Request-Id: 4DGC29DZ109E3B1F
X-Amz-Version-Id: POlo_HYaVHclkLu2hyg9Vj7MIXkA_B11

2022/07/28 22:51:58 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/07/28 22:51:58 ERROR : qa-dotloop-activity-1-2020-03-03-03-54-58-62ef2705-6509-415a-a2f8-5c9333d94d70.gz: corrupted on transfer: sizes differ 154424 vs 5242947
2022/07/28 22:51:58 INFO  : qa-dotloop-activity-1-2020-03-03-03-54-58-62ef2705-6509-415a-a2f8-5c9333d94d70.gz: Removing failed copy
2022/07/28 22:51:58 ERROR : Attempt 1/1 failed with 1 errors and: corrupted on transfer: sizes differ 154424 vs 5242947
2022/07/28 22:51:58 INFO  : 
Transferred:   	    5.000 MiB / 5.000 MiB, 100%, 0 B/s, ETA -
Errors:                 1 (retrying may help)
Elapsed time:         0.7s

2022/07/28 22:51:58 DEBUG : 10 go routines active
2022/07/28 22:51:58 Failed to copy: corrupted on transfer: sizes differ 154424 vs 5242947

That one was 156KiB. I think that it processes a dozen or so of these fine each run and then freezes. I will run it again and post a new logfile.

hmm... that logfile is larger (14 megs) and does not contain a reference to the file that failed earlier:

ubuntu@ip-10-2-225-95:~$ grep 2020-03-03-03-54-58 rclone.3.log
ubuntu@ip-10-2-225-95:~$ du -hs rclone.3.log
14M     rclone.3.log

is rclone syncing the files in a non-deterministic order?