RCLONE Sync CMD - Repeating On A Loop With Latest Version

What is the problem you are having with rclone?

I have been running the CMD below from PowerShell without any issues until I recently updated rclone. I upgraded from rclone version 1.53.3 to version 1.56.0 and now when I run my CMD it just keeps repeating. For example the CMD will start and indicate that there are 25,892 files that it will check. It will than check all 25,892 files and than it just starts over again. Again I do not have this issue with rclon version 1.53.3 only rclone version 1.56.0.

I have ran the CMD with DEBUG logging enabled, however the log files really don't show any reason as to why this happening. I included a snippet of the logs to show that the initial sync is completing and than simply starting again. I can include the entire log file if needed, but its nearly 80,000 lines of text and does not really show anything except a bunch of files that have not changed since the last sync.

What is your rclone version (output from rclone version)

1.56.0

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

Windows 10 64bit

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

None. Local transfer from a NAS to another local device on the LAN via Windows shares.

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

///.\rclone.exe sync "\\192.168.5.2\Home Folders\Jason Codispoti" "D:\Home Folders" --checkers 10 --transfers 10 --check-first --max-backlog=-1 --checksum --backup-dir "D:\BAK" --progress --log-file="backup_log_02.txt" --log-level DEBUG///

The rclone config contents with secrets removed.

Note using the CONFIG file just running the CMD listed above. 

A log from the command with the -vv flag

///2021/08/01 10:31:07 DEBUG : Music/iTunes/Music/Various Artists/The Hunger Games_ Songs From District 12/14 Eyes Open.mp3: Unchanged skipping
2021/08/01 10:31:07 DEBUG : Music/iTunes/Music/Ulrich Schnauss/Goodbye/03 Stars.m4a: md5 = ef8b2ca7ae930f2e4be4ee6b588865ae OK
2021/08/01 10:31:07 DEBUG : Music/iTunes/Music/Ulrich Schnauss/Goodbye/03 Stars.m4a: Size and md5 of src and dst objects identical
2021/08/01 10:31:07 DEBUG : Music/iTunes/Music/Ulrich Schnauss/Goodbye/03 Stars.m4a: Unchanged skipping
2021/08/01 10:31:07 DEBUG : Music/iTunes/Music/Wiz Khalifa/Work Hard, Play Hard [Explicit]/Folder.jpg: md5 = 91d2b363649e01a9134c19fca3076cc0 OK
2021/08/01 10:31:07 DEBUG : Music/iTunes/Music/Wiz Khalifa/Work Hard, Play Hard [Explicit]/Folder.jpg: Size and md5 of src and dst objects identical
2021/08/01 10:31:07 DEBUG : Music/iTunes/Music/Wiz Khalifa/Work Hard, Play Hard [Explicit]/Folder.jpg: Unchanged skipping
2021/08/01 10:31:07 DEBUG : Music/iTunes/Music/Wiz Khalifa/Work Hard, Play Hard [Explicit]/AlbumArtSmall.jpg: md5 = feca179f8d55ee6e6fc84ffc2567125d OK
2021/08/01 10:31:07 DEBUG : Music/iTunes/Music/Wiz Khalifa/Work Hard, Play Hard [Explicit]/AlbumArtSmall.jpg: Size and md5 of src and dst objects identical
2021/08/01 10:31:07 DEBUG : Music/iTunes/Music/Wiz Khalifa/Work Hard, Play Hard [Explicit]/AlbumArtSmall.jpg: Unchanged skipping
2021/08/01 10:31:08 DEBUG : Music/iTunes/Music/Various Artists_Black Sabbath_Marilyn Ma/Ozzfest 2001_ The Second Millennium/13 Last Breath (Live).mp3: md5 = bbb5d894ba2a95d5fd80e820bab0e0d5 OK
2021/08/01 10:31:08 DEBUG : Music/iTunes/Music/Various Artists_Black Sabbath_Marilyn Ma/Ozzfest 2001_ The Second Millennium/13 Last Breath (Live).mp3: Size and md5 of src and dst objects identical
2021/08/01 10:31:08 DEBUG : Music/iTunes/Music/Various Artists_Black Sabbath_Marilyn Ma/Ozzfest 2001_ The Second Millennium/13 Last Breath (Live).mp3: Unchanged skipping
2021/08/01 10:31:08 DEBUG : Music/iTunes/Music/Yellowcard/Here I Am Alive/01 Here I Am Alive.mp3: md5 = 7db6b8cd1a0fbcbf34f1c0c472efd370 OK
2021/08/01 10:31:08 DEBUG : Music/iTunes/Music/Yellowcard/Here I Am Alive/01 Here I Am Alive.mp3: Size and md5 of src and dst objects identical
2021/08/01 10:31:08 DEBUG : Music/iTunes/Music/Yellowcard/Here I Am Alive/01 Here I Am Alive.mp3: Unchanged skipping
2021/08/01 10:31:08 DEBUG : Music/iTunes/Music/Wiz Khalifa/Work Hard, Play Hard [Explicit]/01 Work Hard, Play Hard [Explicit].mp3: md5 = 7939350bbf35765ad8f562cab09fa30a OK
2021/08/01 10:31:08 DEBUG : Music/iTunes/Music/Wiz Khalifa/Work Hard, Play Hard [Explicit]/01 Work Hard, Play Hard [Explicit].mp3: Size and md5 of src and dst objects identical
2021/08/01 10:31:08 DEBUG : Music/iTunes/Music/Wiz Khalifa/Work Hard, Play Hard [Explicit]/01 Work Hard, Play Hard [Explicit].mp3: Unchanged skipping
2021/08/01 10:31:09 DEBUG : PC Backups/7-13-2019/Documents/Software/Windows Server 2019/17763.379.190312-0539.rs5_release_svc_refresh_SERVER_EVAL_x64FRE_en-us.iso: md5 = 22ad0e83e20af5233a6ff453e6e257df OK
2021/08/01 10:31:09 DEBUG : PC Backups/7-13-2019/Documents/Software/Windows Server 2019/17763.379.190312-0539.rs5_release_svc_refresh_SERVER_EVAL_x64FRE_en-us.iso: Size and md5 of src and dst objects identical
2021/08/01 10:31:09 DEBUG : PC Backups/7-13-2019/Documents/Software/Windows Server 2019/17763.379.190312-0539.rs5_release_svc_refresh_SERVER_EVAL_x64FRE_en-us.iso: Unchanged skipping
2021/08/01 10:31:19 DEBUG : PC Backups/7-13-2019/Documents/Software/Windows Server 2016 Datacenter/Windows_Server_2016_Datacenter_EVAL_en-us_14393_refresh.ISO: md5 = 70721288bbcdfe3239d8f8c0fae55f1f OK
2021/08/01 10:31:19 DEBUG : PC Backups/7-13-2019/Documents/Software/Windows Server 2016 Datacenter/Windows_Server_2016_Datacenter_EVAL_en-us_14393_refresh.ISO: Size and md5 of src and dst objects identical
2021/08/01 10:31:19 DEBUG : PC Backups/7-13-2019/Documents/Software/Windows Server 2016 Datacenter/Windows_Server_2016_Datacenter_EVAL_en-us_14393_refresh.ISO: Unchanged skipping
2021/08/01 10:31:19 INFO  : Local file system at //?/D:/Home Folders: Checks finished, now starting transfers
2021/08/01 10:31:19 DEBUG : Local file system at //?/D:/Home Folders: Waiting for transfers to finish
2021/08/01 10:31:19 ERROR : Local file system at //?/D:/Home Folders: not deleting files as there were IO errors
2021/08/01 10:31:19 ERROR : Local file system at //?/D:/Home Folders: not deleting directories as there were IO errors
2021/08/01 10:31:19 ERROR : Attempt 1/3 failed with 2 errors and: not deleting files as there were IO errors
2021/08/01 10:31:19 INFO  : Local file system at //?/D:/Home Folders: Running all checks before starting transfers
2021/08/01 10:31:19 DEBUG : fs cache: switching user supplied name "D:\\BAK" for canonical name "//?/D:/BAK"
2021/08/01 10:31:19 DEBUG : Creating backend with remote "D:\\BAK"
2021/08/01 10:31:19 DEBUG : Links.txt: md5 = 507299c8d7d9763361755a7d947b26a6 OK
2021/08/01 10:31:19 DEBUG : Links.txt: Size and md5 of src and dst objects identical
2021/08/01 10:31:19 DEBUG : Links.txt: Unchanged skipping
2021/08/01 10:31:19 DEBUG : Financial Information/Discover Card & Car Payoff.txt: md5 = 4fb915aef4b5db68e6419b70b6cf62f4 OK
2021/08/01 10:31:19 DEBUG : Financial Information/Discover Card & Car Payoff.txt: Size and md5 of src and dst objects identical
2021/08/01 10:31:19 DEBUG : Financial Information/Discover Card & Car Payoff.txt: Unchanged skipping
2021/08/01 10:31:19 DEBUG : Financial Information/401k.txt: md5 = c986150153f307472dafb3ece7255897 OK
2021/08/01 10:31:19 DEBUG : Financial Information/401k.txt: Size and md5 of src and dst objects identical
2021/08/01 10:31:19 DEBUG : Financial Information/401k.txt: Unchanged skipping
2021/08/01 10:31:19 DEBUG : Financial Information/Home Loan.txt: md5 = 27b0fd19c724a942a515e5d506c70201 OK
2021/08/01 10:31:19 DEBUG : Financial Information/Home Loan.txt: Size and md5 of src and dst objects identical
2021/08/01 10:31:19 DEBUG : Financial Information/Home Loan.txt: Unchanged skipping
2021/08/01 10:31:19 DEBUG : Financial Information/C Spire vs Amazon.txt: md5 = ed211624b35f255ec2686311df6b6dda OK
2021/08/01 10:31:19 DEBUG : Financial Information/C Spire vs Amazon.txt: Size and md5 of src and dst objects identical
2021/08/01 10:31:19 DEBUG : Financial Information/C Spire vs Amazon.txt: Unchanged skipping
2021/08/01 10:31:19 DEBUG : Financial Information/Monthly Budget.xlsx: md5 = 3f9773095b8fcfdc09725aa65ed42a7b OK
2021/08/01 10:31:19 DEBUG : Financial Information/Monthly Budget.xlsx: Size and md5 of src and dst objects identical
2021/08/01 10:31:19 DEBUG : Financial Information/Monthly Budget.xlsx: Unchanged skipping
2021/08/01 10:31:19 DEBUG : Financial Information/Monthly Budget 2.0.xlsx: md5 = f29bef9cc20843f63fef138600e95c38 OK
2021/08/01 10:31:19 DEBUG : Financial Information/Monthly Budget 2.0.xlsx: Size and md5 of src and dst objects identical
2021/08/01 10:31:19 DEBUG : Financial Information/Monthly Budget 2.0.xlsx: Unchanged skipping
2021/08/01 10:31:19 DEBUG : Fan Profile Information/HWiNFO64_settings.reg: md5 = 1309fdbdf0cee3fae4526bec7056ea84 OK
2021/08/01 10:31:19 DEBUG : Fan Profile Information/HWiNFO64_settings.reg: Size and md5 of src and dst objects identical
2021/08/01 10:31:19 DEBUG : Fan Profile Information/HWiNFO64_settings.reg: Unchanged skipping///

hi,

can you post the top lines of the debug log?

what is OS of the NAS?

not sure what that means, D: is a net share?

Sure.

///"\192.168.5.2\Home Folders\Jason Codispoti"///
This is the source directory which is located on a FreeNAS server that is attached to my local LAN (Local Area Nework). FreeNAS Version 9.10.2-U6.

///"D:\Home Folders"///
This is the destination directory which is located on my Windows 10 Desktop that is also attached to my local LAN.

Here are the first 25 lines of the DEBUG file.
///2021/08/01 09:57:32 DEBUG : rclone: Version "v1.56.0" starting with parameters ["C:\rclone\rclone.exe" "sync" "\\192.168.5.2\Home Folders\Jason Codispoti" "D:\Home Folders" "--checkers" "10" "--transfers" "10" "--check-first" "--max-backlog=-1" "--checksum" "--backup-dir" "D:\BAK" "--progress" "--log-file=backup_log_02.txt" "--log-level" "DEBUG"]
2021/08/01 09:57:32 DEBUG : Creating backend with remote "\\192.168.5.2\Home Folders\Jason Codispoti"
2021/08/01 09:57:32 NOTICE: Config file "C:\Users\lab-test-01\AppData\Roaming\rclone\rclone.conf" not found - using defaults
2021/08/01 09:57:32 DEBUG : fs cache: renaming cache item "\\192.168.5.2\Home Folders\Jason Codispoti" to be canonical "//?/UNC/192.168.5.2/Home Folders/Jason Codispoti"
2021/08/01 09:57:32 DEBUG : Creating backend with remote "D:\Home Folders"
2021/08/01 09:57:32 DEBUG : fs cache: renaming cache item "D:\Home Folders" to be canonical "//?/D:/Home Folders"
2021/08/01 09:57:32 INFO : Local file system at //?/D:/Home Folders: Running all checks before starting transfers
2021/08/01 09:57:32 DEBUG : Creating backend with remote "D:\BAK"
2021/08/01 09:57:32 DEBUG : fs cache: renaming cache item "D:\BAK" to be canonical "//?/D:/BAK"
2021/08/01 09:57:32 DEBUG : Links.txt: md5 = 507299c8d7d9763361755a7d947b26a6 OK
2021/08/01 09:57:32 DEBUG : Links.txt: Size and md5 of src and dst objects identical
2021/08/01 09:57:32 DEBUG : Links.txt: Unchanged skipping
2021/08/01 09:57:33 DEBUG : Financial Information/401k.txt: md5 = c986150153f307472dafb3ece7255897 OK
2021/08/01 09:57:33 DEBUG : Financial Information/401k.txt: Size and md5 of src and dst objects identical
2021/08/01 09:57:33 DEBUG : Financial Information/401k.txt: Unchanged skipping
2021/08/01 09:57:33 DEBUG : Financial Information/C Spire vs Amazon.txt: md5 = ed211624b35f255ec2686311df6b6dda OK
2021/08/01 09:57:33 DEBUG : Financial Information/C Spire vs Amazon.txt: Size and md5 of src and dst objects identical
2021/08/01 09:57:33 DEBUG : Financial Information/C Spire vs Amazon.txt: Unchanged skipping
2021/08/01 09:57:33 DEBUG : Financial Information/Home Loan.txt: md5 = 27b0fd19c724a942a515e5d506c70201 OK
2021/08/01 09:57:33 DEBUG : Financial Information/Home Loan.txt: Size and md5 of src and dst objects identical
2021/08/01 09:57:33 DEBUG : Financial Information/Home Loan.txt: Unchanged skipping
2021/08/01 09:57:33 DEBUG : Financial Information/Discover Card & Car Payoff.txt: md5 = 4fb915aef4b5db68e6419b70b6cf62f4 OK
2021/08/01 09:57:33 DEBUG : Financial Information/Discover Card & Car Payoff.txt: Size and md5 of src and dst objects identical
2021/08/01 09:57:33 DEBUG : Financial Information/Discover Card & Car Payoff.txt: Unchanged skipping
2021/08/01 09:57:33 DEBUG : Amazon Job/Candidate NDA.pdf: md5 = 825614c57e3bacb89b6e32eb7f7362c1 OK///

for what it is worth, is there a reason not to run rclone on the nas?

Personal preference and situational mostly...

  • Don't want any backup jobs (including scripts) or backup data stored on the NAS. This is mostly due to the NAS being the primary storage device in my setup.
  • I have a single 'server' that manages backups of multiple devices so it just makes since to have everything 'backup' related consolidated to that one device.

Any ideas on why this is happening?

ok, D: is on the same machine as rclone is run on.

ERROR : Attempt 1/3 failed with 2 errors
i think this is normal behaviour as per the documentation
https://rclone.org/docs/#retries-int
"Retry the entire sync if it fails this many times it fails (default 3)."

and what are those 2 errors?

if you get those two exact same errors with v1.53.3, rclone sync would not attempt to retry?

Hmm, I think that you may be on to something... I did see those errors in the log, but all it really indicates is that there was an IO Error. I do not see anything about it being a specific file etc. I went back and looked and my previous log files and I was not getting those errors with v1.53.3. However I just retested and I did get those errors and it started the process over again. I guess the question now is why am I getting those errors...

you can search thru the log for ERROR and should be able to find it....

if the problem is reproducible, to create a smaller log file, add
--retries=1 --low-level-retries=1

Yeah, retesting with that now... I think that I have found the issue appears to be one file that rclone is not able to open due to an access denied error. This may be what is causing the issue. I am retesting to confirm...

LMAO... so added the flags that you had suggested and ran it again and now its not detecting any errors...

yeah, that is a bummer, but going forward i think you have what you need to figure out what is going on....

Agreed. Thank you very much for your help on this! You have been great!!!

sure, but the main thing is there is not a rclone bug....

Correct. That was my mistake. See if I can change the topic of this post.

1 Like

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