"./operations.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^TestDirMove$'" - Starting (try 2/5)
2025/03/22 05:56:27 DEBUG : Creating backend with remote "TestDropbox:rclone-test-cixetaf4sahe"
2025/03/22 05:56:27 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/03/22 05:56:28 DEBUG : Creating backend with remote "/tmp/rclone2417204820"
=== RUN   TestDirMove
    run.go:180: Remote "Dropbox root 'rclone-test-cixetaf4sahe'", Local "Local file system at /tmp/rclone2417204820", Modify Window "1s"
2025/03/22 05:56:29 DEBUG : A1/one: Uploading chunk 1/1
2025/03/22 05:56:30 DEBUG : A1/one: Uploading chunk 2/1
2025/03/22 05:56:30 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Adding "A1/one" to batch
2025/03/22 05:56:31 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Batch idle for 500ms so committing
2025/03/22 05:56:31 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Committing sync batch length 1 starting with: A1/one
2025/03/22 05:56:31 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Committed sync batch length 1 starting with: A1/one
2025/03/22 05:56:32 DEBUG : A1/two: Uploading chunk 1/1
2025/03/22 05:56:32 DEBUG : A1/two: Uploading chunk 2/1
2025/03/22 05:56:33 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Adding "A1/two" to batch
2025/03/22 05:56:33 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Batch idle for 500ms so committing
2025/03/22 05:56:33 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Committing sync batch length 1 starting with: A1/two
2025/03/22 05:56:34 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Committed sync batch length 1 starting with: A1/two
2025/03/22 05:56:34 DEBUG : A1/B1/three: Uploading chunk 1/1
2025/03/22 05:56:35 DEBUG : A1/B1/three: Uploading chunk 2/1
2025/03/22 05:56:36 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Adding "A1/B1/three" to batch
2025/03/22 05:56:36 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Batch idle for 500ms so committing
2025/03/22 05:56:36 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Committing sync batch length 1 starting with: A1/B1/three
2025/03/22 05:56:37 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Committed sync batch length 1 starting with: A1/B1/three
2025/03/22 05:56:37 DEBUG : A1/B1/C1/four: Uploading chunk 1/1
2025/03/22 05:56:38 DEBUG : A1/B1/C1/four: Uploading chunk 2/1
2025/03/22 05:56:38 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Adding "A1/B1/C1/four" to batch
2025/03/22 05:56:39 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Batch idle for 500ms so committing
2025/03/22 05:56:39 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Committing sync batch length 1 starting with: A1/B1/C1/four
2025/03/22 05:56:39 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Committed sync batch length 1 starting with: A1/B1/C1/four
2025/03/22 05:56:40 DEBUG : A1/B1/C2/five: Uploading chunk 1/1
2025/03/22 05:56:40 DEBUG : A1/B1/C2/five: Uploading chunk 2/1
2025/03/22 05:56:41 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Adding "A1/B1/C2/five" to batch
2025/03/22 05:56:41 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Batch idle for 500ms so committing
2025/03/22 05:56:41 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Committing sync batch length 1 starting with: A1/B1/C2/five
2025/03/22 05:56:42 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Committed sync batch length 1 starting with: A1/B1/C2/five
2025/03/22 05:56:42 INFO  : A1/B2: Making directory
2025/03/22 05:56:43 INFO  : A1/B1/C3: Making directory
2025/03/22 05:56:43 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/.)
2025/03/22 05:56:43 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/03/22 05:56:44 DEBUG : pacer: Reducing sleep to 15ms
2025/03/22 05:56:44 DEBUG : pacer: Reducing sleep to 11.25ms
2025/03/22 05:56:44 DEBUG : pacer: Reducing sleep to 10ms
2025/03/22 05:56:46 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/..)
2025/03/22 05:56:46 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/03/22 05:56:47 DEBUG : pacer: Reducing sleep to 15ms
2025/03/22 05:56:47 DEBUG : pacer: Reducing sleep to 11.25ms
2025/03/22 05:56:48 DEBUG : pacer: Reducing sleep to 10ms
2025/03/22 05:56:54 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/.)
2025/03/22 05:56:54 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/03/22 05:56:54 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/)
2025/03/22 05:56:54 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/03/22 05:56:54 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...)
2025/03/22 05:56:54 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2025/03/22 05:56:54 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/.)
2025/03/22 05:56:54 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2025/03/22 05:56:55 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/..)
2025/03/22 05:56:55 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2025/03/22 05:56:55 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/..)
2025/03/22 05:56:55 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2025/03/22 05:56:55 DEBUG : pacer: Reducing sleep to 480ms
2025/03/22 05:56:55 INFO  : A2/B1/C2/five: Moved (server-side) to: A3/B1/C2/five
2025/03/22 05:56:55 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/..)
2025/03/22 05:56:55 DEBUG : pacer: Rate limited, increasing sleep to 960ms
2025/03/22 05:56:55 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/...)
2025/03/22 05:56:55 DEBUG : pacer: Rate limited, increasing sleep to 1.92s
2025/03/22 05:56:56 DEBUG : pacer: Reducing sleep to 1.44s
2025/03/22 05:56:56 INFO  : A2/B1/C1/four: Moved (server-side) to: A3/B1/C1/four
2025/03/22 05:56:56 DEBUG : pacer: Reducing sleep to 1.08s
2025/03/22 05:56:56 INFO  : A2/B1/three: Moved (server-side) to: A3/B1/three
2025/03/22 05:56:59 DEBUG : pacer: Reducing sleep to 810ms
2025/03/22 05:56:59 INFO  : A2/two: Moved (server-side) to: A3/two
2025/03/22 05:56:59 DEBUG : pacer: Reducing sleep to 607.5ms
2025/03/22 05:56:59 INFO  : A2/one: Moved (server-side) to: A3/one
2025/03/22 05:57:00 DEBUG : pacer: Reducing sleep to 455.625ms
2025/03/22 05:57:01 DEBUG : pacer: Reducing sleep to 341.71875ms
2025/03/22 05:57:02 DEBUG : pacer: Reducing sleep to 256.289062ms
2025/03/22 05:57:02 DEBUG : pacer: Reducing sleep to 192.216796ms
2025/03/22 05:57:02 DEBUG : pacer: Reducing sleep to 144.162597ms
2025/03/22 05:57:03 DEBUG : pacer: Reducing sleep to 108.121947ms
2025/03/22 05:57:03 DEBUG : pacer: Reducing sleep to 81.09146ms
2025/03/22 05:57:04 DEBUG : pacer: Reducing sleep to 60.818595ms
2025/03/22 05:57:04 DEBUG : pacer: Reducing sleep to 45.613946ms
2025/03/22 05:57:04 DEBUG : pacer: Reducing sleep to 34.210459ms
2025/03/22 05:57:05 DEBUG : pacer: Reducing sleep to 25.657844ms
2025/03/22 05:57:05 DEBUG : pacer: Reducing sleep to 19.243383ms
2025/03/22 05:57:06 DEBUG : pacer: Reducing sleep to 14.432537ms
2025/03/22 05:57:06 DEBUG : pacer: Reducing sleep to 10.824402ms
2025/03/22 05:57:07 DEBUG : pacer: Reducing sleep to 10ms
2025/03/22 05:57:09 INFO  : Dropbox root 'rclone-test-cixetaf4sahe': Can't DirMove - falling back to file moves: can't move directory - incompatible remotes
2025/03/22 05:57:13 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...)
2025/03/22 05:57:13 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/03/22 05:57:14 DEBUG : pacer: Reducing sleep to 15ms
2025/03/22 05:57:14 DEBUG : pacer: Reducing sleep to 11.25ms
2025/03/22 05:57:15 DEBUG : pacer: Reducing sleep to 10ms
2025/03/22 05:57:15 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/)
2025/03/22 05:57:15 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/03/22 05:57:15 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...)
2025/03/22 05:57:15 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/03/22 05:57:15 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/)
2025/03/22 05:57:15 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2025/03/22 05:57:15 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/..)
2025/03/22 05:57:15 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2025/03/22 05:57:16 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/...)
2025/03/22 05:57:16 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2025/03/22 05:57:16 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/.)
2025/03/22 05:57:16 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2025/03/22 05:57:16 DEBUG : pacer: Reducing sleep to 480ms
2025/03/22 05:57:16 INFO  : A3/B1/C1/four: Moved (server-side) to: A4/B1/C1/four
2025/03/22 05:57:16 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/.)
2025/03/22 05:57:16 DEBUG : pacer: Rate limited, increasing sleep to 960ms
2025/03/22 05:57:17 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/...)
2025/03/22 05:57:17 DEBUG : pacer: Rate limited, increasing sleep to 1.92s
2025/03/22 05:57:17 DEBUG : pacer: Reducing sleep to 1.44s
2025/03/22 05:57:17 INFO  : A3/B1/three: Moved (server-side) to: A4/B1/three
2025/03/22 05:57:18 DEBUG : pacer: Reducing sleep to 1.08s
2025/03/22 05:57:18 INFO  : A3/two: Moved (server-side) to: A4/two
2025/03/22 05:57:20 DEBUG : pacer: Reducing sleep to 810ms
2025/03/22 05:57:20 INFO  : A3/one: Moved (server-side) to: A4/one
2025/03/22 05:57:20 DEBUG : pacer: low level retry 4/10 (error too_many_write_operations/...)
2025/03/22 05:57:20 DEBUG : pacer: Rate limited, increasing sleep to 1.62s
2025/03/22 05:57:22 DEBUG : pacer: Reducing sleep to 1.215s
2025/03/22 05:57:22 INFO  : A3/B1/C2/five: Moved (server-side) to: A4/B1/C2/five
2025/03/22 05:57:23 DEBUG : pacer: Reducing sleep to 911.25ms
2025/03/22 05:57:24 DEBUG : pacer: Reducing sleep to 683.4375ms
2025/03/22 05:57:25 DEBUG : pacer: Reducing sleep to 512.578125ms
2025/03/22 05:57:26 DEBUG : pacer: Reducing sleep to 384.433593ms
2025/03/22 05:57:27 DEBUG : pacer: Reducing sleep to 288.325194ms
2025/03/22 05:57:27 DEBUG : pacer: Reducing sleep to 216.243895ms
2025/03/22 05:57:28 DEBUG : pacer: Reducing sleep to 162.182921ms
2025/03/22 05:57:28 DEBUG : pacer: Reducing sleep to 121.63719ms
2025/03/22 05:57:29 DEBUG : pacer: Reducing sleep to 91.227892ms
2025/03/22 05:57:29 DEBUG : pacer: Reducing sleep to 68.420919ms
2025/03/22 05:57:29 DEBUG : pacer: Reducing sleep to 51.315689ms
2025/03/22 05:57:30 DEBUG : pacer: Reducing sleep to 38.486766ms
2025/03/22 05:57:30 DEBUG : pacer: Reducing sleep to 28.865074ms
2025/03/22 05:57:30 DEBUG : pacer: Reducing sleep to 21.648805ms
2025/03/22 05:57:31 DEBUG : pacer: Reducing sleep to 16.236603ms
2025/03/22 05:57:31 DEBUG : pacer: Reducing sleep to 12.177452ms
2025/03/22 05:57:32 DEBUG : pacer: Reducing sleep to 10ms
--- PASS: TestDirMove (76.85s)
PASS
2025/03/22 05:57:45 DEBUG : Dropbox root 'rclone-test-cixetaf4sahe': Purge remote
"./operations.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^TestDirMove$'" - Finished OK in 1m18.106103769s (try 2/5)