Encrypted chunker (chunker->crypt->remote): size command and --fast-list flag may not enumerate some chunked files

What is the problem you are having with rclone?

Size command may return incorrect value for folders with chunked files. It miss some fully & correctly uploaded chunked files as if they do not exist or they are missing some chunks (normally file is not shown if not all chunks are present). The same behaviour happens for sync/copy commands with --fast-list flag. Without --fast-list flag, all files are correctly enumerated and there are no unnecessary same files re-uploading. It happens to two different remotes too (Google Drive + Jottacloud). And the missing files count is different for different remotes (what is very strange). For the case in a log example: 19 files out of 20 for Google Drive and 10 files out of 20 for Jottacloud (totally no chunked files at all are enumerated). I believe that this difference may be caused by differences in timing between those two remotes. Due to this bug, not all chunked files will be copied/synced when used with --fast-list flag and copied from the chunked source (very important).

What is your rclone version (output from rclone version)

rclone v1.52.2

  • os/arch: windows/amd64
  • go version: go1.14.4

Which OS you are using and how many bits (eg Windows 7, 64 bit)

Windows 10, 64 bit

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

Google Drive; Jottacloud

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

rclone size gcrypt-chunk:"chunked_folder/" -P
rclone size jottacrypt-chunk:"chunked_folder/" -P

rclone copy "C:\chunked_folder\" gcrypt-chunk:"chunked_folder/" -P --fast-list
rclone sync "C:\chunked_folder\" gcrypt-chunk:"chunked_folder/" -P --fast-list

The rclone config contents with secrets removed.

[gdrive]
type = drive
scope = drive
token = [REDACTED]
root_folder_id = root

[gcrypt]
type = crypt
remote = gdrive:
filename_encryption = standard
directory_name_encryption = true
password = [REDACTED]
password2 = [REDACTED]

[gcrypt-chunk]
type = chunker
remote = gcrypt:
chunk_size = 1G
name_format = *.rcc##
hash_type = none

A log from the command with the -vv flag

Quite heavily redacted for privacy :smile:. I hope I didn't distort it too much. Really didn't like to do that. Wasted some time for that thing in the hopes that it would really help fix this bug.

rclone size gcrypt-chunk:"[REDACTED]" -P -vv
2020/XX/XX XX:XX:XX DEBUG : rclone: Version "v1.52.2" starting with parameters ["rclone" "size" "gcrypt-chunk:chunked_folder/[REDACTED]" "-P" "-vv"]
2020/XX/XX XX:XX:XX DEBUG : Using config file from "[REDACTED]\\rclone.conf"
2020/XX/XX XX:XX:XX DEBUG : Chunked 'gcrypt-chunk:chunked_folder/[REDACTED]"
2020/XX/XX XX:XX:XX DEBUG : Chunked 'gcrypt-chunk:chunked_folder/[REDACTED].rcc02" without meta object
2020/XX/XX XX:XX:XX DEBUG : Chunked 'gcrypt-chunk:chunked_folder/[REDACTED].rcc03" without meta object
2020/XX/XX XX:XX:XX DEBUG : Chunked 'gcrypt-chunk:chunked_folder/[REDACTED].rcc06" without meta object
Transferred:             0 / 0 Bytes, -, 0 Bytes/s, ETA -
Elapsed time:         0.0sTotal objects: 19
Transferred:             0 / 0 Bytes, -, 0 Bytes/s, ETA -
Elapsed time:         0.0s
2020/XX/XX XX:XX:XX  DEBUG : 6 go routines active

rclone sync "C:\[REDACTED]" gcrypt-chunk:"[REDACTED]" -P --fast-list --dry-run -vv
2020/XX/XX XX:XX:XX DEBUG : rclone: Version "v1.52.2" starting with parameters ["rclone" "sync" "C:\[REDACTED]" "gcrypt-chunk:[REDACTED]" "-P" "--fast-list" "--dry-run" "-vv"]
2020/XX/XX XX:XX:XX DEBUG : Using config file from "[REDACTED]\\rclone.conf"
2020/XX/XX XX:XX:XX DEBUG : fs cache: renaming cache item "C:\[REDACTED]" to be canonical "//?/C:\[REDACTED]"
2020/XX/XX XX:XX:XX DEBUG : Chunked 'gcrypt-chunk:[REDACTED]': invalid chunks in object "[REDACTED]"
2020/XX/XX XX:XX:XX DEBUG : Chunked 'gcrypt-chunk:[REDACTED]': skip chunk "[REDACTED].rcc02" without meta object
2020/XX/XX XX:XX:XX DEBUG : Chunked 'gcrypt-chunk:[REDACTED]': skip chunk "[REDACTED].rcc03" without meta object
2020/XX/XX XX:XX:XX DEBUG : Chunked 'gcrypt-chunk:[REDACTED]': skip chunk "[REDACTED].rcc06" without meta object
2020/XX/XX XX:XX:XX NOTICE: [REDACTED]: Not copying as --dry-run
2020/XX/XX XX:XX:XX DEBUG : Chunked 'gcrypt-chunk:[REDACTED]': Waiting for checks to finish
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -795.1µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -628.1µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -934.8µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -473µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -643µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -250.1µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -655.1µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -976.7µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -734.8µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -333µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -725.8µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -48.9µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -468.9µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -430.9µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -45.2µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -298.1µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -961.7µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -920.2µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Size and modification time the same (differ by -568.3µs, within tolerance 1ms)
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : [REDACTED]: Unchanged skipping
2020/XX/XX XX:XX:XX DEBUG : Chunked 'gcrypt-chunk:[REDACTED]': Waiting for transfers to finish
2020/XX/XX XX:XX:XX DEBUG : Waiting for deletions to finish
Transferred:             0 / 0 Bytes, -, 0 Bytes/s, ETA -
Checks:                19 / 19, 100%
Transferred:            1 / 1, 100%
Elapsed time:         0.9s
2020/XX/XX XX:XX:XX INFO  :
Transferred:             0 / 0 Bytes, -, 0 Bytes/s, ETA -
Checks:                19 / 19, 100%
Transferred:            1 / 1, 100%
Elapsed time:         0.9s

2020/XX/XX XX:XX:XX DEBUG : 6 go routines active

It sounds like you have some orphaned chunks as described here https://rclone.org/chunker/#migrations

That gives a procedure for cleaning them. You can also delete them by hand

It would be nice if the rclone cleanup command worked here - what do you think @ivandeex ?

Chunker can "skip" files on Google Drive. This bug was discussed here: https://github.com/rclone/rclone/issues/3972#issuecomment-595927263
The cause is that Drive internally activates ListR access method. A quick fix is to disable ListR and fallback to ordinary non-recursive List with Chunker (tried here https://github.com/ivandeex/rclone/commits/chunker-drive-skip).

You can try a beta binary https://github.com/ivandeex/rclone/releases/tag/v1.51.driveskip to see if it helps.
A full solution is to completely rewrite directory listing code (processEntries) in Chunker. I have started it here: https://github.com/ivandeex/rclone/commits/exotics (not yet done).

In the meantime please invoke rclone like this:

rclone ls gcrypt-chunk: -vv --disable=ListR
rclone size gcrypt-chunk: -vv --disable=ListR

Hope it helps

1 Like

@ncw
It can take some time to finish rewriting of Chunker's ProcessEntries as the change is big: https://github.com/ivandeex/rclone/commit/2e2942dfd6bad345072523ea274a7e66a6cfb8a7
Until then we can merge the known workoaround on master: https://github.com/ivandeex/rclone/commit/6c495db636a21da473d5d4950a879dc432af806d
What do you think?

Yes that looks fine - let's do that.