"./operations.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^(TestCheckSizeOnly|TestDirMove)$'" - Starting (try 2/5) 2025/02/20 03:30:09 DEBUG : Creating backend with remote "TestDropbox:rclone-test-vokuvov6nivu" 2025/02/20 03:30:09 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/02/20 03:30:09 DEBUG : Creating backend with remote "/tmp/rclone3200691353" === RUN TestCheckSizeOnly run.go:180: Remote "Dropbox root 'rclone-test-vokuvov6nivu'", Local "Local file system at /tmp/rclone3200691353", Modify Window "1s" 2025/02/20 03:30:10 DEBUG : rutabaga: Uploading chunk 1/1 2025/02/20 03:30:10 DEBUG : rutabaga: Uploading chunk 2/1 2025/02/20 03:30:11 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Adding "rutabaga" to batch 2025/02/20 03:30:11 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Batch idle for 500ms so committing 2025/02/20 03:30:11 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Committing sync batch length 1 starting with: rutabaga 2025/02/20 03:30:12 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Committed sync batch length 1 starting with: rutabaga === RUN TestCheckSizeOnly/1 === RUN TestCheckSizeOnly/2 2025/02/20 03:30:13 DEBUG : empty space: Uploading chunk 1/1 2025/02/20 03:30:14 DEBUG : empty space: Uploading chunk 2/1 2025/02/20 03:30:14 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Adding "empty space" to batch 2025/02/20 03:30:14 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Batch idle for 500ms so committing 2025/02/20 03:30:14 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Committing sync batch length 1 starting with: empty space 2025/02/20 03:30:15 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Committed sync batch length 1 starting with: empty space === RUN TestCheckSizeOnly/3 2025/02/20 03:30:16 DEBUG : potato2: Uploading chunk 1/1 2025/02/20 03:30:16 DEBUG : potato2: Uploading chunk 2/1 2025/02/20 03:30:17 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Adding "potato2" to batch 2025/02/20 03:30:17 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Batch idle for 500ms so committing 2025/02/20 03:30:17 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Committing sync batch length 1 starting with: potato2 2025/02/20 03:30:18 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Committed sync batch length 1 starting with: potato2 === RUN TestCheckSizeOnly/4 === RUN TestCheckSizeOnly/5 2025/02/20 03:30:19 DEBUG : remotepotato: Uploading chunk 1/1 2025/02/20 03:30:19 DEBUG : remotepotato: Uploading chunk 2/1 2025/02/20 03:30:20 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Adding "remotepotato" to batch 2025/02/20 03:30:20 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Batch idle for 500ms so committing 2025/02/20 03:30:20 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Committing sync batch length 1 starting with: remotepotato 2025/02/20 03:30:21 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Committed sync batch length 1 starting with: remotepotato === RUN TestCheckSizeOnly/6 === RUN TestCheckSizeOnly/7 --- PASS: TestCheckSizeOnly (16.41s) --- PASS: TestCheckSizeOnly/1 (0.23s) --- PASS: TestCheckSizeOnly/2 (0.24s) --- PASS: TestCheckSizeOnly/3 (0.25s) --- PASS: TestCheckSizeOnly/4 (0.32s) --- PASS: TestCheckSizeOnly/5 (0.22s) --- PASS: TestCheckSizeOnly/6 (0.22s) --- PASS: TestCheckSizeOnly/7 (0.23s) === RUN TestDirMove run.go:180: Remote "Dropbox root 'rclone-test-vokuvov6nivu'", Local "Local file system at /tmp/rclone3200691353", Modify Window "1s" 2025/02/20 03:30:26 DEBUG : A1/one: Uploading chunk 1/1 2025/02/20 03:30:27 DEBUG : A1/one: Uploading chunk 2/1 2025/02/20 03:30:27 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Adding "A1/one" to batch 2025/02/20 03:30:27 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Batch idle for 500ms so committing 2025/02/20 03:30:27 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Committing sync batch length 1 starting with: A1/one 2025/02/20 03:30:28 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Committed sync batch length 1 starting with: A1/one 2025/02/20 03:30:28 DEBUG : A1/two: Uploading chunk 1/1 2025/02/20 03:30:29 DEBUG : A1/two: Uploading chunk 2/1 2025/02/20 03:30:29 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Adding "A1/two" to batch 2025/02/20 03:30:30 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Batch idle for 500ms so committing 2025/02/20 03:30:30 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Committing sync batch length 1 starting with: A1/two 2025/02/20 03:30:31 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Committed sync batch length 1 starting with: A1/two 2025/02/20 03:30:31 DEBUG : A1/B1/three: Uploading chunk 1/1 2025/02/20 03:30:31 DEBUG : A1/B1/three: Uploading chunk 2/1 2025/02/20 03:30:32 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Adding "A1/B1/three" to batch 2025/02/20 03:30:32 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Batch idle for 500ms so committing 2025/02/20 03:30:32 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Committing sync batch length 1 starting with: A1/B1/three 2025/02/20 03:30:33 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Committed sync batch length 1 starting with: A1/B1/three 2025/02/20 03:30:34 DEBUG : A1/B1/C1/four: Uploading chunk 1/1 2025/02/20 03:30:34 DEBUG : A1/B1/C1/four: Uploading chunk 2/1 2025/02/20 03:30:34 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Adding "A1/B1/C1/four" to batch 2025/02/20 03:30:35 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Batch idle for 500ms so committing 2025/02/20 03:30:35 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Committing sync batch length 1 starting with: A1/B1/C1/four 2025/02/20 03:30:36 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Committed sync batch length 1 starting with: A1/B1/C1/four 2025/02/20 03:30:36 DEBUG : A1/B1/C2/five: Uploading chunk 1/1 2025/02/20 03:30:37 DEBUG : A1/B1/C2/five: Uploading chunk 2/1 2025/02/20 03:30:37 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Adding "A1/B1/C2/five" to batch 2025/02/20 03:30:38 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Batch idle for 500ms so committing 2025/02/20 03:30:38 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Committing sync batch length 1 starting with: A1/B1/C2/five 2025/02/20 03:30:38 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Committed sync batch length 1 starting with: A1/B1/C2/five 2025/02/20 03:30:38 INFO : A1/B2: Making directory 2025/02/20 03:30:39 INFO : A1/B1/C3: Making directory 2025/02/20 03:30:52 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...) 2025/02/20 03:30:52 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/02/20 03:30:52 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/) 2025/02/20 03:30:52 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2025/02/20 03:30:52 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/..) 2025/02/20 03:30:52 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2025/02/20 03:30:53 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/...) 2025/02/20 03:30:53 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2025/02/20 03:30:53 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/..) 2025/02/20 03:30:53 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2025/02/20 03:30:53 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/..) 2025/02/20 03:30:53 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2025/02/20 03:30:53 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/) 2025/02/20 03:30:53 DEBUG : pacer: Rate limited, increasing sleep to 1.28s 2025/02/20 03:30:53 DEBUG : pacer: Reducing sleep to 960ms 2025/02/20 03:30:53 INFO : A2/one: Moved (server-side) to: A3/one 2025/02/20 03:30:53 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/) 2025/02/20 03:30:53 DEBUG : pacer: Rate limited, increasing sleep to 1.92s 2025/02/20 03:30:54 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/) 2025/02/20 03:30:54 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/02/20 03:30:54 DEBUG : pacer: Reducing sleep to 1.5s 2025/02/20 03:30:54 INFO : A2/B1/C2/five: Moved (server-side) to: A3/B1/C2/five 2025/02/20 03:30:57 DEBUG : pacer: Reducing sleep to 1.125s 2025/02/20 03:30:57 INFO : A2/B1/C1/four: Moved (server-side) to: A3/B1/C1/four 2025/02/20 03:30:58 DEBUG : pacer: Reducing sleep to 843.75ms 2025/02/20 03:30:58 INFO : A2/two: Moved (server-side) to: A3/two 2025/02/20 03:31:00 DEBUG : pacer: Reducing sleep to 632.8125ms 2025/02/20 03:31:00 INFO : A2/B1/three: Moved (server-side) to: A3/B1/three 2025/02/20 03:31:10 DEBUG : pacer: Reducing sleep to 474.609375ms 2025/02/20 03:31:11 DEBUG : pacer: Reducing sleep to 355.957031ms 2025/02/20 03:31:11 DEBUG : pacer: Reducing sleep to 266.967773ms 2025/02/20 03:31:12 DEBUG : pacer: Reducing sleep to 200.225829ms 2025/02/20 03:31:12 DEBUG : pacer: Reducing sleep to 150.169371ms 2025/02/20 03:31:13 DEBUG : pacer: Reducing sleep to 112.627028ms 2025/02/20 03:31:13 DEBUG : pacer: Reducing sleep to 84.470271ms 2025/02/20 03:31:13 DEBUG : pacer: Reducing sleep to 63.352703ms 2025/02/20 03:31:14 DEBUG : pacer: Reducing sleep to 47.514527ms 2025/02/20 03:31:15 DEBUG : pacer: Reducing sleep to 35.635895ms 2025/02/20 03:31:15 DEBUG : pacer: Reducing sleep to 26.726921ms 2025/02/20 03:31:16 DEBUG : pacer: Reducing sleep to 20.04519ms 2025/02/20 03:31:16 DEBUG : pacer: Reducing sleep to 15.033892ms 2025/02/20 03:31:16 DEBUG : pacer: Reducing sleep to 11.275419ms 2025/02/20 03:31:17 DEBUG : pacer: Reducing sleep to 10ms 2025/02/20 03:31:19 INFO : Dropbox root 'rclone-test-vokuvov6nivu': Can't DirMove - falling back to file moves: can't move directory - incompatible remotes 2025/02/20 03:31:26 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/) 2025/02/20 03:31:26 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/02/20 03:31:26 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/) 2025/02/20 03:31:26 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2025/02/20 03:31:26 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...) 2025/02/20 03:31:26 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2025/02/20 03:31:26 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/..) 2025/02/20 03:31:26 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2025/02/20 03:31:27 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/..) 2025/02/20 03:31:27 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2025/02/20 03:31:27 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/..) 2025/02/20 03:31:27 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2025/02/20 03:31:27 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/...) 2025/02/20 03:31:27 DEBUG : pacer: Rate limited, increasing sleep to 1.28s 2025/02/20 03:31:27 DEBUG : pacer: Reducing sleep to 960ms 2025/02/20 03:31:27 INFO : A3/B1/C1/four: Moved (server-side) to: A4/B1/C1/four 2025/02/20 03:31:27 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/...) 2025/02/20 03:31:27 DEBUG : pacer: Rate limited, increasing sleep to 1.92s 2025/02/20 03:31:28 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/) 2025/02/20 03:31:28 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/02/20 03:31:28 DEBUG : pacer: Reducing sleep to 1.5s 2025/02/20 03:31:28 INFO : A3/two: Moved (server-side) to: A4/two 2025/02/20 03:31:30 DEBUG : pacer: Reducing sleep to 1.125s 2025/02/20 03:31:30 INFO : A3/B1/C2/five: Moved (server-side) to: A4/B1/C2/five 2025/02/20 03:31:31 DEBUG : pacer: Reducing sleep to 843.75ms 2025/02/20 03:31:31 INFO : A3/B1/three: Moved (server-side) to: A4/B1/three 2025/02/20 03:31:33 DEBUG : pacer: Reducing sleep to 632.8125ms 2025/02/20 03:31:33 INFO : A3/one: Moved (server-side) to: A4/one 2025/02/20 03:31:33 DEBUG : pacer: Reducing sleep to 474.609375ms 2025/02/20 03:31:33 DEBUG : pacer: Reducing sleep to 355.957031ms 2025/02/20 03:31:34 DEBUG : pacer: Reducing sleep to 266.967773ms 2025/02/20 03:31:35 DEBUG : pacer: Reducing sleep to 200.225829ms 2025/02/20 03:31:35 DEBUG : pacer: Reducing sleep to 150.169371ms 2025/02/20 03:31:36 DEBUG : pacer: Reducing sleep to 112.627028ms 2025/02/20 03:31:36 DEBUG : pacer: Reducing sleep to 84.470271ms 2025/02/20 03:31:36 DEBUG : pacer: Reducing sleep to 63.352703ms 2025/02/20 03:31:37 DEBUG : pacer: Reducing sleep to 47.514527ms 2025/02/20 03:31:38 DEBUG : pacer: Reducing sleep to 35.635895ms 2025/02/20 03:31:38 DEBUG : pacer: Reducing sleep to 26.726921ms 2025/02/20 03:31:39 DEBUG : pacer: Reducing sleep to 20.04519ms 2025/02/20 03:31:39 DEBUG : pacer: Reducing sleep to 15.033892ms 2025/02/20 03:31:39 DEBUG : pacer: Reducing sleep to 11.275419ms 2025/02/20 03:31:40 DEBUG : pacer: Reducing sleep to 10ms --- PASS: TestDirMove (91.57s) PASS 2025/02/20 03:31:57 DEBUG : Dropbox root 'rclone-test-vokuvov6nivu': Purge remote "./operations.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^(TestCheckSizeOnly|TestDirMove)$'" - Finished OK in 1m49.090449215s (try 2/5)