6 minute wait for 0 byte transfer

Help and Support
1

STOP and READ USE THIS TEMPLATE NO EXCEPTIONS - By not using this, you waste your time, our time and really hate puppies. Please remove these two lines and that will confirm you have read them.

What is the problem you are having with rclone?

Looking for cause of slow 0 Byte Transfers that take minutes to complete.

It seems that in every case where rclone reports, "fs cache: renaming cache item", it returns several minutes later with, "S3 bucket frank-prod-origin path published/2022/8/18/7: Waiting for checks to finish".

Neither the CPU nor the network are very busy, yet the process seems to be waiting for something external. Is there a way that I can further inspect where rclone seems to be stuck?

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

rclone v1.62.2

os/version: ubuntu 18.04 (64 bit)
os/kernel: 4.15.0-144-generic (x86_64)
os/type: linux
os/arch: amd64
go/version: go1.20.2
go/linking: static
go/tags: none

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

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

rclone copy -M --max-backlog=8 --transfers 6 --checkers 6 --buffer-size 256M --progress --stats 5s --fast-list --log-level DEBUG --log-file /home/CORP/alex/tmp/rclone_mediadownloads.20230706_224414 /mnt/storage/frank/published/2022/8/18/7/ MinIO:frank-prod-origin/published/2022/8/18/7/ --include *.mp4

The rclone config contents with secrets removed.

[MinIO]
type = s3
provider = Minio
access_key_id = REDACTED
secret_access_key = REDACTED
endpoint = http://192.168.1.200/
acl = public-read-write
no_check_bucket = true
upload_cutoff = 16M
copy_cutoff = 16M
chunk_size = 5M
upload_concurrency = 8
max_upload_parts = 10000

A log from the command with the -vv flag

2023/07/06 22:44:14 DEBUG : rclone: Version "v1.62.2" starting with parameters ["rclone" "copy" "-M" "--max-backlog=8" "--transfers" "6" "--checkers" "6" "--buffer-size" "256M" "--progress" "--stats" "5s" "--fast-list" "--log-level" "DEBUG" "--log-file" "/home/CORP/alex/tmp/rclone_mediadownloads.20230706_224414" "/mnt/storage/frank/published/2022/8/18/7/" "MinIO:frank-prod-origin/published/2022/8/18/7/" "--include" "*.mp4"]
2023/07/06 22:44:14 DEBUG : Creating backend with remote "/mnt/storage/frank/published/2022/8/18/7/"
2023/07/06 22:44:14 DEBUG : Using config file from "/home/CORP/alex/.config/rclone/rclone.conf"
2023/07/06 22:44:14 DEBUG : fs cache: renaming cache item "/mnt/storage/frank/published/2022/8/18/7/" to be canonical "/mnt/storage/frank/published/2022/8/18/7"
2023/07/06 22:44:14 DEBUG : Creating backend with remote "MinIO:frank-prod-origin/published/2022/8/18/7/"
2023/07/06 22:44:14 DEBUG : Resolving service "s3" region "us-east-1"
2023/07/06 22:44:14 DEBUG : fs cache: renaming cache item "MinIO:frank-prod-origin/published/2022/8/18/7/" to be canonical "MinIO:frank-prod-origin/published/2022/8/18/7"
2023/07/06 22:50:22 DEBUG : S3 bucket frank-prod-origin path published/2022/8/18/7: Waiting for checks to finish
2023/07/06 22:50:22 DEBUG : S3 bucket frank-prod-origin path published/2022/8/18/7: Waiting for transfers to finish
2023/07/06 22:50:22 DEBUG : 16x9__trimmed_70951968_156296838_H264_WII_650.mp4: md5 = d3935d84371780568b5369aa90ab79e0 OK
2023/07/06 22:50:22 INFO  : 16x9__trimmed_70951968_156296838_H264_WII_650.mp4: Copied (new)
2023/07/06 22:50:22 DEBUG : 4x3_70981629_156326721_H264_WII_650.mp4: md5 = dd91279597639e666c336e8933d104d7 OK
2023/07/06 22:50:22 INFO  : 4x3_70981629_156326721_H264_WII_650.mp4: Copied (new)
2023/07/06 22:50:22 DEBUG : 16x9_70962848_156307774_H264_1000_156307999_video.mp4: md5 = be7f02c719895d210a2a61c70bc2bf8b OK
2023/07/06 22:50:22 INFO  : 16x9_70962848_156307774_H264_1000_156307999_video.mp4: Copied (new)
2023/07/06 22:50:22 DEBUG : 0182b41c-3c2c-15a0-356f-00eea02cd909_1000068324865_H264_1000_1000068325010_video.mp4: md5 = 7d674769436e27fd5ffca4b2ed0e725d OK
2023/07/06 22:50:22 INFO  : 0182b41c-3c2c-15a0-356f-00eea02cd909_1000068324865_H264_1000_1000068325010_video.mp4: Copied (new)
2023/07/06 22:50:22 DEBUG : 4x3__trimmed_70963542_156308408_H264_2000_156309612_video.mp4: md5 = 858ae360f36a7916b8f5146a11fbe873 OK
2023/07/06 22:50:22 INFO  : 4x3__trimmed_70963542_156308408_H264_2000_156309612_video.mp4: Copied (new)
2023/07/06 22:50:23 DEBUG : 0182b41e-9414-4f4b-356f-00a5531bd9d0_1000068324934_H264_200.mp4: md5 = 4fcd7d2b0c28e5a392c427aa7f14f91b OK
2023/07/06 22:50:23 INFO  : 0182b41e-9414-4f4b-356f-00a5531bd9d0_1000068324934_H264_200.mp4: Copied (new)
2023/07/06 22:50:23 DEBUG : 4x3_70951174_156295803_H264_200.mp4: md5 = bd490b9a05a0318c6bc9d48e0c513afb OK
2023/07/06 22:50:23 INFO  : 4x3_70951174_156295803_H264_200.mp4: Copied (new)
2023/07/06 22:50:23 INFO  :
Transferred:       11.718 MiB / 11.718 MiB, 100%, 0 B/s, ETA -
Transferred:            7 / 7, 100%
Elapsed time:       6m8.8s
2

rclone copy is listing both source and destination before transfers start. In your case it takes 6 min which is nothing unusual - for large remotes it can take much longer. How many files/folders is in your remote? Millions?

Too see what is going on in more details run your copy command with additional flag --dump headers

1 Like
3

Fully agree with @kapitainsky with a little addition:

The transfers may start earlier if you remove --fast-list, which isn't always the fastest option.

More info here:
https://rclone.org/docs/#checkers-n
https://rclone.org/docs/#fast-list
https://rclone.org/docs/#dump-headers

4

Yes, this remote is easily more than a million files and we intend to continue adding to it. I suppose what we need is a blind copy to seed storage followed by a longer running rclone process to resolve differences and correct transfer errors.

Is there a flag we can use to disable checksums and use rclone more like remote-copy (rcp)?

5

--s3-disable-checksum

fwiw, if possible, let rclone run the first time with checksums.
valuable down the road for rclone check to catch bit-rot, ransomware, etc...

and for subsequent runs, find ways to reduce the number of checks.

one possible way, --max-age=24h
any source file older than 24 hours will not be checked or copied to the dest, no api calls to minio server.

1 Like
6

Agree with hash comment - I would never turn it off.

If your test is indicative of your usage then as per docs:

If you are only copying a small number of files into a big repository then using --no-traverse is a good idea. This finds objects directly instead of through directory listings. You can do a "top-up" sync very cheaply by using --max-age and --no-traverse to copy only recent files

1 Like
7

... and if restarting the copy during seeding you may want to use --size-only or --checksum as suggested here:

https://rclone.org/s3/#avoiding-head-requests-to-read-the-modification-time

and then check the modification times in the final check/correction run.

1 Like
8

Adding --no-traverse has taken response times from several minutes to 0.1 seconds. I'll continue to test but so far that's looking pretty good.

9

because you are transferring only few files to destination with many files. Read documentation and adjust flags based on your typical use case. Unless your workload is extremely demanding most often it simply does not make sense to optimise things for sake of pursuing some optimal parameters. Also because they do not exist.

--no-traverse is good example - it is double edge sword - if it is few too many you gain bigger the gap is but if equation changes and you transfer many files you will suffer with sometimes extreme performance degradation

1 Like
10

Yes, when we began and there were a few GBs in the remote object store and several PetaB local. The solution has changed now that the remote store has several PetaB and my transfers are pulling from many directories, each with only a few GB per directory; the last 2PB spread across ~20K discrete directories.

1 Like
11

I just wanted to highlight that there is no magic bullet - all depends - on many things:)

12

Indeed, now that I have an approach that seems to outperform, I will stop the currently slower running tasks and replace them with equivalents that use --checksum.
Unfortunately, the configuration of my MinIO instance is such that updating last-mod-time results in a 403. That's very unfortunate but my work around has been to include --no-update-modtime.

1 Like
13

you should also try the latest beta - there are some significant optimisations for BIG storages:

We see more and more serious data volumes involved - and it brings unique challenges.

14

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