"./sync.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^TestFixCase$'" - Starting (try 2/5) 2025/04/18 05:32:22 DEBUG : Creating backend with remote "TestDropbox:rclone-test-veqewap5xava" 2025/04/18 05:32:22 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/04/18 05:32:22 DEBUG : Creating backend with remote "/tmp/rclone2433000070" === RUN TestFixCase run.go:180: Remote "Dropbox root 'rclone-test-veqewap5xava'", Local "Local file system at /tmp/rclone2433000070", Modify Window "1s" 2025/04/18 05:32:23 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/) 2025/04/18 05:32:23 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/04/18 05:32:23 DEBUG : pacer: Reducing sleep to 15ms 2025/04/18 05:32:24 DEBUG : pacer: Reducing sleep to 11.25ms 2025/04/18 05:32:24 DEBUG : EXISTING: Uploading chunk 1/1 2025/04/18 05:32:24 DEBUG : pacer: Reducing sleep to 10ms 2025/04/18 05:32:24 DEBUG : EXISTING: Uploading chunk 2/1 2025/04/18 05:32:25 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Adding "EXISTING" to batch 2025/04/18 05:32:25 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Batch idle for 500ms so committing 2025/04/18 05:32:25 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Committing sync batch length 1 starting with: EXISTING 2025/04/18 05:32:26 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Committed sync batch length 1 starting with: EXISTING 2025/04/18 05:32:26 DEBUG : EXISTINGBUTDIFFERENT: Uploading chunk 1/1 2025/04/18 05:32:27 DEBUG : EXISTINGBUTDIFFERENT: Uploading chunk 2/1 2025/04/18 05:32:27 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Adding "EXISTINGBUTDIFFERENT" to batch 2025/04/18 05:32:28 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Batch idle for 500ms so committing 2025/04/18 05:32:28 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Committing sync batch length 1 starting with: EXISTINGBUTDIFFERENT 2025/04/18 05:32:29 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Committed sync batch length 1 starting with: EXISTINGBUTDIFFERENT 2025/04/18 05:32:29 DEBUG : SUBDIRA/subdirb/SUBDIRC/HELLO: Uploading chunk 1/1 2025/04/18 05:32:29 DEBUG : SUBDIRA/subdirb/SUBDIRC/HELLO: Uploading chunk 2/1 2025/04/18 05:32:30 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Adding "SUBDIRA/subdirb/SUBDIRC/HELLO" to batch 2025/04/18 05:32:30 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Batch idle for 500ms so committing 2025/04/18 05:32:30 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Committing sync batch length 1 starting with: SUBDIRA/subdirb/SUBDIRC/HELLO 2025/04/18 05:32:31 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Committed sync batch length 1 starting with: SUBDIRA/subdirb/SUBDIRC/HELLO 2025/04/18 05:32:32 DEBUG : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: Uploading chunk 1/1 2025/04/18 05:32:32 DEBUG : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: Uploading chunk 2/1 2025/04/18 05:32:33 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Adding "SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences" to batch 2025/04/18 05:32:33 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Batch idle for 500ms so committing 2025/04/18 05:32:33 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Committing sync batch length 1 starting with: SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences 2025/04/18 05:32:34 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Committed sync batch length 1 starting with: SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences 2025/04/18 05:32:36 DEBUG : existing: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2025/04/18 05:32:36 DEBUG : existing: Unchanged skipping 2025/04/18 05:32:36 DEBUG : existingbutdifferent: Sizes differ (src 5 vs dst 8) 2025/04/18 05:32:36 DEBUG : EXISTING: moving to existing-rclone-move-jiniwew2 2025/04/18 05:32:36 DEBUG : EXISTINGBUTDIFFERENT: moving to existingbutdifferent-rclone-move-milozup2 2025/04/18 05:32:36 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/..) 2025/04/18 05:32:36 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/04/18 05:32:36 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...) 2025/04/18 05:32:36 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2025/04/18 05:32:37 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/...) 2025/04/18 05:32:37 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2025/04/18 05:32:37 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/) 2025/04/18 05:32:37 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2025/04/18 05:32:37 DEBUG : pacer: Reducing sleep to 120ms 2025/04/18 05:32:37 DEBUG : pacer: Reducing sleep to 90ms 2025/04/18 05:32:37 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/) 2025/04/18 05:32:37 DEBUG : pacer: Rate limited, increasing sleep to 180ms 2025/04/18 05:32:38 DEBUG : pacer: low level retry 4/10 (error too_many_write_operations/...) 2025/04/18 05:32:38 DEBUG : pacer: Rate limited, increasing sleep to 360ms 2025/04/18 05:32:38 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/) 2025/04/18 05:32:38 DEBUG : pacer: Rate limited, increasing sleep to 720ms 2025/04/18 05:32:38 DEBUG : pacer: Reducing sleep to 540ms 2025/04/18 05:32:38 INFO : EXISTING: Moved (server-side) to: existing-rclone-move-jiniwew2 2025/04/18 05:32:38 DEBUG : EXISTING: moving to existing 2025/04/18 05:32:38 DEBUG : pacer: low level retry 5/10 (error too_many_write_operations/...) 2025/04/18 05:32:38 DEBUG : pacer: Rate limited, increasing sleep to 1.08s 2025/04/18 05:32:39 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/) 2025/04/18 05:32:39 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/04/18 05:32:39 DEBUG : pacer: Reducing sleep to 1.5s 2025/04/18 05:32:39 INFO : SUBDIRA: Fixed case by renaming to: subdira 2025/04/18 05:32:40 DEBUG : pacer: low level retry 6/10 (error too_many_write_operations/...) 2025/04/18 05:32:40 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/04/18 05:32:42 DEBUG : pacer: Reducing sleep to 1.5s 2025/04/18 05:32:42 INFO : existing-rclone-move-jiniwew2: Moved (server-side) to: existing 2025/04/18 05:32:42 INFO : EXISTING: Moved (server-side) to: existing 2025/04/18 05:32:42 INFO : EXISTING: Fixed case by renaming to: existing 2025/04/18 05:32:44 DEBUG : pacer: Reducing sleep to 1.125s 2025/04/18 05:32:46 DEBUG : pacer: Reducing sleep to 843.75ms 2025/04/18 05:32:46 INFO : EXISTINGBUTDIFFERENT: Moved (server-side) to: existingbutdifferent-rclone-move-milozup2 2025/04/18 05:32:46 DEBUG : EXISTINGBUTDIFFERENT: moving to existingbutdifferent 2025/04/18 05:32:46 DEBUG : pacer: Reducing sleep to 632.8125ms 2025/04/18 05:32:48 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/..) 2025/04/18 05:32:48 DEBUG : pacer: Rate limited, increasing sleep to 1.265625s 2025/04/18 05:32:48 DEBUG : pacer: Reducing sleep to 949.21875ms 2025/04/18 05:32:48 INFO : existingbutdifferent-rclone-move-milozup2: Moved (server-side) to: existingbutdifferent 2025/04/18 05:32:48 INFO : EXISTINGBUTDIFFERENT: Moved (server-side) to: existingbutdifferent 2025/04/18 05:32:48 INFO : EXISTINGBUTDIFFERENT: Fixed case by renaming to: existingbutdifferent 2025/04/18 05:32:49 DEBUG : pacer: Reducing sleep to 711.914062ms 2025/04/18 05:32:49 DEBUG : pacer: Reducing sleep to 533.935546ms 2025/04/18 05:32:49 DEBUG : existingbutdifferent: Uploading chunk 1/1 2025/04/18 05:32:50 DEBUG : pacer: Reducing sleep to 400.451659ms 2025/04/18 05:32:51 DEBUG : pacer: Reducing sleep to 300.338744ms 2025/04/18 05:32:51 DEBUG : existingbutdifferent: Uploading chunk 2/1 2025/04/18 05:32:52 DEBUG : pacer: Reducing sleep to 225.254058ms 2025/04/18 05:32:52 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Adding "existingbutdifferent" to batch 2025/04/18 05:32:52 DEBUG : pacer: Reducing sleep to 168.940543ms 2025/04/18 05:32:52 INFO : SUBDIRA/subdirb: Fixed case by renaming to: subdira/subdirb 2025/04/18 05:32:52 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Batch idle for 500ms so committing 2025/04/18 05:32:52 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Committing sync batch length 1 starting with: existingbutdifferent 2025/04/18 05:32:53 DEBUG : pacer: Reducing sleep to 126.705407ms 2025/04/18 05:32:53 DEBUG : pacer: Reducing sleep to 95.029055ms 2025/04/18 05:32:53 DEBUG : pacer: Reducing sleep to 71.271791ms 2025/04/18 05:32:53 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Committed sync batch length 1 starting with: existingbutdifferent 2025/04/18 05:32:53 DEBUG : existingbutdifferent: dropbox = 876764f8f7cb4581b40dd4a7a1be217b2c58ae386ca01c86ea0b30bba6d050ed OK 2025/04/18 05:32:53 INFO : existingbutdifferent: Copied (replaced existing) 2025/04/18 05:32:53 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/.) 2025/04/18 05:32:53 DEBUG : pacer: Rate limited, increasing sleep to 142.543582ms 2025/04/18 05:32:54 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/.) 2025/04/18 05:32:54 DEBUG : pacer: Rate limited, increasing sleep to 285.087164ms 2025/04/18 05:32:55 DEBUG : pacer: Reducing sleep to 213.815373ms 2025/04/18 05:32:55 DEBUG : pacer: Reducing sleep to 160.361529ms 2025/04/18 05:32:57 DEBUG : pacer: Reducing sleep to 120.271146ms 2025/04/18 05:32:57 INFO : SUBDIRA/subdirb/SUBDIRC: Fixed case by renaming to: subdira/subdirb/subdirc 2025/04/18 05:32:57 DEBUG : pacer: Reducing sleep to 90.203359ms 2025/04/18 05:32:57 DEBUG : subdira/subdirb/subdirc/hello: Sizes differ (src 5 vs dst 8) 2025/04/18 05:32:57 DEBUG : pacer: Reducing sleep to 67.652519ms 2025/04/18 05:32:57 DEBUG : pacer: Reducing sleep to 50.739389ms 2025/04/18 05:32:57 DEBUG : SUBDIRA/subdirb/SUBDIRC/HELLO: moving to subdira/subdirb/subdirc/hello-rclone-move-nedahif5 2025/04/18 05:32:58 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...) 2025/04/18 05:32:58 DEBUG : pacer: Rate limited, increasing sleep to 101.478778ms 2025/04/18 05:32:58 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/..) 2025/04/18 05:32:58 DEBUG : pacer: Rate limited, increasing sleep to 202.957556ms 2025/04/18 05:32:58 DEBUG : pacer: Reducing sleep to 152.218167ms 2025/04/18 05:32:59 DEBUG : pacer: Reducing sleep to 114.163625ms 2025/04/18 05:32:59 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/.) 2025/04/18 05:32:59 DEBUG : pacer: Rate limited, increasing sleep to 228.32725ms 2025/04/18 05:32:59 DEBUG : pacer: Reducing sleep to 171.245437ms 2025/04/18 05:32:59 INFO : SUBDIRA/subdirb/SUBDIRC/HELLO: Moved (server-side) to: subdira/subdirb/subdirc/hello-rclone-move-nedahif5 2025/04/18 05:32:59 DEBUG : SUBDIRA/subdirb/SUBDIRC/HELLO: moving to subdira/subdirb/subdirc/hello 2025/04/18 05:33:00 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/..) 2025/04/18 05:33:00 DEBUG : pacer: Rate limited, increasing sleep to 342.490874ms 2025/04/18 05:33:00 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/) 2025/04/18 05:33:00 DEBUG : pacer: Rate limited, increasing sleep to 684.981748ms 2025/04/18 05:33:00 DEBUG : pacer: Reducing sleep to 513.736311ms 2025/04/18 05:33:00 INFO : subdira/subdirb/subdirc/hello-rclone-move-nedahif5: Moved (server-side) to: subdira/subdirb/subdirc/hello 2025/04/18 05:33:00 INFO : SUBDIRA/subdirb/SUBDIRC/HELLO: Moved (server-side) to: subdira/subdirb/subdirc/hello 2025/04/18 05:33:00 INFO : SUBDIRA/subdirb/SUBDIRC/HELLO: Fixed case by renaming to: subdira/subdirb/subdirc/hello 2025/04/18 05:33:01 DEBUG : pacer: Reducing sleep to 385.302233ms 2025/04/18 05:33:01 DEBUG : subdira/subdirb/subdirc/hello: Uploading chunk 1/1 2025/04/18 05:33:01 DEBUG : pacer: Reducing sleep to 288.976674ms 2025/04/18 05:33:01 INFO : SUBDIRA/subdirb/SUBDIRC/subdird: Fixed case by renaming to: subdira/subdirb/subdirc/subdird 2025/04/18 05:33:02 DEBUG : pacer: Reducing sleep to 216.732505ms 2025/04/18 05:33:02 DEBUG : subdira/subdirb/subdirc/hello: Uploading chunk 2/1 2025/04/18 05:33:02 DEBUG : pacer: Reducing sleep to 162.549378ms 2025/04/18 05:33:02 DEBUG : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: Sizes differ (src 5 vs dst 8) 2025/04/18 05:33:02 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Waiting for checks to finish 2025/04/18 05:33:02 DEBUG : pacer: Reducing sleep to 121.912033ms 2025/04/18 05:33:02 DEBUG : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: moving to subdira/subdirb/subdirc/subdird/filewithoutcasedifferences-rclone-move-yosagif0 2025/04/18 05:33:03 DEBUG : pacer: Reducing sleep to 91.434024ms 2025/04/18 05:33:03 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Adding "subdira/subdirb/subdirc/hello" to batch 2025/04/18 05:33:03 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...) 2025/04/18 05:33:03 DEBUG : pacer: Rate limited, increasing sleep to 182.868048ms 2025/04/18 05:33:03 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Batch idle for 500ms so committing 2025/04/18 05:33:03 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Committing sync batch length 1 starting with: subdira/subdirb/subdirc/hello 2025/04/18 05:33:03 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/.) 2025/04/18 05:33:03 DEBUG : pacer: Rate limited, increasing sleep to 365.736096ms 2025/04/18 05:33:04 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/...) 2025/04/18 05:33:04 DEBUG : pacer: Rate limited, increasing sleep to 731.472192ms 2025/04/18 05:33:04 DEBUG : pacer: Reducing sleep to 548.604144ms 2025/04/18 05:33:04 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Committed sync batch length 1 starting with: subdira/subdirb/subdirc/hello 2025/04/18 05:33:04 DEBUG : subdira/subdirb/subdirc/hello: dropbox = 876764f8f7cb4581b40dd4a7a1be217b2c58ae386ca01c86ea0b30bba6d050ed OK 2025/04/18 05:33:04 INFO : subdira/subdirb/subdirc/hello: Copied (replaced existing) 2025/04/18 05:33:05 DEBUG : pacer: Reducing sleep to 411.453108ms 2025/04/18 05:33:05 INFO : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: Moved (server-side) to: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences-rclone-move-yosagif0 2025/04/18 05:33:05 DEBUG : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: moving to subdira/subdirb/subdirc/subdird/filewithoutcasedifferences 2025/04/18 05:33:06 DEBUG : pacer: Reducing sleep to 308.589831ms 2025/04/18 05:33:06 INFO : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences-rclone-move-yosagif0: Moved (server-side) to: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences 2025/04/18 05:33:06 INFO : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: Moved (server-side) to: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences 2025/04/18 05:33:06 INFO : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: Fixed case by renaming to: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences 2025/04/18 05:33:06 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Waiting for transfers to finish 2025/04/18 05:33:06 DEBUG : pacer: Reducing sleep to 231.442373ms 2025/04/18 05:33:06 DEBUG : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: Uploading chunk 1/1 2025/04/18 05:33:07 DEBUG : pacer: Reducing sleep to 173.581779ms 2025/04/18 05:33:07 DEBUG : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: Uploading chunk 2/1 2025/04/18 05:33:07 DEBUG : pacer: Reducing sleep to 130.186334ms 2025/04/18 05:33:07 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Adding "subdira/subdirb/subdirc/subdird/filewithoutcasedifferences" to batch 2025/04/18 05:33:08 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Batch idle for 500ms so committing 2025/04/18 05:33:08 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Committing sync batch length 1 starting with: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences 2025/04/18 05:33:09 DEBUG : pacer: Reducing sleep to 97.63975ms 2025/04/18 05:33:09 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Committed sync batch length 1 starting with: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences 2025/04/18 05:33:09 DEBUG : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: dropbox = 876764f8f7cb4581b40dd4a7a1be217b2c58ae386ca01c86ea0b30bba6d050ed OK 2025/04/18 05:33:09 INFO : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: Copied (replaced existing) 2025/04/18 05:33:09 DEBUG : Waiting for deletions to finish 2025/04/18 05:33:09 DEBUG : pacer: Reducing sleep to 73.229812ms 2025/04/18 05:33:09 DEBUG : pacer: Reducing sleep to 54.922359ms 2025/04/18 05:33:10 DEBUG : pacer: Reducing sleep to 41.191769ms 2025/04/18 05:33:10 DEBUG : pacer: Reducing sleep to 30.893826ms 2025/04/18 05:33:10 DEBUG : pacer: Reducing sleep to 23.170369ms 2025/04/18 05:33:10 DEBUG : pacer: Reducing sleep to 17.377776ms 2025/04/18 05:33:11 DEBUG : pacer: Reducing sleep to 13.033332ms 2025/04/18 05:33:12 DEBUG : pacer: Reducing sleep to 10ms --- PASS: TestFixCase (57.29s) PASS 2025/04/18 05:33:19 DEBUG : Dropbox root 'rclone-test-veqewap5xava': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^TestFixCase$'" - Finished OK in 58.364234492s (try 2/5)