"./sync.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^TestFixCase$'" - Starting (try 4/5)
2025/10/31 02:10:44 DEBUG : Creating backend with remote "TestDropbox:rclone-test-jojudoj8doko"
2025/10/31 02:10:44 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/10/31 02:10:45 DEBUG : Creating backend with remote "/tmp/rclone3755334245"
=== RUN   TestFixCase
    run.go:185: Remote "Dropbox root 'rclone-test-jojudoj8doko'", Local "Local file system at /tmp/rclone3755334245", Modify Window "1s"
2025/10/31 02:10:46 DEBUG : EXISTING: Uploading chunk 1/1
2025/10/31 02:10:46 DEBUG : EXISTING: Uploading chunk 2/1
2025/10/31 02:10:46 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Adding "EXISTING" to batch
2025/10/31 02:10:47 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Batch idle for 500ms so committing
2025/10/31 02:10:47 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Committing sync batch length 1 starting with: EXISTING
2025/10/31 02:10:48 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Committed sync batch length 1 starting with: EXISTING
2025/10/31 02:10:48 DEBUG : EXISTINGBUTDIFFERENT: Uploading chunk 1/1
2025/10/31 02:10:48 DEBUG : EXISTINGBUTDIFFERENT: Uploading chunk 2/1
2025/10/31 02:10:49 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Adding "EXISTINGBUTDIFFERENT" to batch
2025/10/31 02:10:49 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Batch idle for 500ms so committing
2025/10/31 02:10:49 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Committing sync batch length 1 starting with: EXISTINGBUTDIFFERENT
2025/10/31 02:10:50 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Committed sync batch length 1 starting with: EXISTINGBUTDIFFERENT
2025/10/31 02:10:51 DEBUG : SUBDIRA/subdirb/SUBDIRC/HELLO: Uploading chunk 1/1
2025/10/31 02:10:51 DEBUG : SUBDIRA/subdirb/SUBDIRC/HELLO: Uploading chunk 2/1
2025/10/31 02:10:51 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Adding "SUBDIRA/subdirb/SUBDIRC/HELLO" to batch
2025/10/31 02:10:52 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Batch idle for 500ms so committing
2025/10/31 02:10:52 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Committing sync batch length 1 starting with: SUBDIRA/subdirb/SUBDIRC/HELLO
2025/10/31 02:10:53 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Committed sync batch length 1 starting with: SUBDIRA/subdirb/SUBDIRC/HELLO
2025/10/31 02:10:53 DEBUG : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: Uploading chunk 1/1
2025/10/31 02:10:54 DEBUG : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: Uploading chunk 2/1
2025/10/31 02:10:54 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Adding "SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences" to batch
2025/10/31 02:10:55 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Batch idle for 500ms so committing
2025/10/31 02:10:55 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Committing sync batch length 1 starting with: SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences
2025/10/31 02:10:55 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Committed sync batch length 1 starting with: SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences
2025/10/31 02:10:57 DEBUG : existing: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/10/31 02:10:57 DEBUG : existing: Unchanged skipping
2025/10/31 02:10:57 DEBUG : existingbutdifferent: Sizes differ (src 5 vs dst 8)
2025/10/31 02:10:57 DEBUG : EXISTING: moving to existing-rclone-move-vawamen2
2025/10/31 02:10:57 DEBUG : EXISTINGBUTDIFFERENT: moving to existingbutdifferent-rclone-move-vulijev8
2025/10/31 02:10:58 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...)
2025/10/31 02:10:58 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/10/31 02:10:58 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/)
2025/10/31 02:10:58 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/10/31 02:10:59 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/...)
2025/10/31 02:10:59 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2025/10/31 02:10:59 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/..)
2025/10/31 02:10:59 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2025/10/31 02:10:59 DEBUG : pacer: Reducing sleep to 120ms
2025/10/31 02:10:59 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/.)
2025/10/31 02:10:59 DEBUG : pacer: Rate limited, increasing sleep to 240ms
2025/10/31 02:10:59 DEBUG : pacer: Reducing sleep to 180ms
2025/10/31 02:10:59 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/.)
2025/10/31 02:10:59 DEBUG : pacer: Rate limited, increasing sleep to 360ms
2025/10/31 02:11:00 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/..)
2025/10/31 02:11:00 DEBUG : pacer: Rate limited, increasing sleep to 720ms
2025/10/31 02:11:00 DEBUG : pacer: low level retry 4/10 (error too_many_write_operations/.)
2025/10/31 02:11:00 DEBUG : pacer: Rate limited, increasing sleep to 1.44s
2025/10/31 02:11:00 DEBUG : pacer: Reducing sleep to 1.08s
2025/10/31 02:11:00 INFO  : EXISTING: Moved (server-side) to: existing-rclone-move-vawamen2
2025/10/31 02:11:00 DEBUG : EXISTING: moving to existing
2025/10/31 02:11:00 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/)
2025/10/31 02:11:00 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/10/31 02:11:02 DEBUG : pacer: Reducing sleep to 1.5s
2025/10/31 02:11:02 INFO  : EXISTINGBUTDIFFERENT: Moved (server-side) to: existingbutdifferent-rclone-move-vulijev8
2025/10/31 02:11:02 DEBUG : EXISTINGBUTDIFFERENT: moving to existingbutdifferent
2025/10/31 02:11:06 DEBUG : pacer: Reducing sleep to 1.125s
2025/10/31 02:11:06 INFO  : SUBDIRA: Fixed case by renaming to: subdira
2025/10/31 02:11:06 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/..)
2025/10/31 02:11:06 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/10/31 02:11:07 DEBUG : pacer: Reducing sleep to 1.5s
2025/10/31 02:11:07 DEBUG : pacer: Reducing sleep to 1.125s
2025/10/31 02:11:07 INFO  : existingbutdifferent-rclone-move-vulijev8: Moved (server-side) to: existingbutdifferent
2025/10/31 02:11:07 INFO  : EXISTINGBUTDIFFERENT: Moved (server-side) to: existingbutdifferent
2025/10/31 02:11:07 INFO  : EXISTINGBUTDIFFERENT: Fixed case by renaming to: existingbutdifferent
2025/10/31 02:11:10 DEBUG : pacer: Reducing sleep to 843.75ms
2025/10/31 02:11:10 DEBUG : pacer: Reducing sleep to 632.8125ms
2025/10/31 02:11:10 INFO  : existing-rclone-move-vawamen2: Moved (server-side) to: existing
2025/10/31 02:11:10 INFO  : EXISTING: Moved (server-side) to: existing
2025/10/31 02:11:10 INFO  : EXISTING: Fixed case by renaming to: existing
2025/10/31 02:11:11 DEBUG : pacer: Reducing sleep to 474.609375ms
2025/10/31 02:11:11 DEBUG : existingbutdifferent: Uploading chunk 1/1
2025/10/31 02:11:12 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...)
2025/10/31 02:11:12 DEBUG : pacer: Rate limited, increasing sleep to 949.21875ms
2025/10/31 02:11:12 DEBUG : pacer: Reducing sleep to 711.914062ms
2025/10/31 02:11:12 DEBUG : existingbutdifferent: Uploading chunk 2/1
2025/10/31 02:11:15 DEBUG : pacer: Reducing sleep to 533.935546ms
2025/10/31 02:11:15 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Adding "existingbutdifferent" to batch
2025/10/31 02:11:15 DEBUG : pacer: Reducing sleep to 400.451659ms
2025/10/31 02:11:15 DEBUG : pacer: Reducing sleep to 300.338744ms
2025/10/31 02:11:15 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Batch idle for 500ms so committing
2025/10/31 02:11:15 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Committing sync batch length 1 starting with: existingbutdifferent
2025/10/31 02:11:15 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/..)
2025/10/31 02:11:15 DEBUG : pacer: Rate limited, increasing sleep to 600.677488ms
2025/10/31 02:11:16 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/)
2025/10/31 02:11:16 DEBUG : pacer: Rate limited, increasing sleep to 1.201354976s
2025/10/31 02:11:16 DEBUG : pacer: Reducing sleep to 901.016232ms
2025/10/31 02:11:16 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Committed sync batch length 1 starting with: existingbutdifferent
2025/10/31 02:11:16 DEBUG : existingbutdifferent: dropbox = 876764f8f7cb4581b40dd4a7a1be217b2c58ae386ca01c86ea0b30bba6d050ed OK
2025/10/31 02:11:16 INFO  : existingbutdifferent: Copied (replaced existing)
2025/10/31 02:11:18 DEBUG : pacer: Reducing sleep to 675.762174ms
2025/10/31 02:11:18 INFO  : SUBDIRA/subdirb: Fixed case by renaming to: subdira/subdirb
2025/10/31 02:11:18 DEBUG : pacer: Reducing sleep to 506.82163ms
2025/10/31 02:11:19 DEBUG : pacer: Reducing sleep to 380.116222ms
2025/10/31 02:11:20 DEBUG : pacer: Reducing sleep to 285.087166ms
2025/10/31 02:11:20 DEBUG : pacer: Reducing sleep to 213.815374ms
2025/10/31 02:11:21 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/)
2025/10/31 02:11:21 DEBUG : pacer: Rate limited, increasing sleep to 427.630748ms
2025/10/31 02:11:23 DEBUG : pacer: Reducing sleep to 320.723061ms
2025/10/31 02:11:23 INFO  : SUBDIRA/subdirb/SUBDIRC: Fixed case by renaming to: subdira/subdirb/subdirc
2025/10/31 02:11:23 DEBUG : pacer: Reducing sleep to 240.542295ms
2025/10/31 02:11:23 DEBUG : subdira/subdirb/subdirc/hello: Sizes differ (src 5 vs dst 8)
2025/10/31 02:11:23 DEBUG : pacer: Reducing sleep to 180.406721ms
2025/10/31 02:11:23 DEBUG : pacer: Reducing sleep to 135.30504ms
2025/10/31 02:11:23 DEBUG : SUBDIRA/subdirb/SUBDIRC/HELLO: moving to subdira/subdirb/subdirc/hello-rclone-move-vaputug1
2025/10/31 02:11:24 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...)
2025/10/31 02:11:24 DEBUG : pacer: Rate limited, increasing sleep to 270.61008ms
2025/10/31 02:11:24 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/)
2025/10/31 02:11:24 DEBUG : pacer: Rate limited, increasing sleep to 541.22016ms
2025/10/31 02:11:25 DEBUG : pacer: Reducing sleep to 405.91512ms
2025/10/31 02:11:25 DEBUG : pacer: Reducing sleep to 304.43634ms
2025/10/31 02:11:26 DEBUG : pacer: Reducing sleep to 228.327255ms
2025/10/31 02:11:26 INFO  : SUBDIRA/subdirb/SUBDIRC/HELLO: Moved (server-side) to: subdira/subdirb/subdirc/hello-rclone-move-vaputug1
2025/10/31 02:11:26 DEBUG : SUBDIRA/subdirb/SUBDIRC/HELLO: moving to subdira/subdirb/subdirc/hello
2025/10/31 02:11:26 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/.)
2025/10/31 02:11:26 DEBUG : pacer: Rate limited, increasing sleep to 456.65451ms
2025/10/31 02:11:26 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/)
2025/10/31 02:11:26 DEBUG : pacer: Rate limited, increasing sleep to 913.30902ms
2025/10/31 02:11:27 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/...)
2025/10/31 02:11:27 DEBUG : pacer: Rate limited, increasing sleep to 1.82661804s
2025/10/31 02:11:27 DEBUG : pacer: Reducing sleep to 1.36996353s
2025/10/31 02:11:27 INFO  : subdira/subdirb/subdirc/hello-rclone-move-vaputug1: Moved (server-side) to: subdira/subdirb/subdirc/hello
2025/10/31 02:11:27 INFO  : SUBDIRA/subdirb/SUBDIRC/HELLO: Moved (server-side) to: subdira/subdirb/subdirc/hello
2025/10/31 02:11:27 INFO  : SUBDIRA/subdirb/SUBDIRC/HELLO: Fixed case by renaming to: subdira/subdirb/subdirc/hello
2025/10/31 02:11:29 DEBUG : pacer: Reducing sleep to 1.027472647s
2025/10/31 02:11:29 DEBUG : subdira/subdirb/subdirc/hello: Uploading chunk 1/1
2025/10/31 02:11:29 DEBUG : pacer: Reducing sleep to 770.604485ms
2025/10/31 02:11:29 INFO  : SUBDIRA/subdirb/SUBDIRC/subdird: Fixed case by renaming to: subdira/subdirb/subdirc/subdird
2025/10/31 02:11:30 DEBUG : pacer: Reducing sleep to 577.953363ms
2025/10/31 02:11:30 DEBUG : subdira/subdirb/subdirc/hello: Uploading chunk 2/1
2025/10/31 02:11:31 DEBUG : pacer: Reducing sleep to 433.465022ms
2025/10/31 02:11:31 DEBUG : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: Sizes differ (src 5 vs dst 8)
2025/10/31 02:11:31 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Waiting for checks to finish
2025/10/31 02:11:32 DEBUG : pacer: Reducing sleep to 325.098766ms
2025/10/31 02:11:32 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Adding "subdira/subdirb/subdirc/hello" to batch
2025/10/31 02:11:32 DEBUG : pacer: Reducing sleep to 243.824074ms
2025/10/31 02:11:32 DEBUG : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: moving to subdira/subdirb/subdirc/subdird/filewithoutcasedifferences-rclone-move-mixidan9
2025/10/31 02:11:32 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Batch idle for 500ms so committing
2025/10/31 02:11:32 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Committing sync batch length 1 starting with: subdira/subdirb/subdirc/hello
2025/10/31 02:11:33 DEBUG : pacer: Reducing sleep to 182.868055ms
2025/10/31 02:11:33 INFO  : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: Moved (server-side) to: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences-rclone-move-mixidan9
2025/10/31 02:11:33 DEBUG : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: moving to subdira/subdirb/subdirc/subdird/filewithoutcasedifferences
2025/10/31 02:11:34 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/.)
2025/10/31 02:11:34 DEBUG : pacer: Rate limited, increasing sleep to 365.73611ms
2025/10/31 02:11:34 DEBUG : pacer: Reducing sleep to 274.302082ms
2025/10/31 02:11:34 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Committed sync batch length 1 starting with: subdira/subdirb/subdirc/hello
2025/10/31 02:11:34 DEBUG : subdira/subdirb/subdirc/hello: dropbox = 876764f8f7cb4581b40dd4a7a1be217b2c58ae386ca01c86ea0b30bba6d050ed OK
2025/10/31 02:11:34 INFO  : subdira/subdirb/subdirc/hello: Copied (replaced existing)
2025/10/31 02:11:35 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/.)
2025/10/31 02:11:35 DEBUG : pacer: Rate limited, increasing sleep to 548.604164ms
2025/10/31 02:11:36 DEBUG : pacer: Reducing sleep to 411.453123ms
2025/10/31 02:11:36 INFO  : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences-rclone-move-mixidan9: Moved (server-side) to: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences
2025/10/31 02:11:36 INFO  : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: Moved (server-side) to: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences
2025/10/31 02:11:36 INFO  : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: Fixed case by renaming to: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences
2025/10/31 02:11:36 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Waiting for transfers to finish
2025/10/31 02:11:36 DEBUG : pacer: Reducing sleep to 308.589842ms
2025/10/31 02:11:36 DEBUG : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: Uploading chunk 1/1
2025/10/31 02:11:37 DEBUG : pacer: Reducing sleep to 231.442381ms
2025/10/31 02:11:37 DEBUG : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: Uploading chunk 2/1
2025/10/31 02:11:37 DEBUG : pacer: Reducing sleep to 173.581785ms
2025/10/31 02:11:37 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Adding "subdira/subdirb/subdirc/subdird/filewithoutcasedifferences" to batch
2025/10/31 02:11:38 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Batch idle for 500ms so committing
2025/10/31 02:11:38 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Committing sync batch length 1 starting with: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences
2025/10/31 02:11:39 DEBUG : pacer: Reducing sleep to 130.186338ms
2025/10/31 02:11:39 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Committed sync batch length 1 starting with: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences
2025/10/31 02:11:39 DEBUG : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: dropbox = 876764f8f7cb4581b40dd4a7a1be217b2c58ae386ca01c86ea0b30bba6d050ed OK
2025/10/31 02:11:39 INFO  : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: Copied (replaced existing)
2025/10/31 02:11:39 DEBUG : Waiting for deletions to finish
2025/10/31 02:11:39 DEBUG : pacer: Reducing sleep to 97.639753ms
2025/10/31 02:11:39 DEBUG : pacer: Reducing sleep to 73.229814ms
2025/10/31 02:11:40 DEBUG : pacer: Reducing sleep to 54.92236ms
2025/10/31 02:11:40 DEBUG : pacer: Reducing sleep to 41.19177ms
2025/10/31 02:11:40 DEBUG : pacer: Reducing sleep to 30.893827ms
2025/10/31 02:11:40 DEBUG : pacer: Reducing sleep to 23.17037ms
2025/10/31 02:11:41 DEBUG : pacer: Reducing sleep to 17.377777ms
2025/10/31 02:11:41 DEBUG : pacer: Reducing sleep to 13.033332ms
2025/10/31 02:11:42 DEBUG : pacer: Reducing sleep to 10ms
--- PASS: TestFixCase (64.79s)
PASS
2025/10/31 02:11:49 DEBUG : Dropbox root 'rclone-test-jojudoj8doko': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^TestFixCase$'" - Finished OK in 1m5.890303765s (try 4/5)