Is there a way to get an ordered log? (for readability)

Rclone default log is not ideal if your objective is to understand what was done by Rclone, since all the files are processed in a pretty random order.
Is disabling multithreading with --checkers 1 and --transfers 1 the only way to get more readable logs?
Sounds like that would have a major performance impact.

PS
Ordered = files are grouped by folder, at least.

--checkers 1 --transfers 1 --check-first will get you the most ordered log at the cost of performance.

Rclone is fast because it does lots of things concurrently - unfortunately this makes for very confusing logs for our single threaded human brains!

1 Like

you can also try --order-by=name,asc

1 Like

Good idea. Most accurate with --check-first and will work without changing transfers or checkers. The log won't be perfectly ordered as the transfers will start in order but may not finish in order (when the log is written).

1 Like

In Windows, I usually output the command to a log file, load it into Notepad++ and let it order the lines with Edit > Line Operations > Sort Lines Lexicographically Ascending. It's immediate and it can handle big files with no issues.

1 Like

"--check-first --order-by=name,asc" seems to work for transfers. But not for deletions/moves to backup dir.

Thanks!
"--check-first --order-by=name,asc" seems like the best option for now. I have not tried to use " --order-by=name,asc" without "--check-first", should I?

This is great for one log. However, I usually have multiple logs output to a single file (so I can scroll up to see previous operations without having to open up many files). So it might work well enough for a single big operation, but not many small ones.

It only works for the transfers at the moment.

It will make the transfers start sooner, but some things will be out of order.

Any hope for seeing this apply to moves or deletions in the future?

Probably not as it is for ordering which files get processed first, but there is no way to order the subsequent move / deletes which happen as part of a transfer.

My problem is that if I delete, move, or rename a folder with many files, rclone sync takes days, sometimes weeks, to finish the move to backup dir in Dropbox.
In the log, all the moves to backup dir are randomly ordered, and there is no indication of how many are left. So I have no idea when it will finally finish or even where we are in the process.

The only way to get a vague idea of how many are left is to login to the Dropbox web interface and check the size of the folders that were moved/deleted/renamed. They slowly go to 0.

PS
Why is the move to backup dir (server-side move) so slow with Dropbox? Am I doing something wrong? It does 32k files a day, that means 0.3 files a second. (the command I am running is on my previous topic)

The rclone stats should also be giving you an idea? If you use -v you'll gets stats printed in the log every 1 minute by default (change with --stats) which will give you an idea of the overall progress.

That does sound slow. Rclone should be doing --checkers of these in parallel.

I suggest you examine the log for clues. A debug log with -vv is recommended.

Thanks a lot for the quick reply.

Maybe the suffix adding is also adding to the slowness?

I'm seeing a lot of too_many_write_operations.
I don't know why. I'm using --tpslimit 12 --tpslimit-burst 0 and every rclone instance has its own Dropbox App ID. I even tried to make sure that no other rclone operation was running, same result.

The -vv log is a lot of this:

2023/05/11 16:44:33 INFO : - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/World of Warcraft/WoWScrnShot_010711_013914.jpg: Moved (server-side) to: - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/World of Warcraft/WoWScrnShot_010711_013914 -saved 2023-05-11 15.09.07.jpg

2023/05/11 16:44:33 INFO : - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/World of Warcraft/WoWScrnShot_010711_013914.jpg: Moved into backup dir

2023/05/11 16:44:36 DEBUG : pacer: Reducing sleep to 843.75ms

2023/05/11 16:44:36 INFO : - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/World of Warcraft SAVE AZEROTH/Dungeon (Northrend) - Ahn'kahet The Old Kingdom/WoWScrnShot_091709_172322.jpg: Moved (server-side) to: - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/World of Warcraft SAVE AZEROTH/Dungeon (Northrend) - Ahn'kahet The Old Kingdom/WoWScrnShot_091709_172322 -saved 2023-05-11 15.09.07.jpg

2023/05/11 16:44:36 INFO : - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/World of Warcraft SAVE AZEROTH/Dungeon (Northrend) - Ahn'kahet The Old Kingdom/WoWScrnShot_091709_172322.jpg: Moved into backup dir

2023/05/11 16:44:37 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/..)

2023/05/11 16:44:37 DEBUG : pacer: Rate limited, increasing sleep to 1.6875s

2023/05/11 16:44:37 DEBUG : pacer: Reducing sleep to 1.265625s

2023/05/11 16:44:37 INFO : - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/Bioshock Infinite/2013-03-26_00125.jpg: Moved (server-side) to: - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/Bioshock Infinite/2013-03-26_00125 -saved 2023-05-11 15.09.07.jpg

2023/05/11 16:44:37 INFO : - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/Bioshock Infinite/2013-03-26_00125.jpg: Moved into backup dir

2023/05/11 16:44:37 DEBUG : pacer: Reducing sleep to 949.21875ms

2023/05/11 16:44:40 DEBUG : pacer: Reducing sleep to 711.914062ms

2023/05/11 16:44:40 INFO : - 10 - Dropbox/- 10 - Libraries/Ives Screenshots/- 2 - List/World of Warcraft SAVE AZEROTH/Kalimdor - Winterspring/WoWScrnShot_060710_191447.jpg: Moved (server-side) to: - 10 - Dropbox/- 10 - Libraries/Ives Screenshots/- 2 - List/World of Warcraft SAVE AZEROTH/Kalimdor - Winterspring/WoWScrnShot_060710_191447 -saved 2023-05-11 15.09.07.jpg

2023/05/11 16:44:40 INFO : - 10 - Dropbox/- 10 - Libraries/Ives Screenshots/- 2 - List/World of Warcraft SAVE AZEROTH/Kalimdor - Winterspring/WoWScrnShot_060710_191447.jpg: Moved into backup dir

2023/05/11 16:44:40 DEBUG : pacer: Reducing sleep to 533.935546ms

2023/05/11 16:44:40 INFO : - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/Dragon Age - N5/Screenshot20100710091926113.jpg: Moved (server-side) to: - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/Dragon Age - N5/Screenshot20100710091926113 -saved 2023-05-11 15.09.07.jpg

2023/05/11 16:44:40 INFO : - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/Dragon Age - N5/Screenshot20100710091926113.jpg: Moved into backup dir

2023/05/11 16:44:42 DEBUG : pacer: Reducing sleep to 400.451659ms

2023/05/11 16:44:42 DEBUG : pacer: Reducing sleep to 300.338744ms

2023/05/11 16:44:42 DEBUG : pacer: Reducing sleep to 225.254058ms

2023/05/11 16:44:42 INFO : - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/World of Warcraft SAVE AZEROTH/Eastern Kingdoms - Eversong Woods/WoWScrnShot_060310_225836.jpg: Moved (server-side) to: - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/World of Warcraft SAVE AZEROTH/Eastern Kingdoms - Eversong Woods/WoWScrnShot_060310_225836 -saved 2023-05-11 15.09.07.jpg

2023/05/11 16:44:42 INFO : - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/World of Warcraft SAVE AZEROTH/Eastern Kingdoms - Eversong Woods/WoWScrnShot_060310_225836.jpg: Moved into backup dir

2023/05/11 16:44:43 DEBUG : pacer: Reducing sleep to 168.940543ms

2023/05/11 16:44:43 DEBUG : pacer: Reducing sleep to 126.705407ms

2023/05/11 16:44:43 DEBUG : pacer: Reducing sleep to 95.029055ms

2023/05/11 16:44:43 DEBUG : pacer: Reducing sleep to 71.271791ms

2023/05/11 16:44:43 INFO : - 10 - Dropbox/- 10 - Libraries/Ives Screenshots/- 2 - List/Assassin's Creed Odyssey/Assassin's Creed Odyssey Screenshot 2020.03.19 - 15.19.45.73.png: Moved (server-side) to: - 10 - Dropbox/- 10 - Libraries/Ives Screenshots/- 2 - List/Assassin's Creed Odyssey/Assassin's Creed Odyssey Screenshot 2020.03.19 - 15.19.45.73 -saved 2023-05-11 15.09.07.png

2023/05/11 16:44:43 INFO : - 10 - Dropbox/- 10 - Libraries/Ives Screenshots/- 2 - List/Assassin's Creed Odyssey/Assassin's Creed Odyssey Screenshot 2020.03.19 - 15.19.45.73.png: Moved into backup dir

2023/05/11 16:44:44 DEBUG : pacer: Reducing sleep to 53.453843ms

2023/05/11 16:44:44 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...)

2023/05/11 16:44:44 DEBUG : pacer: Rate limited, increasing sleep to 106.907686ms

2023/05/11 16:44:44 DEBUG : pacer: Reducing sleep to 80.180764ms

2023/05/11 16:44:45 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/.)

2023/05/11 16:44:45 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/)

2023/05/11 16:44:45 DEBUG : pacer: Rate limited, increasing sleep to 160.361528ms

2023/05/11 16:44:45 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...)

2023/05/11 16:44:45 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/)

2023/05/11 16:44:45 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...)

2023/05/11 16:44:45 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/...)

2023/05/11 16:44:45 DEBUG : pacer: Rate limited, increasing sleep to 320.723056ms

2023/05/11 16:44:45 DEBUG : pacer: Rate limited, increasing sleep to 641.446112ms

2023/05/11 16:44:45 DEBUG : pacer: Rate limited, increasing sleep to 1.282892224s

2023/05/11 16:44:45 DEBUG : pacer: Rate limited, increasing sleep to 2s

2023/05/11 16:44:45 DEBUG : pacer: Reducing sleep to 1.5s

2023/05/11 16:44:45 INFO : - 10 - Dropbox/censoredfile1.pdf: Moved (server-side) to: - 10 - Dropbox/censoredfile1 -saved 2023-05-11 15.09.07.pdf

2023/05/11 16:44:45 INFO : - 10 - Dropbox/censoredfile1.pdf: Moved into backup dir

2023/05/11 16:44:45 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/...)

2023/05/11 16:44:45 DEBUG : pacer: Rate limited, increasing sleep to 2s

2023/05/11 16:44:46 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/...)

2023/05/11 16:44:46 DEBUG : pacer: Reducing sleep to 1.5s

2023/05/11 16:44:46 INFO : - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/App Docs/Playgrounds/Learn to Code 1.playgroundbook/Contents/Modules/Document5_Challenge2.playgroundmodule/Sources/Commands.swift: Moved (server-side) to: - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/App Docs/Playgrounds/Learn to Code 1.playgroundbook/Contents/Modules/Document5_Challenge2.playgroundmodule/Sources/Commands -saved 2023-05-11 15.09.07.swift

2023/05/11 16:44:46 INFO : - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/App Docs/Playgrounds/Learn to Code 1.playgroundbook/Contents/Modules/Document5_Challenge2.playgroundmodule/Sources/Commands.swift: Moved into backup dir

2023/05/11 16:44:49 DEBUG : pacer: Reducing sleep to 1.125s

2023/05/11 16:44:49 INFO : - 10 - Dropbox/censoredfile2.pdf: Moved (server-side) to: - 10 - Dropbox/censoredfile2 -saved 2023-05-11 15.09.07.pdf

2023/05/11 16:44:49 INFO : - 10 - Dropbox/censoredfile2.pdf: Moved into backup dir

2023/05/11 16:44:49 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/.)

2023/05/11 16:44:49 DEBUG : pacer: Rate limited, increasing sleep to 2s

2023/05/11 16:44:51 DEBUG : pacer: Reducing sleep to 1.5s

2023/05/11 16:44:51 INFO : - 10 - Dropbox/- 10 - Libraries/Images/- 2 - List/Worth a Buy Channel youtube-dl Backup 2018-01-22/Worth A Buy - 324 - 20160316 - Stardew Valley Review - Worthabuy - 1920x1080 60.mp4: Moved (server-side) to: - 10 - Dropbox/- 10 - Libraries/Images/- 2 - List/Worth a Buy Channel youtube-dl Backup 2018-01-22/Worth A Buy - 324 - 20160316 - Stardew Valley Review - Worthabuy - 1920x1080 60 -saved 2023-05-11 15.09.07.mp4

2023/05/11 16:44:51 INFO : - 10 - Dropbox/- 10 - Libraries/Images/- 2 - List/Worth a Buy Channel youtube-dl Backup 2018-01-22/Worth A Buy - 324 - 20160316 - Stardew Valley Review - Worthabuy - 1920x1080 60.mp4: Moved into backup dir

2023/05/11 16:44:53 DEBUG : pacer: Reducing sleep to 1.125s

2023/05/11 16:44:54 DEBUG : pacer: Reducing sleep to 843.75ms

2023/05/11 16:44:54 INFO : - 10 - Dropbox/- 10 - Libraries/Movies Screenshots/- 3 - Unsorted/Star.Trek.Discovery.S03E03.People.of.Earth.1080p.mkv_003515.625.png: Moved (server-side) to: - 10 - Dropbox/- 10 - Libraries/Movies Screenshots/- 3 - Unsorted/Star.Trek.Discovery.S03E03.People.of.Earth.1080p.mkv_003515.625 -saved 2023-05-11 15.09.07.png

2023/05/11 16:44:54 INFO : - 10 - Dropbox/- 10 - Libraries/Movies Screenshots/- 3 - Unsorted/Star.Trek.Discovery.S03E03.People.of.Earth.1080p.mkv_003515.625.png: Moved into backup dir

2023/05/11 16:44:56 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/..)

2023/05/11 16:44:56 DEBUG : pacer: Rate limited, increasing sleep to 1.6875s

2023/05/11 16:44:56 DEBUG : pacer: Reducing sleep to 1.265625s

2023/05/11 16:44:57 DEBUG : pacer: Reducing sleep to 949.21875ms

2023/05/11 16:44:57 INFO : - 10 - Dropbox/All Dupes Probably/Libraries (shared folder conflict)/App Docs/Playgrounds/Learn to Code 2.playgroundbook/Contents/Chapters/Document13.playgroundchapter/Pages/08.playgroundpage/PrivateResources/tr.lproj/Hints.plist: Moved (server-side) to: - 10 - Dropbox/All Dupes Probably/Libraries (shared folder conflict)/App Docs/Playgrounds/Learn to Code 2.playgroundbook/Contents/Chapters/Document13.playgroundchapter/Pages/08.playgroundpage/PrivateResources/tr.lproj/Hints -saved 2023-05-11 15.09.07.plist

2023/05/11 16:44:57 INFO : - 10 - Dropbox/All Dupes Probably/Libraries (shared folder conflict)/App Docs/Playgrounds/Learn to Code 2.playgroundbook/Contents/Chapters/Document13.playgroundchapter/Pages/08.playgroundpage/PrivateResources/tr.lproj/Hints.plist: Moved into backup dir

2023/05/11 16:44:58 DEBUG : pacer: Reducing sleep to 711.914062ms

2023/05/11 16:45:00 DEBUG : pacer: Reducing sleep to 533.935546ms

2023/05/11 16:45:01 DEBUG : pacer: Reducing sleep to 400.451659ms

2023/05/11 16:45:02 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/..)

2023/05/11 16:45:02 DEBUG : pacer: Rate limited, increasing sleep to 800.903318ms

2023/05/11 16:45:02 DEBUG : pacer: Reducing sleep to 600.677488ms

2023/05/11 16:45:02 INFO : - 10 - Dropbox/censoredName1/My Mac (wheatley-4.home)/Movies/SDR.fcpbundle/2022-02-06 Kittten/Render Files/Thumbnail Media/E6215C25945ACFB68E41B16364C10910/Frame 107520 - 108543: Moved (server-side) to: - 10 - Dropbox/censoredName1/My Mac (wheatley-4.home)/Movies/SDR.fcpbundle/2022-02-06 Kittten/Render Files/Thumbnail Media/E6215C25945ACFB68E41B16364C10910/Frame 107520 - 108543 -saved 2023-05-11 15.09.07

2023/05/11 16:45:02 INFO : - 10 - Dropbox/censoredName1/My Mac (wheatley-4.home)/Movies/SDR.fcpbundle/2022-02-06 Kittten/Render Files/Thumbnail Media/E6215C25945ACFB68E41B16364C10910/Frame 107520 - 108543: Moved into backup dir

2023/05/11 16:45:03 DEBUG : pacer: Reducing sleep to 450.508116ms

2023/05/11 16:45:03 DEBUG : pacer: Reducing sleep to 337.881087ms

2023/05/11 16:45:03 INFO : - 10 - Dropbox/- 10 - Libraries/Ives Screenshots/- 2 - List/Dragon Age - N5/Screenshot20100427095521193.jpg: Moved (server-side) to: - 10 - Dropbox/- 10 - Libraries/Ives Screenshots/- 2 - List/Dragon Age - N5/Screenshot20100427095521193 -saved 2023-05-11 15.09.07.jpg

2023/05/11 16:45:03 INFO : - 10 - Dropbox/- 10 - Libraries/Ives Screenshots/- 2 - List/Dragon Age - N5/Screenshot20100427095521193.jpg: Moved into backup dir

2023/05/11 16:45:05 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/)

2023/05/11 16:45:05 DEBUG : pacer: Rate limited, increasing sleep to 675.762174ms

2023/05/11 16:45:05 DEBUG : pacer: Reducing sleep to 506.82163ms

2023/05/11 16:45:05 INFO : - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/Dragon Age Origins/Dragon Age - Audio/Alistair/Main/30359_m.wav.mp3: Moved (server-side) to: - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/Dragon Age Origins/Dragon Age - Audio/Alistair/Main/30359_m.wav -saved 2023-05-11 15.09.07.mp3

2023/05/11 16:45:05 INFO : - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/Dragon Age Origins/Dragon Age - Audio/Alistair/Main/30359_m.wav.mp3: Moved into backup dir

2023/05/11 16:45:05 DEBUG : pacer: Reducing sleep to 380.116222ms

2023/05/11 16:45:05 DEBUG : pacer: Reducing sleep to 285.087166ms

Sorry, I did have to censor some file names. (Which took a while, is there a fast way to do it?)


This is the full command for that run:

rclone sync  "D:\" "Dropbox:/Only Online/rclone/D - Data"     `
            --backup-dir="Dropbox:/Only Online/rclone/π deleted/D - Data"     `
            --exclude-from "D:\- 10 - Dropbox\- 100 - how it should be\lib\rclone\exclude\exclude.txt"     `
            `
            -vv     `
            --stats-file-name-length 0     `
            --create-empty-src-dirs     `
            --suffix " -saved $(Get-Date -Format "yyyy-MM-dd HH.mm.ss")" --suffix-keep-extension     `
            --delete-excluded     `
            --tpslimit 12 --tpslimit-burst 0     `
            `
            --progress     `
            --log-file=$LogFile     `
            `
            `
			--check-first          `
			--order-by=name,asc     `
            `
            `
            --local-no-check-updated

The stats that rclone gives me while moving to backup dir are like this:

Transferred:      121.063 MiB / 121.063 MiB, 100%, 247.083 KiB/s, ETA 0s
Checks:            345264 / 345272, 100%
Deleted:               74 (files), 0 (dirs)
Renamed:               72
Transferred:           32 / 32, 100%
Elapsed time:      37m7.5s
Checking:
 * - 10 - Dropbox/All Dupes Probably/Libraries (shared folder conflict)/App Docs/Playgrounds/Learn to Code 1.playgroundbook/Contents/Chapters/Document3.playgroundchapter/Pages/Exercise2.playgroundpage/Private
 * - 10 - Dropbox/- 10 - Libraries/Movies Screenshots/- 2 - List/Cellular/Cellular.2004.1080p.mkv_010334.443.png:  0% /1.760Mi, 0/s, -, moving
 * - 10 - Dropbox/- 10 - Libraries/Ives Screenshots/- 2 - List/Bioshock 2/BioShock2 2010-03-04 02-24-07-40.jpg:  0% /271.166Ki, 0/s, -, moving
 * - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 2 - List/Dragon Age - N5/Screenshot20100313104405750.jpg:  0% /539.353Ki, 0/s, -, moving
 * - 10 - Dropbox/- 10 - Libraries/Ives Screenshots/- 2 - List/World of Warcraft SAVE AZEROTH/Dungeon (Northrend) - Ulduar/WoWScrnShot_070709_001624.jpg:  0% /235.271Ki, 0/s, -, moving
 * - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Ives Screenshots/- 3 - Unsorted/OculusScreenshot1586744288.jpeg:  0% /305.043Ki, 0/s, -, moving
 * - 10 - Dropbox/- 10 - Libraries/Movies Screenshots/- 2 - List/Pride and Prejudice/Pride and Prejudice.jpg: deleting
 * - 10 - Dropbox/All Dupes Probably/- 10 - Libraries (view-only conflicts 2022-07-19)/Movies Screenshots/- 2 - List/Stargate Atlantis/vlcsnap-2013-05-15-13h27m37s42.jpg: deleting

None of these indicate how many files are left to move to the backup dir. Unlesss I'm missing something?

That looks like it is the problem. You can see in your log that rclone is spending a lot of time sleeping as it has been told to slow down by dropbox, eg "Rate limited, increasing sleep to 800.903318ms"

Are you running multiple rclone instances from the same IP? It might be that it is being rate limited per source IP address rather than per App ID.

It looks like your transfer is finished except for the renames. I guess rclone expects server side moves to be quick.

Sometimes I have multiple rclone instances running. However, I have not noticed the speed of the server-side move to backup dir to change when other instances are running, compared to when it's the only one.

I have checked with no other operation running, the too_many_write_operations errors are still there, and the sleeping times seem the same.

Also, when both operations are running, I'm not seeing errors or sleeping on the -vv log of the other operation. The other operation is on another machine (macOS), but same IP, uploading a lot of small files from local to Dropbox (same account, different App ID). Only the one doing server-side moves is being limited.


PS
Sorry, this topic was about an ordered log, and it changed to this problem of the slow moving to backup dir. Though they are related, since an ordered log for the move to backup dir would at least give me an indication of progress. A slow process with no ETA ior % ior count of completed/left vs total is... not great.

It looks like Dropbox hates server side moves more than uploads so you'll have to choose a lower --tpslimit I think. Try halving it and see if you can get the too_many_write_operations errors to disappear.

No worries!

The operation finally finished, after something like a week and a half (they were something like 400k files).
Next time I delete many files, I'll try to lower the tpslimit and see if it's faster.
Thank you for looking into this, have a nice Sunday.

1 Like

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