"./operations.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^TestDirMove$'" - Starting (try 2/5)
2025/07/15 01:29:38 DEBUG : Creating backend with remote "TestDropbox:rclone-test-vitocuj9siya"
2025/07/15 01:29:38 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/07/15 01:29:39 DEBUG : Creating backend with remote "/tmp/rclone3960487610"
=== RUN   TestDirMove
    run.go:180: Remote "Dropbox root 'rclone-test-vitocuj9siya'", Local "Local file system at /tmp/rclone3960487610", Modify Window "1s"
2025/07/15 01:29:40 DEBUG : A1/one: Uploading chunk 1/1
2025/07/15 01:29:40 DEBUG : A1/one: Uploading chunk 2/1
2025/07/15 01:29:41 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Adding "A1/one" to batch
2025/07/15 01:29:41 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Batch idle for 500ms so committing
2025/07/15 01:29:41 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Committing sync batch length 1 starting with: A1/one
2025/07/15 01:29:42 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Committed sync batch length 1 starting with: A1/one
2025/07/15 01:29:42 DEBUG : A1/two: Uploading chunk 1/1
2025/07/15 01:29:42 DEBUG : A1/two: Uploading chunk 2/1
2025/07/15 01:29:43 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Adding "A1/two" to batch
2025/07/15 01:29:44 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Batch idle for 500ms so committing
2025/07/15 01:29:44 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Committing sync batch length 1 starting with: A1/two
2025/07/15 01:29:44 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Committed sync batch length 1 starting with: A1/two
2025/07/15 01:29:45 DEBUG : A1/B1/three: Uploading chunk 1/1
2025/07/15 01:29:45 DEBUG : A1/B1/three: Uploading chunk 2/1
2025/07/15 01:29:45 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Adding "A1/B1/three" to batch
2025/07/15 01:29:46 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Batch idle for 500ms so committing
2025/07/15 01:29:46 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Committing sync batch length 1 starting with: A1/B1/three
2025/07/15 01:29:47 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Committed sync batch length 1 starting with: A1/B1/three
2025/07/15 01:29:47 DEBUG : A1/B1/C1/four: Uploading chunk 1/1
2025/07/15 01:29:47 DEBUG : A1/B1/C1/four: Uploading chunk 2/1
2025/07/15 01:29:48 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Adding "A1/B1/C1/four" to batch
2025/07/15 01:29:48 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Batch idle for 500ms so committing
2025/07/15 01:29:48 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Committing sync batch length 1 starting with: A1/B1/C1/four
2025/07/15 01:29:49 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Committed sync batch length 1 starting with: A1/B1/C1/four
2025/07/15 01:29:49 DEBUG : A1/B1/C2/five: Uploading chunk 1/1
2025/07/15 01:29:50 DEBUG : A1/B1/C2/five: Uploading chunk 2/1
2025/07/15 01:29:50 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Adding "A1/B1/C2/five" to batch
2025/07/15 01:29:50 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Batch idle for 500ms so committing
2025/07/15 01:29:50 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Committing sync batch length 1 starting with: A1/B1/C2/five
2025/07/15 01:29:51 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Committed sync batch length 1 starting with: A1/B1/C2/five
2025/07/15 01:29:51 INFO  : A1/B2: Making directory
2025/07/15 01:29:52 INFO  : A1/B1/C3: Making directory
2025/07/15 01:29:58 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/)
2025/07/15 01:29:58 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/07/15 01:29:59 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/..)
2025/07/15 01:29:59 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/07/15 01:29:59 DEBUG : pacer: Reducing sleep to 30ms
2025/07/15 01:30:00 DEBUG : pacer: Reducing sleep to 22.5ms
2025/07/15 01:30:00 DEBUG : pacer: Reducing sleep to 16.875ms
2025/07/15 01:30:00 DEBUG : pacer: Reducing sleep to 12.65625ms
2025/07/15 01:30:01 DEBUG : pacer: Reducing sleep to 10ms
2025/07/15 01:30:02 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/..)
2025/07/15 01:30:02 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/07/15 01:30:03 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/.)
2025/07/15 01:30:03 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/07/15 01:30:03 DEBUG : pacer: Reducing sleep to 30ms
2025/07/15 01:30:03 DEBUG : pacer: Reducing sleep to 22.5ms
2025/07/15 01:30:03 DEBUG : pacer: Reducing sleep to 16.875ms
2025/07/15 01:30:03 DEBUG : pacer: Reducing sleep to 12.65625ms
2025/07/15 01:30:03 DEBUG : pacer: Reducing sleep to 10ms
2025/07/15 01:30:04 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...)
2025/07/15 01:30:04 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/07/15 01:30:04 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/)
2025/07/15 01:30:04 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/07/15 01:30:04 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/..)
2025/07/15 01:30:04 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2025/07/15 01:30:04 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...)
2025/07/15 01:30:04 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2025/07/15 01:30:04 DEBUG : pacer: Reducing sleep to 120ms
2025/07/15 01:30:04 INFO  : A2/B1/three: Moved (server-side) to: A3/B1/three
2025/07/15 01:30:04 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/...)
2025/07/15 01:30:04 DEBUG : pacer: Rate limited, increasing sleep to 240ms
2025/07/15 01:30:04 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/...)
2025/07/15 01:30:04 DEBUG : pacer: Rate limited, increasing sleep to 480ms
2025/07/15 01:30:05 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/)
2025/07/15 01:30:05 DEBUG : pacer: Rate limited, increasing sleep to 960ms
2025/07/15 01:30:05 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/..)
2025/07/15 01:30:05 DEBUG : pacer: Rate limited, increasing sleep to 1.92s
2025/07/15 01:30:05 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/...)
2025/07/15 01:30:05 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/07/15 01:30:06 DEBUG : pacer: Reducing sleep to 1.5s
2025/07/15 01:30:06 INFO  : A2/two: Moved (server-side) to: A3/two
2025/07/15 01:30:07 DEBUG : pacer: Reducing sleep to 1.125s
2025/07/15 01:30:07 INFO  : A2/one: Moved (server-side) to: A3/one
2025/07/15 01:30:08 DEBUG : pacer: Reducing sleep to 843.75ms
2025/07/15 01:30:08 INFO  : A2/B1/C2/five: Moved (server-side) to: A3/B1/C2/five
2025/07/15 01:30:09 DEBUG : pacer: low level retry 4/10 (error too_many_write_operations/.)
2025/07/15 01:30:09 DEBUG : pacer: Rate limited, increasing sleep to 1.6875s
2025/07/15 01:30:11 DEBUG : pacer: Reducing sleep to 1.265625s
2025/07/15 01:30:11 INFO  : A2/B1/C1/four: Moved (server-side) to: A3/B1/C1/four
2025/07/15 01:30:11 DEBUG : pacer: Reducing sleep to 949.21875ms
2025/07/15 01:30:13 DEBUG : pacer: Reducing sleep to 711.914062ms
2025/07/15 01:30:14 DEBUG : pacer: Reducing sleep to 533.935546ms
2025/07/15 01:30:14 DEBUG : pacer: Reducing sleep to 400.451659ms
2025/07/15 01:30:15 DEBUG : pacer: Reducing sleep to 300.338744ms
2025/07/15 01:30:16 DEBUG : pacer: Reducing sleep to 225.254058ms
2025/07/15 01:30:16 DEBUG : pacer: Reducing sleep to 168.940543ms
2025/07/15 01:30:16 DEBUG : pacer: Reducing sleep to 126.705407ms
2025/07/15 01:30:17 DEBUG : pacer: Reducing sleep to 95.029055ms
2025/07/15 01:30:17 DEBUG : pacer: Reducing sleep to 71.271791ms
2025/07/15 01:30:17 DEBUG : pacer: Reducing sleep to 53.453843ms
2025/07/15 01:30:18 DEBUG : pacer: Reducing sleep to 40.090382ms
2025/07/15 01:30:18 DEBUG : pacer: Reducing sleep to 30.067786ms
2025/07/15 01:30:18 DEBUG : pacer: Reducing sleep to 22.550839ms
2025/07/15 01:30:19 DEBUG : pacer: Reducing sleep to 16.913129ms
2025/07/15 01:30:19 DEBUG : pacer: Reducing sleep to 12.684846ms
2025/07/15 01:30:19 DEBUG : pacer: Reducing sleep to 10ms
2025/07/15 01:30:21 INFO  : Dropbox root 'rclone-test-vitocuj9siya': Can't DirMove - falling back to file moves: can't move directory - incompatible remotes
2025/07/15 01:30:22 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/..)
2025/07/15 01:30:22 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/07/15 01:30:23 DEBUG : pacer: Reducing sleep to 15ms
2025/07/15 01:30:23 DEBUG : pacer: Reducing sleep to 11.25ms
2025/07/15 01:30:24 DEBUG : pacer: Reducing sleep to 10ms
2025/07/15 01:30:25 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/)
2025/07/15 01:30:25 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/07/15 01:30:25 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/.)
2025/07/15 01:30:25 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/07/15 01:30:26 DEBUG : pacer: Reducing sleep to 30ms
2025/07/15 01:30:26 DEBUG : pacer: Reducing sleep to 22.5ms
2025/07/15 01:30:27 DEBUG : pacer: Reducing sleep to 16.875ms
2025/07/15 01:30:27 DEBUG : pacer: Reducing sleep to 12.65625ms
2025/07/15 01:30:27 DEBUG : pacer: Reducing sleep to 10ms
2025/07/15 01:30:28 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...)
2025/07/15 01:30:28 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/07/15 01:30:28 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...)
2025/07/15 01:30:28 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/07/15 01:30:28 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...)
2025/07/15 01:30:28 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2025/07/15 01:30:28 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/.)
2025/07/15 01:30:28 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2025/07/15 01:30:29 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/...)
2025/07/15 01:30:29 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2025/07/15 01:30:29 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/.)
2025/07/15 01:30:29 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2025/07/15 01:30:29 DEBUG : pacer: Reducing sleep to 480ms
2025/07/15 01:30:29 INFO  : A3/B1/three: Moved (server-side) to: A4/B1/three
2025/07/15 01:30:29 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/..)
2025/07/15 01:30:29 DEBUG : pacer: Rate limited, increasing sleep to 960ms
2025/07/15 01:30:29 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/.)
2025/07/15 01:30:29 DEBUG : pacer: Rate limited, increasing sleep to 1.92s
2025/07/15 01:30:30 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/...)
2025/07/15 01:30:30 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/07/15 01:30:30 DEBUG : pacer: Reducing sleep to 1.5s
2025/07/15 01:30:30 INFO  : A3/two: Moved (server-side) to: A4/two
2025/07/15 01:30:31 DEBUG : pacer: Reducing sleep to 1.125s
2025/07/15 01:30:31 INFO  : A3/B1/C1/four: Moved (server-side) to: A4/B1/C1/four
2025/07/15 01:30:32 DEBUG : pacer: low level retry 4/10 (error too_many_write_operations/.)
2025/07/15 01:30:32 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/07/15 01:30:34 DEBUG : pacer: Reducing sleep to 1.5s
2025/07/15 01:30:34 INFO  : A3/one: Moved (server-side) to: A4/one
2025/07/15 01:30:36 DEBUG : pacer: Reducing sleep to 1.125s
2025/07/15 01:30:36 INFO  : A3/B1/C2/five: Moved (server-side) to: A4/B1/C2/five
2025/07/15 01:30:36 DEBUG : pacer: Reducing sleep to 843.75ms
2025/07/15 01:30:38 DEBUG : pacer: Reducing sleep to 632.8125ms
2025/07/15 01:30:39 DEBUG : pacer: Reducing sleep to 474.609375ms
2025/07/15 01:30:39 DEBUG : pacer: Reducing sleep to 355.957031ms
2025/07/15 01:30:40 DEBUG : pacer: Reducing sleep to 266.967773ms
2025/07/15 01:30:40 DEBUG : pacer: Reducing sleep to 200.225829ms
2025/07/15 01:30:40 DEBUG : pacer: Reducing sleep to 150.169371ms
2025/07/15 01:30:41 DEBUG : pacer: Reducing sleep to 112.627028ms
2025/07/15 01:30:41 DEBUG : pacer: Reducing sleep to 84.470271ms
2025/07/15 01:30:41 DEBUG : pacer: Reducing sleep to 63.352703ms
2025/07/15 01:30:42 DEBUG : pacer: Reducing sleep to 47.514527ms
2025/07/15 01:30:42 DEBUG : pacer: Reducing sleep to 35.635895ms
2025/07/15 01:30:45 DEBUG : pacer: Reducing sleep to 26.726921ms
2025/07/15 01:30:45 DEBUG : pacer: Reducing sleep to 20.04519ms
2025/07/15 01:30:45 DEBUG : pacer: Reducing sleep to 15.033892ms
2025/07/15 01:30:46 DEBUG : pacer: Reducing sleep to 11.275419ms
2025/07/15 01:30:46 DEBUG : pacer: Reducing sleep to 10ms
--- PASS: TestDirMove (81.16s)
PASS
2025/07/15 01:31:00 DEBUG : Dropbox root 'rclone-test-vitocuj9siya': Purge remote
"./operations.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^TestDirMove$'" - Finished OK in 1m22.172248055s (try 2/5)