"./operations.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^(TestCaseInsensitiveMoveFile|TestCheckSizeOnly|TestCopyFileCopyDest|TestParseSumFile)$'" - Starting (try 2/5) 2026/02/02 06:03:26 DEBUG : Creating backend with remote "TestDropbox:rclone-test-hisobup4sesi" 2026/02/02 06:03:26 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/02/02 06:03:27 DEBUG : Creating backend with remote "/tmp/rclone470285901" === RUN TestCheckSizeOnly run.go:185: Remote "Dropbox root 'rclone-test-hisobup4sesi'", Local "Local file system at /tmp/rclone470285901", Modify Window "1s" 2026/02/02 06:03:28 DEBUG : rutabaga: Uploading chunk 1/1 2026/02/02 06:03:28 DEBUG : rutabaga: Uploading chunk 2/1 2026/02/02 06:03:28 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Adding "rutabaga" to batch 2026/02/02 06:03:29 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Batch idle for 500ms so committing 2026/02/02 06:03:29 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committing sync batch length 1 starting with: rutabaga 2026/02/02 06:03:29 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committed sync batch length 1 starting with: rutabaga === RUN TestCheckSizeOnly/1 === RUN TestCheckSizeOnly/2 2026/02/02 06:03:31 DEBUG : empty space: Uploading chunk 1/1 2026/02/02 06:03:31 DEBUG : empty space: Uploading chunk 2/1 2026/02/02 06:03:31 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Adding "empty space" to batch 2026/02/02 06:03:32 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Batch idle for 500ms so committing 2026/02/02 06:03:32 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committing sync batch length 1 starting with: empty space 2026/02/02 06:03:33 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committed sync batch length 1 starting with: empty space === RUN TestCheckSizeOnly/3 2026/02/02 06:03:34 DEBUG : potato2: Uploading chunk 1/1 2026/02/02 06:03:35 DEBUG : potato2: Uploading chunk 2/1 2026/02/02 06:03:35 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Adding "potato2" to batch 2026/02/02 06:03:36 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Batch idle for 500ms so committing 2026/02/02 06:03:36 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committing sync batch length 1 starting with: potato2 2026/02/02 06:03:37 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committed sync batch length 1 starting with: potato2 === RUN TestCheckSizeOnly/4 === RUN TestCheckSizeOnly/5 2026/02/02 06:03:38 DEBUG : remotepotato: Uploading chunk 1/1 2026/02/02 06:03:39 DEBUG : remotepotato: Uploading chunk 2/1 2026/02/02 06:03:39 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Adding "remotepotato" to batch 2026/02/02 06:03:40 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Batch idle for 500ms so committing 2026/02/02 06:03:40 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committing sync batch length 1 starting with: remotepotato 2026/02/02 06:03:40 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committed sync batch length 1 starting with: remotepotato === RUN TestCheckSizeOnly/6 === RUN TestCheckSizeOnly/7 --- PASS: TestCheckSizeOnly (17.72s) --- PASS: TestCheckSizeOnly/1 (0.51s) --- PASS: TestCheckSizeOnly/2 (0.23s) --- PASS: TestCheckSizeOnly/3 (0.43s) --- PASS: TestCheckSizeOnly/4 (0.52s) --- PASS: TestCheckSizeOnly/5 (0.51s) --- PASS: TestCheckSizeOnly/6 (0.22s) --- PASS: TestCheckSizeOnly/7 (0.23s) === RUN TestParseSumFile run.go:185: Remote "Dropbox root 'rclone-test-hisobup4sesi'", Local "Local file system at /tmp/rclone470285901", Modify Window "1s" 2026/02/02 06:03:44 DEBUG : test.sum: Uploading chunk 1/1 2026/02/02 06:03:45 DEBUG : test.sum: Uploading chunk 2/1 2026/02/02 06:03:45 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Adding "test.sum" to batch 2026/02/02 06:03:46 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Batch idle for 500ms so committing 2026/02/02 06:03:46 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committing sync batch length 1 starting with: test.sum 2026/02/02 06:03:46 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committed sync batch length 1 starting with: test.sum 2026/02/02 06:03:47 NOTICE: test.sum: improperly formatted checksum line 4 2026/02/02 06:03:47 NOTICE: test.sum: improperly formatted checksum line 5 2026/02/02 06:03:47 NOTICE: test.sum: improperly formatted checksum line 6 2026/02/02 06:03:47 NOTICE: test.sum: 2 warning(s) suppressed... 2026/02/02 06:03:48 DEBUG : test.sum: Uploading chunk 1/1 2026/02/02 06:03:48 DEBUG : test.sum: Uploading chunk 2/1 2026/02/02 06:03:49 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Adding "test.sum" to batch 2026/02/02 06:03:49 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Batch idle for 500ms so committing 2026/02/02 06:03:49 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committing sync batch length 1 starting with: test.sum 2026/02/02 06:03:50 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committed sync batch length 1 starting with: test.sum 2026/02/02 06:03:52 NOTICE: test.sum: improperly formatted checksum line 4 2026/02/02 06:03:52 NOTICE: test.sum: improperly formatted checksum line 5 2026/02/02 06:03:52 NOTICE: test.sum: improperly formatted checksum line 6 2026/02/02 06:03:52 NOTICE: test.sum: 2 warning(s) suppressed... --- PASS: TestParseSumFile (8.88s) === RUN TestCopyFileCopyDest run.go:185: Remote "Dropbox root 'rclone-test-hisobup4sesi'", Local "Local file system at /tmp/rclone470285901", Modify Window "1s" 2026/02/02 06:03:53 DEBUG : Creating backend with remote "TestDropbox:rclone-test-hisobup4sesi/dst" 2026/02/02 06:03:54 DEBUG : Creating backend with remote "TestDropbox:rclone-test-hisobup4sesi/CopyDest" 2026/02/02 06:03:55 DEBUG : one: Need to transfer - File not found at Destination 2026/02/02 06:03:56 DEBUG : one: Uploading chunk 1/1 2026/02/02 06:03:56 DEBUG : one: Uploading chunk 2/1 2026/02/02 06:03:56 DEBUG : Dropbox root 'rclone-test-hisobup4sesi/dst': Adding "one" to batch 2026/02/02 06:03:57 DEBUG : Dropbox root 'rclone-test-hisobup4sesi/dst': Batch idle for 500ms so committing 2026/02/02 06:03:57 DEBUG : Dropbox root 'rclone-test-hisobup4sesi/dst': Committing sync batch length 1 starting with: one 2026/02/02 06:03:58 DEBUG : Dropbox root 'rclone-test-hisobup4sesi/dst': Committed sync batch length 1 starting with: one 2026/02/02 06:03:58 DEBUG : one: size = 3 OK 2026/02/02 06:03:58 DEBUG : one: dropbox = fe8d7a873dc48961a6af334c996b2cb3ce37149d5ce9c9253952a54c6a92c1ad OK 2026/02/02 06:03:58 INFO : one: Copied (new) 2026/02/02 06:03:59 DEBUG : one: size = 5 (Local file system at /tmp/rclone470285901) 2026/02/02 06:03:59 DEBUG : one: size = 3 (Dropbox root 'rclone-test-hisobup4sesi/dst') 2026/02/02 06:03:59 DEBUG : one: Sizes differ 2026/02/02 06:03:59 DEBUG : one: Uploading chunk 1/1 2026/02/02 06:03:59 DEBUG : one: Uploading chunk 2/1 2026/02/02 06:04:00 DEBUG : Dropbox root 'rclone-test-hisobup4sesi/dst': Adding "one" to batch 2026/02/02 06:04:00 DEBUG : Dropbox root 'rclone-test-hisobup4sesi/dst': Batch idle for 500ms so committing 2026/02/02 06:04:00 DEBUG : Dropbox root 'rclone-test-hisobup4sesi/dst': Committing sync batch length 1 starting with: one 2026/02/02 06:04:02 DEBUG : Dropbox root 'rclone-test-hisobup4sesi/dst': Committed sync batch length 1 starting with: one 2026/02/02 06:04:02 DEBUG : one: size = 5 OK 2026/02/02 06:04:02 DEBUG : one: dropbox = 7da8d117f9fb226817d81adc15c72720c9879c8b7fb821d27f217d198bd79d0d OK 2026/02/02 06:04:02 INFO : one: Copied (replaced existing) 2026/02/02 06:04:03 DEBUG : dst/one: Uploading chunk 1/1 2026/02/02 06:04:03 DEBUG : dst/one: Uploading chunk 2/1 2026/02/02 06:04:04 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Adding "dst/one" to batch 2026/02/02 06:04:04 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Batch idle for 500ms so committing 2026/02/02 06:04:04 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committing sync batch length 1 starting with: dst/one 2026/02/02 06:04:05 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committed sync batch length 1 starting with: dst/one 2026/02/02 06:04:06 DEBUG : CopyDest/one: Uploading chunk 1/1 2026/02/02 06:04:06 DEBUG : CopyDest/one: Uploading chunk 2/1 2026/02/02 06:04:07 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Adding "CopyDest/one" to batch 2026/02/02 06:04:07 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Batch idle for 500ms so committing 2026/02/02 06:04:07 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committing sync batch length 1 starting with: CopyDest/one 2026/02/02 06:04:08 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committed sync batch length 1 starting with: CopyDest/one 2026/02/02 06:04:09 DEBUG : Creating backend with remote "TestDropbox:rclone-test-hisobup4sesi/BackupDir" 2026/02/02 06:04:09 DEBUG : one: size = 5 (Local file system at /tmp/rclone470285901) 2026/02/02 06:04:09 DEBUG : one: size = 3 (Dropbox root 'rclone-test-hisobup4sesi/dst') 2026/02/02 06:04:09 DEBUG : one: Sizes differ 2026/02/02 06:04:10 DEBUG : one: size = 5 OK 2026/02/02 06:04:10 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2026/02/02 06:04:10 DEBUG : one: size = 5 (Local file system at /tmp/rclone470285901) 2026/02/02 06:04:10 DEBUG : one: size = 3 (Dropbox root 'rclone-test-hisobup4sesi/dst') 2026/02/02 06:04:10 DEBUG : one: Sizes differ 2026/02/02 06:04:12 INFO : one: Moved (server-side) 2026/02/02 06:04:13 DEBUG : one: size = 5 OK 2026/02/02 06:04:13 DEBUG : one: dropbox = 7da8d117f9fb226817d81adc15c72720c9879c8b7fb821d27f217d198bd79d0d OK 2026/02/02 06:04:13 INFO : one: Copied (server-side copy) 2026/02/02 06:04:13 DEBUG : one: Destination found in --copy-dest, using server-side copy 2026/02/02 06:04:14 DEBUG : CopyDest/two: Uploading chunk 1/1 2026/02/02 06:04:14 DEBUG : CopyDest/two: Uploading chunk 2/1 2026/02/02 06:04:15 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Adding "CopyDest/two" to batch 2026/02/02 06:04:15 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Batch idle for 500ms so committing 2026/02/02 06:04:15 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committing sync batch length 1 starting with: CopyDest/two 2026/02/02 06:04:16 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committed sync batch length 1 starting with: CopyDest/two 2026/02/02 06:04:17 DEBUG : two: Need to transfer - File not found at Destination 2026/02/02 06:04:17 DEBUG : two: size = 3 OK 2026/02/02 06:04:17 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2026/02/02 06:04:19 DEBUG : two: size = 3 OK 2026/02/02 06:04:19 DEBUG : two: dropbox = 313db63e0283ab2a9bc72e9a0ac749da1d3acf708fcd1a7848767244dd2f17e8 OK 2026/02/02 06:04:19 INFO : two: Copied (server-side copy) 2026/02/02 06:04:19 DEBUG : two: Destination found in --copy-dest, using server-side copy 2026/02/02 06:04:20 DEBUG : two: size = 3 OK 2026/02/02 06:04:20 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2026/02/02 06:04:20 DEBUG : two: Unchanged skipping 2026/02/02 06:04:21 DEBUG : CopyDest/three: Uploading chunk 1/1 2026/02/02 06:04:22 DEBUG : CopyDest/three: Uploading chunk 2/1 2026/02/02 06:04:22 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Adding "CopyDest/three" to batch 2026/02/02 06:04:23 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Batch idle for 500ms so committing 2026/02/02 06:04:23 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committing sync batch length 1 starting with: CopyDest/three 2026/02/02 06:04:23 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committed sync batch length 1 starting with: CopyDest/three 2026/02/02 06:04:24 DEBUG : three: Need to transfer - File not found at Destination 2026/02/02 06:04:24 DEBUG : three: size = 7 (Local file system at /tmp/rclone470285901) 2026/02/02 06:04:24 DEBUG : three: size = 5 (Dropbox root 'rclone-test-hisobup4sesi/CopyDest') 2026/02/02 06:04:24 DEBUG : three: Sizes differ 2026/02/02 06:04:24 DEBUG : three: Destination not found in --copy-dest 2026/02/02 06:04:25 DEBUG : three: Uploading chunk 1/1 2026/02/02 06:04:25 DEBUG : three: Uploading chunk 2/1 2026/02/02 06:04:26 DEBUG : Dropbox root 'rclone-test-hisobup4sesi/dst': Adding "three" to batch 2026/02/02 06:04:26 DEBUG : Dropbox root 'rclone-test-hisobup4sesi/dst': Batch idle for 500ms so committing 2026/02/02 06:04:26 DEBUG : Dropbox root 'rclone-test-hisobup4sesi/dst': Committing sync batch length 1 starting with: three 2026/02/02 06:04:27 DEBUG : Dropbox root 'rclone-test-hisobup4sesi/dst': Committed sync batch length 1 starting with: three 2026/02/02 06:04:27 DEBUG : three: size = 7 OK 2026/02/02 06:04:27 DEBUG : three: dropbox = 78af7ad260025156e50fd9648fd9a36509cd3541c9a8d02597e9b3c598937cbd OK 2026/02/02 06:04:27 INFO : three: Copied (new) 2026/02/02 06:04:35 INFO : Dropbox root 'rclone-test-hisobup4sesi/CopyDest': Committing uploads - please wait... 2026/02/02 06:04:35 INFO : Dropbox root 'rclone-test-hisobup4sesi/BackupDir': Committing uploads - please wait... --- PASS: TestCopyFileCopyDest (42.21s) === RUN TestCaseInsensitiveMoveFile run.go:185: Remote "Dropbox root 'rclone-test-hisobup4sesi'", Local "Local file system at /tmp/rclone470285901", Modify Window "1s" 2026/02/02 06:04:36 DEBUG : file1: Need to transfer - File not found at Destination 2026/02/02 06:04:36 DEBUG : sub/file2: Uploading chunk 1/1 2026/02/02 06:04:36 DEBUG : sub/file2: Uploading chunk 2/1 2026/02/02 06:04:37 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Adding "sub/file2" to batch 2026/02/02 06:04:37 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Batch idle for 500ms so committing 2026/02/02 06:04:37 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committing sync batch length 1 starting with: sub/file2 2026/02/02 06:04:38 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Committed sync batch length 1 starting with: sub/file2 2026/02/02 06:04:38 DEBUG : sub/file2: size = 14 OK 2026/02/02 06:04:38 DEBUG : file1: dropbox = d4b8d7e13c592e454a060a60b4606d5e5c5a03b023d97e24bf4682e9535a8778 OK 2026/02/02 06:04:38 INFO : file1: Copied (new) to: sub/file2 2026/02/02 06:04:38 INFO : file1: Deleted 2026/02/02 06:04:39 DEBUG : sub/file2: size = 14 OK 2026/02/02 06:04:39 DEBUG : file1: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2026/02/02 06:04:39 DEBUG : file1: Unchanged skipping 2026/02/02 06:04:39 INFO : file1: Deleted 2026/02/02 06:04:40 DEBUG : sub/file2: moving to sub/File2-rclone-move-wegiruq8 2026/02/02 06:04:41 INFO : sub/file2: Moved (server-side) to: sub/File2-rclone-move-wegiruq8 2026/02/02 06:04:41 DEBUG : sub/file2: moving to sub/File2 2026/02/02 06:04:41 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/..) 2026/02/02 06:04:41 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/02/02 06:04:42 DEBUG : pacer: Reducing sleep to 15ms 2026/02/02 06:04:42 INFO : sub/File2-rclone-move-wegiruq8: Moved (server-side) to: sub/File2 2026/02/02 06:04:43 DEBUG : pacer: Reducing sleep to 11.25ms 2026/02/02 06:04:43 DEBUG : pacer: Reducing sleep to 10ms --- PASS: TestCaseInsensitiveMoveFile (9.76s) PASS 2026/02/02 06:04:45 DEBUG : Dropbox root 'rclone-test-hisobup4sesi': Purge remote "./operations.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^(TestCaseInsensitiveMoveFile|TestCheckSizeOnly|TestCopyFileCopyDest|TestParseSumFile)$'" - Finished OK in 1m19.747928437s (try 2/5)