Swift sync --checksum calls HEAD on every object so is very slow

What is the problem you are having with rclone?

I want to use rclone sync to keep two large swift containers up to date; I want sync --checksum to use the container listing, rather than doing a HEAD on every object in the container. Despite the container listing containing correct 'hash' info, rclone is still doing a HEAD every time, which is slow.

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

mvernon@ms-fe1012:~$ ./rclone version
rclone v1.58.0
- os/version: debian 11.3 (64 bit)
- os/kernel: 5.10.0-13-amd64 (x86_64)
- os/type: linux
- os/arch: amd64
- go/version: go1.17.8
- go/linking: static
- go/tags: none

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

Openstack Swift (self-hosted)

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

./rclone sync --checksum --dry-run eqiad:wikipedia-testcommons-local-public codfw:wikipedia-testcommons-local-public --include '0/01/3a1e15ca-ee52-118e-65dc-705273b6c7af.jpg' -vv --dump requests,responses --log-file=rclone-sync.log

The rclone config contents with secrets removed.

[eqiad]
type = swift
env_auth = false
user = REDACTED
key = SECRET
auth = http://ms-fe.svc.eqiad.wmnet/auth/v1.0

[codfw]
type = swift
env_auth = false
user = REDACTED
key = SECRET
auth = https://ms-fe.svc.codfw.wmnet/auth/v1.0

A log from the command with the -vv flag

Here are the key highlights (the whole lot is a bit large to paste here), showing rclone getting a listing from the remotes, that listing containing the md5 hash, and then rclone still calling HEAD...

2022/04/21 10:33:54 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/04/21 10:33:54 DEBUG : HTTP REQUEST (req 0xc000efe200)
2022/04/21 10:33:54 DEBUG : GET /v1/AUTH_mw/wikipedia-testcommons-local-public?delimiter=%2F&format=json&limit=1000&prefix=0%2F01%2F HTTP/1.1
Host: ms-fe.svc.codfw.wmnet
User-Agent: rclone/v1.58.0
Transfer-Encoding: chunked
X-Auth-Token: XXXX
Accept-Encoding: gzip

0

2022/04/21 10:33:54 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/04/21 10:33:54 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/04/21 10:33:54 DEBUG : HTTP REQUEST (req 0xc00013f100)
2022/04/21 10:33:54 DEBUG : GET /v1/AUTH_mw/wikipedia-testcommons-local-public?delimiter=%2F&format=json&limit=1000&prefix=0%2F01%2F HTTP/1.1
Host: ms-fe.svc.eqiad.wmnet
User-Agent: rclone/v1.58.0
Transfer-Encoding: chunked
X-Auth-Token: XXXX
Accept-Encoding: gzip

0

2022/04/21 10:33:54 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/04/21 10:33:54 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/04/21 10:33:54 DEBUG : HTTP RESPONSE (req 0xc00013f100)
2022/04/21 10:33:54 DEBUG : HTTP/1.1 200 OK
Content-Length: 198
Accept-Ranges: bytes
Content-Type: application/json; charset=utf-8
Date: Thu, 21 Apr 2022 10:33:54 GMT
Last-Modified: Sat, 18 Apr 2020 00:10:57 GMT
X-Container-Bytes-Used: 1141507372
X-Container-Object-Count: 474
X-Container-Read: mw:thumbor,mw:media,.r:*
X-Container-Write: mw:thumbor,mw:media
X-Openstack-Request-Id: tx4286998d61c24aa6997dd-0062613312
X-Storage-Policy: standard
X-Timestamp: 1546886239.26298
X-Trans-Id: tx4286998d61c24aa6997dd-0062613312

[{"hash": "7461d99daf3f1e0742401ff05ed0fe0b", "last_modified": "2022-01-25T20:55:48.225080", "bytes": 1000578, "name": "0/01/3a1e15ca-ee52-118e-65dc-705273b6c7af.jpg", "content_type": "image/jpeg"}]
2022/04/21 10:33:54 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/04/21 10:33:54 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/04/21 10:33:54 DEBUG : HTTP RESPONSE (req 0xc000efe200)
2022/04/21 10:33:54 DEBUG : HTTP/1.1 200 OK
Content-Length: 198
Accept-Ranges: bytes
Content-Type: application/json; charset=utf-8
Date: Thu, 21 Apr 2022 10:33:54 GMT
Last-Modified: Sat, 18 Apr 2020 00:10:57 GMT
X-Container-Bytes-Used: 1141507372
X-Container-Object-Count: 474
X-Container-Read: mw:thumbor,mw:media,.r:*
X-Container-Write: mw:thumbor,mw:media
X-Storage-Policy: standard
X-Timestamp: 1546886239.61129
X-Trans-Id: tx663b73681cb748c290101-0062613312

[{"hash": "7461d99daf3f1e0742401ff05ed0fe0b", "last_modified": "2022-01-25T20:55:48.451190", "bytes": 1000578, "name": "0/01/3a1e15ca-ee52-118e-65dc-705273b6c7af.jpg", "content_type": "image/jpeg"}]
2022/04/21 10:33:54 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/04/21 10:33:54 DEBUG : Swift container wikipedia-testcommons-local-public: Waiting for checks to finish
2022/04/21 10:33:54 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/04/21 10:33:54 DEBUG : HTTP REQUEST (req 0xc000efe400)
2022/04/21 10:33:54 DEBUG : HEAD /v1/AUTH_mw/wikipedia-testcommons-local-public/0/01/3a1e15ca-ee52-118e-65dc-705273b6c7af.jpg HTTP/1.1
Host: ms-fe.svc.eqiad.wmnet
User-Agent: rclone/v1.58.0
Transfer-Encoding: chunked
X-Auth-Token: XXXX

0

2022/04/21 10:33:54 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/04/21 10:33:54 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/04/21 10:33:54 DEBUG : HTTP REQUEST (req 0xc00013fd00)
2022/04/21 10:33:54 DEBUG : HEAD /v1/AUTH_mw/wikipedia-testcommons-local-public/0/01/3a1e15ca-ee52-118e-65dc-705273b6c7af.jpg HTTP/1.1
Host: ms-fe.svc.codfw.wmnet
User-Agent: rclone/v1.58.0
Transfer-Encoding: chunked
X-Auth-Token: XXXX

0

2022/04/21 10:33:54 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2022/04/21 10:33:54 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/04/21 10:33:54 DEBUG : HTTP RESPONSE (req 0xc000efe400)
2022/04/21 10:33:54 DEBUG : HTTP/1.1 200 OK
Content-Length: 1000578
Accept-Ranges: bytes
Content-Type: image/jpeg
Date: Thu, 21 Apr 2022 10:33:54 GMT
Etag: 7461d99daf3f1e0742401ff05ed0fe0b
Last-Modified: Tue, 25 Jan 2022 20:55:49 GMT
X-Object-Meta-Sha1base36: kvcbxf34p98aldxygpsnqyusl2b5vbx
X-Openstack-Request-Id: txec2710ac9c0e4e92b6248-0062613312
X-Timestamp: 1643144148.22508
X-Trans-Id: txec2710ac9c0e4e92b6248-0062613312

2022/04/21 10:33:54 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/04/21 10:33:54 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/04/21 10:33:54 DEBUG : HTTP RESPONSE (req 0xc00013fd00)
2022/04/21 10:33:54 DEBUG : HTTP/1.1 200 OK
Content-Length: 1000578
Accept-Ranges: bytes
Content-Type: image/jpeg
Date: Thu, 21 Apr 2022 10:33:54 GMT
Etag: 7461d99daf3f1e0742401ff05ed0fe0b
Last-Modified: Tue, 25 Jan 2022 20:55:49 GMT
X-Object-Meta-Sha1base36: kvcbxf34p98aldxygpsnqyusl2b5vbx
X-Timestamp: 1643144148.45119
X-Trans-Id: tx8ce5254bc3d84835a8f13-0062613312

2022/04/21 10:33:54 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022/04/21 10:33:54 DEBUG : 0/01/3a1e15ca-ee52-118e-65dc-705273b6c7af.jpg: md5 = 7461d99daf3f1e0742401ff05ed0fe0b OK
2022/04/21 10:33:54 DEBUG : 0/01/3a1e15ca-ee52-118e-65dc-705273b6c7af.jpg: Size and md5 of src and dst objects identical
2022/04/21 10:33:54 DEBUG : 0/01/3a1e15ca-ee52-118e-65dc-705273b6c7af.jpg: Unchanged skipping

Full log (secrets redacted) is here: ✎ P25943 rclone sync debug output

I think this is rclone ignoring the hash header and so deciding it must HEAD each object for an ETag; but that defeats the point of sync --checksum that I want rclone to just rely on the container listing...

I think these HEAD request are due to static/dynamic large objects.

Rclone needs to figure out if the object is really a chunked object. In that case the hash in the listing will be the hash of the manifest file so should be returned as an empty string indicating the hash is unknown.

I don't think you can figure out if the object is a chunked object just from the listing :frowning:

Do you have any chunked objects?

Here is the code

Unfortunetely those calls to isDynamicLargeObject(ctx) will cause a HEAD request.

Thanks for the quick reply :slight_smile:

I suspect we don't have chunked objects (of either type), but I'm not entirely sure (will try and find out).

From a sync point of view, I think the hash of the manifest is sufficient (for both static and dynamic large objects) to answer the "has this changed?" question.

How plausible would it be to have a "skip the large objects check" behaviour here? [I had the terrible idea of a MD5-lazy hash type or similar that would just return o.md5, but I don't know this codebase at all]

My use case is that we have two swift clusters, and in general expect them to be in sync (mediawiki should write to both clusters). We have some ancient home-brew python that does this (and does so just based on container listings) which I would like to replace with rclone; but we have enough objects that I really can't HEAD them all. [this cluster doesn't have the S3 interface enabled]

I guess this would have to involve modifying newObjectWithInfo in the swift backend to know what sort of operation was involved, maybe?

[sorry, I've not looked into the rclone code before, and maybe slightly off-beam ideas aren't very useful!]

It would be relatively easy to add a new flag - say no_large_files which would turn off all support for either static or dynamic large files. This would mean that you would be limited to files of 5GiB or less. However it would stop rclone doing all those annoying HEAD requests. (rclone also has to do HEAD requests on 0 length files in the listings to determine if they are large objects or not, to show the correct size).

If you do have large files with this flag then the hashes will be wrong, and the copies will fail because the lengths are wrong too.

TBH if we had that option then I'd use it on all my swift remotes as large file handling in swift is a minefield!

If you wanted to try an experiment you could try commenting these lines of code out

And I think rclone will do what you want.

1 Like

That does (at least per --dry-run) look to be doing what I want, and just checking the container listing. So thank you :slight_smile:

From a deployment point of view, it would be nice if this could be done properly - does the Hash function get enough state to know what it's being called for? e.g. so it could either do something different when asked to copy (or even just bail out)? Otherwise, as you say, I think this would work (presumably with an option that gets passed into ctx eventually) except in the case where a large object was out of sync (when it would, as you say, do something strange).

Great!

My preferred way of doing this sort of thing is to add a backend flag.

We could add a very specific one no_head_hash which disabled head requests for that function only.

Or we could add a more general one like no_large_files like I discussed above.

I thought of a possible workaround also... Dynamic Large files always appear with size 0 in the listings, so rclone has to HEAD them to discover if they are really a 0 sized file or not. Rclone could record whether it has done this or not as a isDynamicLargeFile flag and then it wouldn't need to HEAD the object in the Hash method.

However I'm not sure how static large files appear in the directory listings - whether they appear as 0 length or not. If they do appear as 0 length then this workaround will work.

Do you have the ability to create dynamic / static large objects and check how they appear? You can use rclone ls -vv --dump bodies to see what the swift server actually returns.

I tried a larger test, but RAM usage got to over 30G and the OOM-killer came calling...

./rclone sync --checkers=64 --transfers=64 --exclude-from rclone_exclude --no-update-modtime --use-mmap --dry-run --checksum -v -P eqiad: codfw:
#...
Transferred:       30.579 GiB / 30.579 GiB, 100%, 10.030 KiB/s, ETA 0s
Checks:         111330306 / 111330306, 100%
Transferred:       218059 / 218069, 100%
Elapsed time:   1h44m25.0s

Is that expected? Top was saying

1421296 mvernon   20   0   30.8g  28.5g   8624 S 356.8  92.0 288:48.34 rclone

Not long before OOM. [if it would be useful to put the memory-use in a separate ticket, I can do so]

Hmm! Unusual, especially for a dry-run

Do you have folders with millions of entries in a single folder? If so then it is expected, otherwise probably not.

Rclone is relatively easy to profile in terms of memory use if you run with --rc: debugging memory use if you want to investigate further.

A grep of my swift logs suggests the container it was working on at the time of the OOM was wikipedia-commons-local-thumb.81, which is about 7M entries:

mvernon@ms-fe1012:~$ rclone ls eqiad:wikipedia-commons-local-thumb.81 | wc -l
7088074

Ok that explains it!

In order to do a sync between two directories rclone currently loads them both into RAM as it can't trust the order of items that the backend delivers them.

Rclone might use ~1k of RAM per object and given that you have a source and a destination 30G of memory doesn't sound completely out of order!

Remember also that since you've set --checkers=64 rclone can be doing up to 64 of these super large directories at once. If you try lowering that number, rclone will use less memory.

This particular problem is talked about in various issues, for example: New listing interface for backends `ListP` paged listing · Issue #4788 · rclone/rclone · GitHub - I'd like to add this to rclone at some point which would fix your problem - maybe you'd like to sponsor the feature?

There are several practical things that can be done to improve things in the mean time. One is to try setting GOGC=20 as outlined here. That trades CPU time for memory and will make a difference.

Lowering --checkers will help if there is more than one directory with a huge number of files.

Its also possible to use rclone plus some unix tools, for example (choose a separator which doesn't appear in the files - it can be multiple characters). This lists the path, md5 sum and size of every file.

rclone lsf -R --hash MD5 --format phs --files-only --separator "|"  src: | sort > src-files
rclone lsf -R --hash MD5 --format phs --files-only --separator "|" dst: | sort > dst-files

Then you can do this to discover the files which need transferring to the dst and deleting from the dst

comm -23 src-files dst-files | cut -d "|" -f 1 > need-transfer
comm -13 src-files dst-files | cut -d "|" -f 1  > need-delete

You can then feed the need-transfer into rclone copy and the need delete into rclone delete.

Or maybe just find the changed files

comm -3 src-files dst-files | cut -d "|" -f 1 | uniq > changed

Then feeding changed into rclone sync --files-from changed src: dst: might be the best way.

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