Rclone iterating several times during copy

Help and Support
1

What is the problem you are having with rclone?

When copying large amounts of data, I feel that rclone sometimes "loops" over the full data set several times, and never ends. I have an example now where I am running a copy command, and in the logfile I can see it assessing whether to copy the same files over again.

What is your rclone version (output from rclone version)

rclone v1.56.0

  • os/version: ubuntu 20.04 (64 bit)
  • os/kernel: 5.8.0-1039-azure (x86_64)
  • os/type: linux
  • os/arch: amd64
  • go/version: go1.16.5
  • go/linking: static
  • go/tags: none

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

Linux 5.8.0-1039-azure #42~20.04.1-Ubuntu SMP

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

Dropbox source, Azure Dest

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

rclone: Version "v1.56.0" starting with parameters ["/usr/bin/rclonev1.56.0" "--progress" "--max-depth" "-1" "--checkers" "28" "--tpslimit" "13" "--azureblob-archive-tier-delete=false" "--dropbox-impersonate" "<redacted>" "--config" "/home/<redacted>/.config/rclone/rclone.conf" "--transfers" "28" "--log-file=/home/<redacted>/logs//<redacted>-2021-08-25.log" "--log-level" "DEBUG" "copy" "<redacted>:<redacted>" "<redacted>:<redacted>"]

The rclone config contents with secrets removed.

[<source-redacted>]
type = dropbox
client_id = <redacted>
client_secret = <redacted>
token = {<redacted>}


[<dest-redacted>]
type = azureblob
account = <redacted>
key = <redacted>
access_tier = Archive
archive_tier_delete = true
chunk_size = 100M

A log from the command with the -vv flag

example of a file being seemingly processed twice extracted from the log below

cat  logs/r<redacted>.log |grep "julia/kids/Julia/__Webshare__/08. Archive/2008/J811_dokument/InDesign/J811_54_skonhet/Fonts/Spumoni_screen_fonts"
2021/08/26 00:58:25 DEBUG : julia/kids/Julia/__Webshare__/08. Archive/2008/J811_dokument/InDesign/J811_54_skonhet/Fonts/Spumoni_screen_fonts: Size and modification time the same (differ by 0s, within tolerance 1s)
2021/08/26 00:58:25 DEBUG : julia/kids/Julia/__Webshare__/08. Archive/2008/J811_dokument/InDesign/J811_54_skonhet/Fonts/Spumoni_screen_fonts: Unchanged skipping
2021/08/26 13:11:06 DEBUG : julia/kids/Julia/__Webshare__/08. Archive/2008/J811_dokument/InDesign/J811_54_skonhet/Fonts/Spumoni_screen_fonts: Size and modification time the same (differ by 0s, within tolerance 1s)
2021/08/26 13:11:06 DEBUG : julia/kids/Julia/__Webshare__/08. Archive/2008/J811_dokument/InDesign/J811_54_skonhet/Fonts/Spumoni_screen_fonts: Unchanged skipping
2

With only the snippet from the log, it's impossible to tell.

Can you share a single debug log?

3

Hi Magnus,

If there is an (retriable) error during the copy then rclone will retry/loop the copy command up to three times (or --retries).

Try searching/grepping your log for "ERROR" to see if there are any errors.

If so, then search for "Attempt" and you may find one or more entries like this:

2021/08/21 00:49:01 ERROR : Attempt 1/3 failed with xxx errors and: yyyyy

I guess you will find an Attempt between 2021/08/26 00:58:25 and 2021/08/26 13:11:06 - what does it say?

1 Like
4

Good point! let me do some more grep:ing to check this.
(Job is still running)

5

not really, there are errors, but not on those files.

cat logs/rclone-<redacted>-2021-08-25.log |grep ERROR |grep Attempt
2021/08/26 02:55:50 ERROR : Attempt 1/3 failed with 34 errors and: march failed with 26 error(s): first error: unexpected end of JSON input
2021/08/26 15:08:11 ERROR : Attempt 2/3 failed with 27 errors and: march failed with 16 error(s): first error: invalid character '<' looking for beginning of value
6

A full log makes this process much easier...

7

Now this is perhaps interesting, looking at that exact timing of the error, it looks as it starts over the checks..

2021/08/26 15:08:11 DEBUG : julia/MFT/julia/03. Freelance/Jenny Thorell/SNO SMINKSTILEN/Miley Cyrus/J1004_snosminkstilen_mascara_MileyCyrus.jpg.jpg: Size and modification time the same (differ by 0s, within tolerance 1s)
2021/08/26 15:08:11 DEBUG : julia/MFT/julia/03. Freelance/Jenny Thorell/SNO SMINKSTILEN/Miley Cyrus/J1004_snosminkstilen_mascara_MileyCyrus.jpg.jpg: Unchanged skipping
2021/08/26 15:08:11 DEBUG : Azure container <redacted>: Waiting for checks to finish
2021/08/26 15:08:11 DEBUG : Azure container <redacted>: Waiting for transfers to finish
2021/08/26 15:08:11 ERROR : Attempt 2/3 failed with 27 errors and: march failed with 16 error(s): first error: invalid character '<' looking for beginning of value
2021/08/26 15:08:12 DEBUG : WmiData.csv: Size and modification time the same (differ by 0s, within tolerance 1s)
2021/08/26 15:08:12 DEBUG : WmiData.csv: Unchanged skipping
2021/08/26 15:08:15 DEBUG : ARKIV/Tarzan.tif: Size and modification time the same (differ by 0s, within tolerance 1s)
2021/08/26 15:08:15 DEBUG : ARKIV/Tarzan.tif: Unchanged skipping
2021/08/26 15:08:15 DEBUG : ARKIV/LF 1997_03 C1 bw.tif: Size and modification time the same (differ by 0s, within tolerance 1s)
2021/08/26 15:08:15 DEBUG : ARKIV/LF 1997_03 C1 bw.tif: Unchanged skipping
2021/08/26 15:08:15 DEBUG : Ateljen_BA6/.apdisk: Size and modification time the same (differ by 0s, within tolerance 1s)
2021/08/26 15:08:15 DEBUG : Ateljen_BA6/.apdisk: Unchanged skipping
2021/08/26 15:08:15 DEBUG : Ateljen_BA6/.com.apple.timemachine.supported: Size and modification time the same (differ by 0s, within tolerance 1s)
2021/08/26 15:08:15 DEBUG : Ateljen_BA6/.com.apple.timemachine.supported: Unchanged skipping
8

If there any errors, then rclone performs a complete retry - it doesn't just try the failing files, that could get quite complex (if not impossible) in some situations.

As a workaround, you could do your large copy with --retries=1, then check and fix the failing files individually, and then verify with a large copy again.

The errors you get look somewhat strange to me.

It would certainly help if you can share the full log - otherwise grep the first 10 lines with errors - they may help us undertand your situation better. It is very difficult (if not impossible) to help you while you are moving our eyes around without letting us move them ourselves.

9

Yes, I know I am a bit paranoid about redacting stuff and not sharing the full logs (that are also still accumulating), and I realise I may be shooting myself a bit in the foot so to say, so that just makes me appreciate your assistance even more.

10

It makes it painful to go bit by bit unfortunately.

11

ah, so in case I am copying a folder, and there are errors in the copy, it will retry the full copy command 3 times?
That actually explains what I am seeing, so for a job with a large amount of files, I should be setting retries to 1 as you say, and then just retry the other ones with --files-from command.

12

Correct!

Correct in simple situations, but it really depends on the errors - suppose it fails while reading a folder with 10 subfolders with 1000 files each... Take a look at the errors and evaluate you situation. Share your errors if in doubt of correct handling.

1 Like
13

hi,

i knew that rclone sync will re-try the entire source folder after a single file error.

i did not know that rclone copy behaves the same way?

14

I just verified; rclone copy does --retries.

rclone copy can often be seen as a short form for rclone sync --without-deletions

15

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