"./operations.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^(TestCat|TestCheckDownload|TestCheckSumDownload|TestCopyFileCompareDest|TestCopyFileCopyDest|TestCopyFileMaxTransfer|TestMaxDeleteSize|TestTouchDir)$'" - Starting (try 2/5)
2025/09/26 03:16:51 DEBUG : Creating backend with remote "TestDropbox:rclone-test-noyixiy8kifa"
2025/09/26 03:16:51 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/09/26 03:16:52 DEBUG : Creating backend with remote "/tmp/rclone301895392"
=== RUN   TestCheckDownload
    run.go:180: Remote "Dropbox root 'rclone-test-noyixiy8kifa'", Local "Local file system at /tmp/rclone301895392", Modify Window "1s"
2025/09/26 03:16:53 DEBUG : rutabaga: Uploading chunk 1/1
2025/09/26 03:16:53 DEBUG : rutabaga: Uploading chunk 2/1
2025/09/26 03:16:54 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "rutabaga" to batch
2025/09/26 03:16:54 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:16:54 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: rutabaga
2025/09/26 03:16:56 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: rutabaga
=== RUN   TestCheckDownload/1
=== RUN   TestCheckDownload/2
2025/09/26 03:16:58 DEBUG : empty space: Uploading chunk 1/1
2025/09/26 03:16:58 DEBUG : empty space: Uploading chunk 2/1
2025/09/26 03:16:58 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "empty space" to batch
2025/09/26 03:16:59 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:16:59 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: empty space
2025/09/26 03:17:00 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: empty space
=== RUN   TestCheckDownload/3
2025/09/26 03:17:01 DEBUG : potato2: Uploading chunk 1/1
2025/09/26 03:17:01 DEBUG : potato2: Uploading chunk 2/1
2025/09/26 03:17:02 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "potato2" to batch
2025/09/26 03:17:02 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:17:02 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: potato2
2025/09/26 03:17:03 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: potato2
=== RUN   TestCheckDownload/4
=== RUN   TestCheckDownload/5
2025/09/26 03:17:06 DEBUG : remotepotato: Uploading chunk 1/1
2025/09/26 03:17:06 DEBUG : remotepotato: Uploading chunk 2/1
2025/09/26 03:17:07 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "remotepotato" to batch
2025/09/26 03:17:07 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:17:07 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: remotepotato
2025/09/26 03:17:08 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: remotepotato
=== RUN   TestCheckDownload/6
=== RUN   TestCheckDownload/7
--- PASS: TestCheckDownload (21.66s)
    --- PASS: TestCheckDownload/1 (0.66s)
    --- PASS: TestCheckDownload/2 (0.67s)
    --- PASS: TestCheckDownload/3 (0.85s)
    --- PASS: TestCheckDownload/4 (0.95s)
    --- PASS: TestCheckDownload/5 (0.91s)
    --- PASS: TestCheckDownload/6 (0.92s)
    --- PASS: TestCheckDownload/7 (0.92s)
=== RUN   TestCheckSumDownload
    run.go:180: Remote "Dropbox root 'rclone-test-noyixiy8kifa'", Local "Local file system at /tmp/rclone301895392", Modify Window "1s"
2025/09/26 03:17:13 DEBUG : Creating backend with remote "TestDropbox:rclone-test-noyixiy8kifa/data"
2025/09/26 03:17:14 DEBUG : data/banana: Uploading chunk 1/1
2025/09/26 03:17:14 DEBUG : data/banana: Uploading chunk 2/1
2025/09/26 03:17:15 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "data/banana" to batch
2025/09/26 03:17:15 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:17:15 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: data/banana
2025/09/26 03:17:16 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: data/banana
2025/09/26 03:17:16 DEBUG : test.sum: Uploading chunk 1/1
2025/09/26 03:17:17 DEBUG : test.sum: Uploading chunk 2/1
2025/09/26 03:17:17 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "test.sum" to batch
2025/09/26 03:17:18 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:17:18 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: test.sum
2025/09/26 03:17:18 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: test.sum
=== RUN   TestCheckSumDownload/subtest1
2025/09/26 03:17:20 DEBUG : data/potato: Uploading chunk 1/1
2025/09/26 03:17:21 DEBUG : data/potato: Uploading chunk 2/1
2025/09/26 03:17:21 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "data/potato" to batch
2025/09/26 03:17:22 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:17:22 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: data/potato
2025/09/26 03:17:23 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: data/potato
2025/09/26 03:17:24 DEBUG : test.sum: Uploading chunk 1/1
2025/09/26 03:17:24 DEBUG : test.sum: Uploading chunk 2/1
2025/09/26 03:17:25 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "test.sum" to batch
2025/09/26 03:17:25 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:17:25 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: test.sum
2025/09/26 03:17:26 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: test.sum
=== RUN   TestCheckSumDownload/subtest2
2025/09/26 03:17:28 DEBUG : test.sum: Uploading chunk 1/1
2025/09/26 03:17:28 DEBUG : test.sum: Uploading chunk 2/1
2025/09/26 03:17:29 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "test.sum" to batch
2025/09/26 03:17:29 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:17:29 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: test.sum
2025/09/26 03:17:32 ERROR : Dropbox root 'rclone-test-noyixiy8kifa': sync batch commit: failed to commit batch length 1: batch had 1 errors: last error: upload failed: too_many_write_operations
=== NAME  TestCheckSumDownload
    run.go:285: Failed to put "test.sum" to "Dropbox root 'rclone-test-noyixiy8kifa'": upload failed: batch upload failed: upload failed: too_many_write_operations
--- FAIL: TestCheckSumDownload (22.15s)
    --- PASS: TestCheckSumDownload/subtest1 (1.57s)
    --- PASS: TestCheckSumDownload/subtest2 (1.40s)
=== RUN   TestCopyFileCompareDest
    run.go:180: Remote "Dropbox root 'rclone-test-noyixiy8kifa'", Local "Local file system at /tmp/rclone301895392", Modify Window "1s"
2025/09/26 03:17:35 DEBUG : Creating backend with remote "TestDropbox:rclone-test-noyixiy8kifa/dst"
2025/09/26 03:17:36 DEBUG : Creating backend with remote "TestDropbox:rclone-test-noyixiy8kifa/CompareDest"
2025/09/26 03:17:36 DEBUG : one: Need to transfer - File not found at Destination
2025/09/26 03:17:37 DEBUG : one: Uploading chunk 1/1
2025/09/26 03:17:37 DEBUG : one: Uploading chunk 2/1
2025/09/26 03:17:37 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Adding "one" to batch
2025/09/26 03:17:38 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Batch idle for 500ms so committing
2025/09/26 03:17:38 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Committing sync batch length 1 starting with: one
2025/09/26 03:17:39 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Committed sync batch length 1 starting with: one
2025/09/26 03:17:39 DEBUG : one: dropbox = fe8d7a873dc48961a6af334c996b2cb3ce37149d5ce9c9253952a54c6a92c1ad OK
2025/09/26 03:17:39 INFO  : one: Copied (new)
2025/09/26 03:17:40 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/09/26 03:17:40 DEBUG : one: Uploading chunk 1/1
2025/09/26 03:17:41 DEBUG : one: Uploading chunk 2/1
2025/09/26 03:17:41 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Adding "one" to batch
2025/09/26 03:17:42 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Batch idle for 500ms so committing
2025/09/26 03:17:42 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Committing sync batch length 1 starting with: one
2025/09/26 03:17:42 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Committed sync batch length 1 starting with: one
2025/09/26 03:17:42 DEBUG : one: dropbox = 7da8d117f9fb226817d81adc15c72720c9879c8b7fb821d27f217d198bd79d0d OK
2025/09/26 03:17:42 INFO  : one: Copied (replaced existing)
2025/09/26 03:17:43 DEBUG : dst/one: Uploading chunk 1/1
2025/09/26 03:17:43 DEBUG : dst/one: Uploading chunk 2/1
2025/09/26 03:17:44 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "dst/one" to batch
2025/09/26 03:17:44 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:17:44 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: dst/one
2025/09/26 03:17:46 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: dst/one
2025/09/26 03:17:46 DEBUG : CompareDest/one: Uploading chunk 1/1
2025/09/26 03:17:46 DEBUG : CompareDest/one: Uploading chunk 2/1
2025/09/26 03:17:47 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "CompareDest/one" to batch
2025/09/26 03:17:47 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:17:47 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: CompareDest/one
2025/09/26 03:17:48 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: CompareDest/one
2025/09/26 03:17:48 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/09/26 03:17:49 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/09/26 03:17:49 DEBUG : one: Destination found in --compare-dest, skipping
2025/09/26 03:17:49 DEBUG : CompareDest/two: Uploading chunk 1/1
2025/09/26 03:17:50 DEBUG : CompareDest/two: Uploading chunk 2/1
2025/09/26 03:17:51 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "CompareDest/two" to batch
2025/09/26 03:17:51 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:17:51 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: CompareDest/two
2025/09/26 03:17:52 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: CompareDest/two
2025/09/26 03:17:52 DEBUG : two: Need to transfer - File not found at Destination
2025/09/26 03:17:53 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/09/26 03:17:53 DEBUG : two: Destination found in --compare-dest, skipping
2025/09/26 03:17:53 DEBUG : two: Need to transfer - File not found at Destination
2025/09/26 03:17:53 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/09/26 03:17:53 DEBUG : two: Destination found in --compare-dest, skipping
2025/09/26 03:17:55 DEBUG : two: Need to transfer - File not found at Destination
2025/09/26 03:17:55 DEBUG : two: Sizes differ (src 5 vs dst 3)
2025/09/26 03:17:55 DEBUG : two: Uploading chunk 1/1
2025/09/26 03:17:55 DEBUG : two: Uploading chunk 2/1
2025/09/26 03:17:56 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Adding "two" to batch
2025/09/26 03:17:57 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Batch idle for 500ms so committing
2025/09/26 03:17:57 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Committing sync batch length 1 starting with: two
2025/09/26 03:17:58 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Committed sync batch length 1 starting with: two
2025/09/26 03:17:58 DEBUG : two: dropbox = 25e70b9a05696acbcc5bd6fa74ba6fa580c9a58960a02390ae1d2f71d21c0378 OK
2025/09/26 03:17:58 INFO  : two: Copied (new)
2025/09/26 03:18:04 INFO  : Dropbox root 'rclone-test-noyixiy8kifa/CompareDest': Committing uploads - please wait...
--- PASS: TestCopyFileCompareDest (28.22s)
=== RUN   TestCopyFileCopyDest
    run.go:180: Remote "Dropbox root 'rclone-test-noyixiy8kifa'", Local "Local file system at /tmp/rclone301895392", Modify Window "1s"
2025/09/26 03:18:04 DEBUG : Creating backend with remote "TestDropbox:rclone-test-noyixiy8kifa/dst"
2025/09/26 03:18:04 DEBUG : Creating backend with remote "TestDropbox:rclone-test-noyixiy8kifa/CopyDest"
2025/09/26 03:18:04 DEBUG : one: Need to transfer - File not found at Destination
2025/09/26 03:18:05 DEBUG : one: Uploading chunk 1/1
2025/09/26 03:18:05 DEBUG : one: Uploading chunk 2/1
2025/09/26 03:18:06 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Adding "one" to batch
2025/09/26 03:18:06 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Batch idle for 500ms so committing
2025/09/26 03:18:06 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Committing sync batch length 1 starting with: one
2025/09/26 03:18:08 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Committed sync batch length 1 starting with: one
2025/09/26 03:18:08 DEBUG : one: dropbox = fe8d7a873dc48961a6af334c996b2cb3ce37149d5ce9c9253952a54c6a92c1ad OK
2025/09/26 03:18:08 INFO  : one: Copied (new)
2025/09/26 03:18:09 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/09/26 03:18:10 DEBUG : one: Uploading chunk 1/1
2025/09/26 03:18:10 DEBUG : one: Uploading chunk 2/1
2025/09/26 03:18:11 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Adding "one" to batch
2025/09/26 03:18:11 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Batch idle for 500ms so committing
2025/09/26 03:18:11 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Committing sync batch length 1 starting with: one
2025/09/26 03:18:13 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Committed sync batch length 1 starting with: one
2025/09/26 03:18:13 DEBUG : one: dropbox = 7da8d117f9fb226817d81adc15c72720c9879c8b7fb821d27f217d198bd79d0d OK
2025/09/26 03:18:13 INFO  : one: Copied (replaced existing)
2025/09/26 03:18:14 DEBUG : dst/one: Uploading chunk 1/1
2025/09/26 03:18:14 DEBUG : dst/one: Uploading chunk 2/1
2025/09/26 03:18:15 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "dst/one" to batch
2025/09/26 03:18:15 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:18:15 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: dst/one
2025/09/26 03:18:16 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: dst/one
2025/09/26 03:18:16 DEBUG : CopyDest/one: Uploading chunk 1/1
2025/09/26 03:18:17 DEBUG : CopyDest/one: Uploading chunk 2/1
2025/09/26 03:18:17 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "CopyDest/one" to batch
2025/09/26 03:18:18 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:18:18 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: CopyDest/one
2025/09/26 03:18:18 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: CopyDest/one
2025/09/26 03:18:19 DEBUG : Creating backend with remote "TestDropbox:rclone-test-noyixiy8kifa/BackupDir"
2025/09/26 03:18:19 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/09/26 03:18:20 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/09/26 03:18:20 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/09/26 03:18:22 INFO  : one: Moved (server-side)
2025/09/26 03:18:23 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/..)
2025/09/26 03:18:23 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/26 03:18:24 DEBUG : pacer: low level retry 2/10 (error too_many_write_operations/)
2025/09/26 03:18:24 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/09/26 03:18:24 DEBUG : pacer: low level retry 3/10 (error too_many_write_operations/..)
2025/09/26 03:18:24 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2025/09/26 03:18:25 DEBUG : pacer: Reducing sleep to 60ms
2025/09/26 03:18:25 DEBUG : one: dropbox = 7da8d117f9fb226817d81adc15c72720c9879c8b7fb821d27f217d198bd79d0d OK
2025/09/26 03:18:25 INFO  : one: Copied (server-side copy)
2025/09/26 03:18:25 DEBUG : one: Destination found in --copy-dest, using server-side copy
2025/09/26 03:18:26 DEBUG : CopyDest/two: Uploading chunk 1/1
2025/09/26 03:18:27 DEBUG : CopyDest/two: Uploading chunk 2/1
2025/09/26 03:18:27 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "CopyDest/two" to batch
2025/09/26 03:18:27 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:18:27 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: CopyDest/two
2025/09/26 03:18:28 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: CopyDest/two
2025/09/26 03:18:29 DEBUG : pacer: Reducing sleep to 45ms
2025/09/26 03:18:29 DEBUG : two: Need to transfer - File not found at Destination
2025/09/26 03:18:29 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/09/26 03:18:29 DEBUG : pacer: Reducing sleep to 33.75ms
2025/09/26 03:18:30 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/...)
2025/09/26 03:18:30 DEBUG : pacer: Rate limited, increasing sleep to 67.5ms
2025/09/26 03:18:31 DEBUG : pacer: Reducing sleep to 50.625ms
2025/09/26 03:18:31 DEBUG : two: dropbox = 313db63e0283ab2a9bc72e9a0ac749da1d3acf708fcd1a7848767244dd2f17e8 OK
2025/09/26 03:18:31 INFO  : two: Copied (server-side copy)
2025/09/26 03:18:31 DEBUG : two: Destination found in --copy-dest, using server-side copy
2025/09/26 03:18:32 DEBUG : pacer: Reducing sleep to 37.96875ms
2025/09/26 03:18:32 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/09/26 03:18:32 DEBUG : two: Unchanged skipping
2025/09/26 03:18:32 DEBUG : CopyDest/three: Uploading chunk 1/1
2025/09/26 03:18:33 DEBUG : CopyDest/three: Uploading chunk 2/1
2025/09/26 03:18:33 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "CopyDest/three" to batch
2025/09/26 03:18:34 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:18:34 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: CopyDest/three
2025/09/26 03:18:35 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: CopyDest/three
2025/09/26 03:18:36 DEBUG : pacer: Reducing sleep to 28.476562ms
2025/09/26 03:18:36 DEBUG : three: Need to transfer - File not found at Destination
2025/09/26 03:18:36 DEBUG : three: Sizes differ (src 7 vs dst 5)
2025/09/26 03:18:36 DEBUG : three: Destination not found in --copy-dest
2025/09/26 03:18:36 DEBUG : pacer: Reducing sleep to 21.357421ms
2025/09/26 03:18:36 DEBUG : three: Uploading chunk 1/1
2025/09/26 03:18:37 DEBUG : pacer: Reducing sleep to 16.018065ms
2025/09/26 03:18:37 DEBUG : three: Uploading chunk 2/1
2025/09/26 03:18:37 DEBUG : pacer: Reducing sleep to 12.013548ms
2025/09/26 03:18:37 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Adding "three" to batch
2025/09/26 03:18:38 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Batch idle for 500ms so committing
2025/09/26 03:18:38 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Committing sync batch length 1 starting with: three
2025/09/26 03:18:38 DEBUG : pacer: Reducing sleep to 10ms
2025/09/26 03:18:38 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa/dst': Committed sync batch length 1 starting with: three
2025/09/26 03:18:38 DEBUG : three: dropbox = 78af7ad260025156e50fd9648fd9a36509cd3541c9a8d02597e9b3c598937cbd OK
2025/09/26 03:18:38 INFO  : three: Copied (new)
2025/09/26 03:18:47 INFO  : Dropbox root 'rclone-test-noyixiy8kifa/CopyDest': Committing uploads - please wait...
2025/09/26 03:18:47 INFO  : Dropbox root 'rclone-test-noyixiy8kifa/BackupDir': Committing uploads - please wait...
--- PASS: TestCopyFileCopyDest (43.23s)
=== RUN   TestCopyFileMaxTransfer
    run.go:180: Remote "Dropbox root 'rclone-test-noyixiy8kifa'", Local "Local file system at /tmp/rclone301895392", Modify Window "1s"
2025/09/26 03:18:47 DEBUG : TestCopyFileMaxTransfer/file1: Need to transfer - File not found at Destination
2025/09/26 03:18:47 DEBUG : TestCopyFileMaxTransfer/file1: Uploading chunk 1/1
2025/09/26 03:18:48 DEBUG : TestCopyFileMaxTransfer/file1: Uploading chunk 2/1
2025/09/26 03:18:49 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "TestCopyFileMaxTransfer/file1" to batch
2025/09/26 03:18:49 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:18:49 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: TestCopyFileMaxTransfer/file1
2025/09/26 03:18:50 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: TestCopyFileMaxTransfer/file1
2025/09/26 03:18:50 DEBUG : TestCopyFileMaxTransfer/file1: dropbox = d4b8d7e13c592e454a060a60b4606d5e5c5a03b023d97e24bf4682e9535a8778 OK
2025/09/26 03:18:50 INFO  : TestCopyFileMaxTransfer/file1: Copied (new)
2025/09/26 03:18:50 DEBUG : TestCopyFileMaxTransfer/file2: Need to transfer - File not found at Destination
2025/09/26 03:18:51 DEBUG : TestCopyFileMaxTransfer/file2: Uploading chunk 1/1
2025/09/26 03:18:51 DEBUG : pacer: low level retry 1/10 (error Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": max transfer limit reached as set by --max-transfer)
2025/09/26 03:18:51 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/26 03:18:51 DEBUG : pacer: low level retry 2/10 (error Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": max transfer limit reached as set by --max-transfer)
2025/09/26 03:18:51 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/09/26 03:18:51 DEBUG : pacer: low level retry 3/10 (error Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": max transfer limit reached as set by --max-transfer)
2025/09/26 03:18:51 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2025/09/26 03:18:51 DEBUG : pacer: low level retry 4/10 (error Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": max transfer limit reached as set by --max-transfer)
2025/09/26 03:18:51 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2025/09/26 03:18:51 DEBUG : pacer: low level retry 5/10 (error Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": max transfer limit reached as set by --max-transfer)
2025/09/26 03:18:51 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2025/09/26 03:18:51 DEBUG : pacer: low level retry 6/10 (error Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": max transfer limit reached as set by --max-transfer)
2025/09/26 03:18:51 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2025/09/26 03:18:51 DEBUG : pacer: low level retry 7/10 (error Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": max transfer limit reached as set by --max-transfer)
2025/09/26 03:18:51 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2025/09/26 03:18:52 DEBUG : pacer: low level retry 8/10 (error Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": max transfer limit reached as set by --max-transfer)
2025/09/26 03:18:52 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/09/26 03:18:53 DEBUG : pacer: low level retry 9/10 (error Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": max transfer limit reached as set by --max-transfer)
2025/09/26 03:18:55 DEBUG : pacer: low level retry 10/10 (error Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": max transfer limit reached as set by --max-transfer)
2025/09/26 03:18:55 DEBUG : TestCopyFileMaxTransfer/file2: Received error: upload failed: Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": max transfer limit reached as set by --max-transfer - low level retry 0/10
2025/09/26 03:18:58 DEBUG : pacer: Reducing sleep to 1.5s
2025/09/26 03:19:00 DEBUG : pacer: Reducing sleep to 1.125s
2025/09/26 03:19:01 DEBUG : pacer: Reducing sleep to 843.75ms
2025/09/26 03:19:01 DEBUG : TestCopyFileMaxTransfer/file3: Need to transfer - File not found at Destination
2025/09/26 03:19:02 DEBUG : pacer: Reducing sleep to 632.8125ms
2025/09/26 03:19:03 DEBUG : pacer: Reducing sleep to 474.609375ms
2025/09/26 03:19:04 DEBUG : pacer: Reducing sleep to 355.957031ms
2025/09/26 03:19:04 DEBUG : TestCopyFileMaxTransfer/file4: Need to transfer - File not found at Destination
2025/09/26 03:19:04 DEBUG : pacer: Reducing sleep to 266.967773ms
2025/09/26 03:19:04 DEBUG : TestCopyFileMaxTransfer/file4: Uploading chunk 1/1
2025/09/26 03:19:05 DEBUG : pacer: Reducing sleep to 200.225829ms
2025/09/26 03:19:05 DEBUG : TestCopyFileMaxTransfer/file4: Uploading chunk 2/1
2025/09/26 03:19:05 DEBUG : pacer: Reducing sleep to 150.169371ms
2025/09/26 03:19:05 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "TestCopyFileMaxTransfer/file4" to batch
2025/09/26 03:19:06 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:19:06 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: TestCopyFileMaxTransfer/file4
2025/09/26 03:19:07 DEBUG : pacer: Reducing sleep to 112.627028ms
2025/09/26 03:19:07 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: TestCopyFileMaxTransfer/file4
2025/09/26 03:19:07 DEBUG : TestCopyFileMaxTransfer/file4: dropbox = 3b0f5089b79c6383c2595fcbcc6d834153e166aeeb17a685a6bbc00b6ace1139 OK
2025/09/26 03:19:07 INFO  : TestCopyFileMaxTransfer/file4: Copied (new)
2025/09/26 03:19:07 DEBUG : pacer: Reducing sleep to 84.470271ms
2025/09/26 03:19:07 DEBUG : pacer: Reducing sleep to 63.352703ms
2025/09/26 03:19:07 DEBUG : pacer: Reducing sleep to 47.514527ms
2025/09/26 03:19:07 DEBUG : pacer: Reducing sleep to 35.635895ms
2025/09/26 03:19:08 DEBUG : pacer: Reducing sleep to 26.726921ms
2025/09/26 03:19:09 DEBUG : pacer: Reducing sleep to 20.04519ms
2025/09/26 03:19:09 DEBUG : pacer: Reducing sleep to 15.033892ms
2025/09/26 03:19:09 DEBUG : pacer: Reducing sleep to 11.275419ms
2025/09/26 03:19:10 DEBUG : pacer: Reducing sleep to 10ms
--- PASS: TestCopyFileMaxTransfer (23.10s)
=== RUN   TestMaxDeleteSize
    run.go:180: Remote "Dropbox root 'rclone-test-noyixiy8kifa'", Local "Local file system at /tmp/rclone301895392", Modify Window "1s"
2025/09/26 03:19:10 DEBUG : small: Uploading chunk 1/1
2025/09/26 03:19:11 DEBUG : small: Uploading chunk 2/1
2025/09/26 03:19:11 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "small" to batch
2025/09/26 03:19:12 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:19:12 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: small
2025/09/26 03:19:12 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: small
2025/09/26 03:19:12 DEBUG : medium: Uploading chunk 1/1
2025/09/26 03:19:13 DEBUG : medium: Uploading chunk 2/1
2025/09/26 03:19:14 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "medium" to batch
2025/09/26 03:19:14 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:19:14 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: medium
2025/09/26 03:19:15 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: medium
2025/09/26 03:19:16 DEBUG : large: Uploading chunk 1/1
2025/09/26 03:19:16 DEBUG : large: Uploading chunk 2/1
2025/09/26 03:19:16 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "large" to batch
2025/09/26 03:19:17 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:19:17 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: large
2025/09/26 03:19:18 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: large
2025/09/26 03:19:18 DEBUG : Waiting for deletions to finish
2025/09/26 03:19:18 ERROR : medium: Got fatal error on delete: --max-delete-size threshold reached
2025/09/26 03:19:19 INFO  : large: Deleted
2025/09/26 03:19:19 INFO  : small: Deleted
--- PASS: TestMaxDeleteSize (10.92s)
=== RUN   TestCat
    run.go:180: Remote "Dropbox root 'rclone-test-noyixiy8kifa'", Local "Local file system at /tmp/rclone301895392", Modify Window "1s"
2025/09/26 03:19:21 DEBUG : file1: Uploading chunk 1/1
2025/09/26 03:19:22 DEBUG : file1: Uploading chunk 2/1
2025/09/26 03:19:22 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "file1" to batch
2025/09/26 03:19:22 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:19:22 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: file1
2025/09/26 03:19:23 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: file1
2025/09/26 03:19:24 DEBUG : file2: Uploading chunk 1/1
2025/09/26 03:19:24 DEBUG : file2: Uploading chunk 2/1
2025/09/26 03:19:24 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "file2" to batch
2025/09/26 03:19:25 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:19:25 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: file2
2025/09/26 03:19:25 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: file2
--- PASS: TestCat (15.05s)
=== RUN   TestTouchDir
    run.go:180: Remote "Dropbox root 'rclone-test-noyixiy8kifa'", Local "Local file system at /tmp/rclone301895392", Modify Window "1s"
2025/09/26 03:19:36 DEBUG : potato2: Uploading chunk 1/1
2025/09/26 03:19:36 DEBUG : potato2: Uploading chunk 2/1
2025/09/26 03:19:37 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "potato2" to batch
2025/09/26 03:19:38 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:19:38 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: potato2
2025/09/26 03:19:38 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: potato2
2025/09/26 03:19:39 DEBUG : empty space: Uploading chunk 1/1
2025/09/26 03:19:39 DEBUG : empty space: Uploading chunk 2/1
2025/09/26 03:19:39 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "empty space" to batch
2025/09/26 03:19:40 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:19:40 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: empty space
2025/09/26 03:19:41 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: empty space
2025/09/26 03:19:41 DEBUG : sub dir/potato3: Uploading chunk 1/1
2025/09/26 03:19:41 DEBUG : sub dir/potato3: Uploading chunk 2/1
2025/09/26 03:19:42 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Adding "sub dir/potato3" to batch
2025/09/26 03:19:42 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Batch idle for 500ms so committing
2025/09/26 03:19:42 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committing sync batch length 1 starting with: sub dir/potato3
2025/09/26 03:19:43 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Committed sync batch length 1 starting with: sub dir/potato3
2025/09/26 03:19:44 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Touching "potato2"
2025/09/26 03:19:44 ERROR : potato2: failed to touch: can't set modified time without deleting existing object
2025/09/26 03:19:44 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Touching "empty space"
2025/09/26 03:19:44 ERROR : empty space: failed to touch: can't set modified time without deleting existing object
2025/09/26 03:19:44 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Touching "sub dir/potato3"
2025/09/26 03:19:44 ERROR : sub dir/potato3: failed to touch: can't set modified time without deleting existing object
--- PASS: TestTouchDir (11.84s)
FAIL
2025/09/26 03:19:48 DEBUG : Dropbox root 'rclone-test-noyixiy8kifa': Purge remote
"./operations.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^(TestCat|TestCheckDownload|TestCheckSumDownload|TestCopyFileCompareDest|TestCopyFileCopyDest|TestCopyFileMaxTransfer|TestMaxDeleteSize|TestTouchDir)$'" - Finished ERROR in 2m57.052601688s (try 2/5): exit status 1: Failed [TestCheckSumDownload]