"./operations.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^TestDirMove$'" - Starting (try 2/5)
2024/12/29 03:45:07 DEBUG : Creating backend with remote "TestDropbox:rclone-test-bofipot4rubu"
2024/12/29 03:45:07 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/12/29 03:45:07 DEBUG : Creating backend with remote "/tmp/rclone2131202241"
=== RUN   TestDirMove
    run.go:180: Remote "Dropbox root 'rclone-test-bofipot4rubu'", Local "Local file system at /tmp/rclone2131202241", Modify Window "1s"
2024/12/29 03:45:08 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/)
2024/12/29 03:45:08 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2024/12/29 03:45:08 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/..)
2024/12/29 03:45:08 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2024/12/29 03:45:08 DEBUG : pacer: Reducing sleep to 30ms
2024/12/29 03:45:09 DEBUG : pacer: Reducing sleep to 22.5ms
2024/12/29 03:45:09 DEBUG : pacer: Reducing sleep to 16.875ms
2024/12/29 03:45:09 DEBUG : A1/one: Uploading chunk 1/1
2024/12/29 03:45:09 DEBUG : pacer: Reducing sleep to 12.65625ms
2024/12/29 03:45:09 DEBUG : A1/one: Uploading chunk 2/1
2024/12/29 03:45:10 DEBUG : pacer: Reducing sleep to 10ms
2024/12/29 03:45:10 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Adding "A1/one" to batch
2024/12/29 03:45:10 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Batch idle for 500ms so committing
2024/12/29 03:45:10 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Committing sync batch length 1 starting with: A1/one
2024/12/29 03:45:11 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Committed sync batch length 1 starting with: A1/one
2024/12/29 03:45:11 DEBUG : A1/two: Uploading chunk 1/1
2024/12/29 03:45:12 DEBUG : A1/two: Uploading chunk 2/1
2024/12/29 03:45:12 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Adding "A1/two" to batch
2024/12/29 03:45:13 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Batch idle for 500ms so committing
2024/12/29 03:45:13 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Committing sync batch length 1 starting with: A1/two
2024/12/29 03:45:13 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Committed sync batch length 1 starting with: A1/two
2024/12/29 03:45:14 DEBUG : A1/B1/three: Uploading chunk 1/1
2024/12/29 03:45:14 DEBUG : A1/B1/three: Uploading chunk 2/1
2024/12/29 03:45:14 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Adding "A1/B1/three" to batch
2024/12/29 03:45:15 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Batch idle for 500ms so committing
2024/12/29 03:45:15 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Committing sync batch length 1 starting with: A1/B1/three
2024/12/29 03:45:16 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Committed sync batch length 1 starting with: A1/B1/three
2024/12/29 03:45:16 DEBUG : A1/B1/C1/four: Uploading chunk 1/1
2024/12/29 03:45:16 DEBUG : A1/B1/C1/four: Uploading chunk 2/1
2024/12/29 03:45:17 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Adding "A1/B1/C1/four" to batch
2024/12/29 03:45:17 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Batch idle for 500ms so committing
2024/12/29 03:45:17 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Committing sync batch length 1 starting with: A1/B1/C1/four
2024/12/29 03:45:18 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Committed sync batch length 1 starting with: A1/B1/C1/four
2024/12/29 03:45:19 DEBUG : A1/B1/C2/five: Uploading chunk 1/1
2024/12/29 03:45:19 DEBUG : A1/B1/C2/five: Uploading chunk 2/1
2024/12/29 03:45:20 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Adding "A1/B1/C2/five" to batch
2024/12/29 03:45:20 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Batch idle for 500ms so committing
2024/12/29 03:45:20 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Committing sync batch length 1 starting with: A1/B1/C2/five
2024/12/29 03:45:21 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Committed sync batch length 1 starting with: A1/B1/C2/five
2024/12/29 03:45:21 DEBUG : A1/B2: Making directory
2024/12/29 03:45:22 DEBUG : A1/B1/C3: Making directory
2024/12/29 03:45:22 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/..)
2024/12/29 03:45:22 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2024/12/29 03:45:23 DEBUG : pacer: Reducing sleep to 15ms
2024/12/29 03:45:23 DEBUG : pacer: Reducing sleep to 11.25ms
2024/12/29 03:45:23 DEBUG : pacer: Reducing sleep to 10ms
2024/12/29 03:45:24 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/)
2024/12/29 03:45:24 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2024/12/29 03:45:25 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/)
2024/12/29 03:45:25 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2024/12/29 03:45:25 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/..)
2024/12/29 03:45:25 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2024/12/29 03:45:27 DEBUG : pacer: Reducing sleep to 60ms
2024/12/29 03:45:27 DEBUG : pacer: Reducing sleep to 45ms
2024/12/29 03:45:27 DEBUG : pacer: Reducing sleep to 33.75ms
2024/12/29 03:45:28 DEBUG : pacer: Reducing sleep to 25.3125ms
2024/12/29 03:45:28 DEBUG : pacer: Reducing sleep to 18.984375ms
2024/12/29 03:45:28 DEBUG : pacer: Reducing sleep to 14.238281ms
2024/12/29 03:45:28 DEBUG : pacer: Reducing sleep to 10.67871ms
2024/12/29 03:45:28 DEBUG : pacer: Reducing sleep to 10ms
2024/12/29 03:45:32 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...)
2024/12/29 03:45:32 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2024/12/29 03:45:33 DEBUG : pacer: Reducing sleep to 15ms
2024/12/29 03:45:33 DEBUG : pacer: Reducing sleep to 11.25ms
2024/12/29 03:45:33 DEBUG : pacer: Reducing sleep to 10ms
2024/12/29 03:45:34 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/..)
2024/12/29 03:45:34 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2024/12/29 03:45:34 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/..)
2024/12/29 03:45:34 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/.)
2024/12/29 03:45:34 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2024/12/29 03:45:34 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2024/12/29 03:45:34 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...)
2024/12/29 03:45:34 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2024/12/29 03:45:35 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/..)
2024/12/29 03:45:35 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2024/12/29 03:45:35 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/..)
2024/12/29 03:45:35 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2024/12/29 03:45:35 DEBUG : pacer: Reducing sleep to 480ms
2024/12/29 03:45:35 INFO  : A2/two: Moved (server-side) to: A3/two
2024/12/29 03:45:35 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/.)
2024/12/29 03:45:35 DEBUG : pacer: Rate limited, increasing sleep to 960ms
2024/12/29 03:45:35 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/)
2024/12/29 03:45:35 DEBUG : pacer: Rate limited, increasing sleep to 1.92s
2024/12/29 03:45:35 DEBUG : pacer: Reducing sleep to 1.44s
2024/12/29 03:45:35 INFO  : A2/B1/three: Moved (server-side) to: A3/B1/three
2024/12/29 03:45:36 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/...)
2024/12/29 03:45:36 DEBUG : pacer: Rate limited, increasing sleep to 2s
2024/12/29 03:45:38 DEBUG : pacer: Reducing sleep to 1.5s
2024/12/29 03:45:38 INFO  : A2/one: Moved (server-side) to: A3/one
2024/12/29 03:45:40 DEBUG : pacer: Reducing sleep to 1.125s
2024/12/29 03:45:40 INFO  : A2/B1/C2/five: Moved (server-side) to: A3/B1/C2/five
2024/12/29 03:45:42 DEBUG : pacer: Reducing sleep to 843.75ms
2024/12/29 03:45:42 INFO  : A2/B1/C1/four: Moved (server-side) to: A3/B1/C1/four
2024/12/29 03:45:42 DEBUG : pacer: Reducing sleep to 632.8125ms
2024/12/29 03:45:43 DEBUG : pacer: Reducing sleep to 474.609375ms
2024/12/29 03:45:44 DEBUG : pacer: Reducing sleep to 355.957031ms
2024/12/29 03:45:44 DEBUG : pacer: Reducing sleep to 266.967773ms
2024/12/29 03:45:45 DEBUG : pacer: Reducing sleep to 200.225829ms
2024/12/29 03:45:45 DEBUG : pacer: Reducing sleep to 150.169371ms
2024/12/29 03:45:46 DEBUG : pacer: Reducing sleep to 112.627028ms
2024/12/29 03:45:46 DEBUG : pacer: Reducing sleep to 84.470271ms
2024/12/29 03:45:47 DEBUG : pacer: Reducing sleep to 63.352703ms
2024/12/29 03:45:47 DEBUG : pacer: Reducing sleep to 47.514527ms
2024/12/29 03:45:47 DEBUG : pacer: Reducing sleep to 35.635895ms
2024/12/29 03:45:50 DEBUG : pacer: Reducing sleep to 26.726921ms
2024/12/29 03:45:50 DEBUG : pacer: Reducing sleep to 20.04519ms
2024/12/29 03:45:51 DEBUG : pacer: Reducing sleep to 15.033892ms
2024/12/29 03:45:51 DEBUG : pacer: Reducing sleep to 11.275419ms
2024/12/29 03:45:51 DEBUG : pacer: Reducing sleep to 10ms
2024/12/29 03:45:54 INFO  : Dropbox root 'rclone-test-bofipot4rubu': Can't DirMove - falling back to file moves: can't move directory - incompatible remotes
2024/12/29 03:46:01 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/.)
2024/12/29 03:46:01 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2024/12/29 03:46:01 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/.)
2024/12/29 03:46:01 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2024/12/29 03:46:01 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/.)
2024/12/29 03:46:01 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2024/12/29 03:46:01 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/)
2024/12/29 03:46:01 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2024/12/29 03:46:01 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...)
2024/12/29 03:46:01 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2024/12/29 03:46:01 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/...)
2024/12/29 03:46:01 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2024/12/29 03:46:01 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/.)
2024/12/29 03:46:01 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2024/12/29 03:46:01 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/.)
2024/12/29 03:46:01 DEBUG : pacer: Rate limited, increasing sleep to 2s
2024/12/29 03:46:02 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/.)
2024/12/29 03:46:02 DEBUG : pacer: Reducing sleep to 1.5s
2024/12/29 03:46:02 INFO  : A3/B1/three: Moved (server-side) to: A4/B1/three
2024/12/29 03:46:04 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/..)
2024/12/29 03:46:04 DEBUG : pacer: Rate limited, increasing sleep to 2s
2024/12/29 03:46:06 DEBUG : pacer: Reducing sleep to 1.5s
2024/12/29 03:46:06 INFO  : A3/two: Moved (server-side) to: A4/two
2024/12/29 03:46:08 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/...)
2024/12/29 03:46:08 DEBUG : pacer: Rate limited, increasing sleep to 2s
2024/12/29 03:46:09 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/...)
2024/12/29 03:46:11 DEBUG : pacer: low level retry 4/10 (error too_many_write_operations/.)
2024/12/29 03:46:14 DEBUG : pacer: Reducing sleep to 1.5s
2024/12/29 03:46:14 INFO  : A3/one: Moved (server-side) to: A4/one
2024/12/29 03:46:16 DEBUG : pacer: Reducing sleep to 1.125s
2024/12/29 03:46:16 INFO  : A3/B1/C1/four: Moved (server-side) to: A4/B1/C1/four
2024/12/29 03:46:17 DEBUG : pacer: Reducing sleep to 843.75ms
2024/12/29 03:46:17 INFO  : A3/B1/C2/five: Moved (server-side) to: A4/B1/C2/five
2024/12/29 03:46:18 DEBUG : pacer: Reducing sleep to 632.8125ms
2024/12/29 03:46:18 DEBUG : pacer: Reducing sleep to 474.609375ms
2024/12/29 03:46:19 DEBUG : pacer: Reducing sleep to 355.957031ms
2024/12/29 03:46:20 DEBUG : pacer: Reducing sleep to 266.967773ms
2024/12/29 03:46:20 DEBUG : pacer: Reducing sleep to 200.225829ms
2024/12/29 03:46:21 DEBUG : pacer: Reducing sleep to 150.169371ms
2024/12/29 03:46:21 DEBUG : pacer: Reducing sleep to 112.627028ms
2024/12/29 03:46:21 DEBUG : pacer: Reducing sleep to 84.470271ms
2024/12/29 03:46:22 DEBUG : pacer: Reducing sleep to 63.352703ms
2024/12/29 03:46:22 DEBUG : pacer: Reducing sleep to 47.514527ms
2024/12/29 03:46:23 DEBUG : pacer: Reducing sleep to 35.635895ms
2024/12/29 03:46:23 DEBUG : pacer: Reducing sleep to 26.726921ms
2024/12/29 03:46:23 DEBUG : pacer: Reducing sleep to 20.04519ms
2024/12/29 03:46:24 DEBUG : pacer: Reducing sleep to 15.033892ms
2024/12/29 03:46:24 DEBUG : pacer: Reducing sleep to 11.275419ms
2024/12/29 03:46:25 DEBUG : pacer: Reducing sleep to 10ms
--- PASS: TestDirMove (91.85s)
PASS
2024/12/29 03:46:39 DEBUG : Dropbox root 'rclone-test-bofipot4rubu': Purge remote
"./operations.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^TestDirMove$'" - Finished OK in 1m33.103373228s (try 2/5)