"./operations.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^(TestCheckSumDownload|TestPurge)$|^TestRcat$/^withChecksum=false,ignoreChecksum=false$'" - Starting (try 2/5)
2024/09/26 05:29:26 DEBUG : Creating backend with remote "TestDropbox:rclone-test-lotituw4tugo"
2024/09/26 05:29:26 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/09/26 05:29:26 DEBUG : Creating backend with remote "/tmp/rclone1983328452"
=== RUN   TestCheckSumDownload
    run.go:180: Remote "Dropbox root 'rclone-test-lotituw4tugo'", Local "Local file system at /tmp/rclone1983328452", Modify Window "1s"
2024/09/26 05:29:26 DEBUG : Creating backend with remote "TestDropbox:rclone-test-lotituw4tugo/data"
2024/09/26 05:29:28 DEBUG : data/banana: Uploading chunk 1/1
2024/09/26 05:29:28 DEBUG : data/banana: Uploading chunk 2/1
2024/09/26 05:29:29 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Adding "data/banana" to batch
2024/09/26 05:29:29 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Batch idle for 500ms so committing
2024/09/26 05:29:29 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committing sync batch length 1 starting with: data/banana
2024/09/26 05:29:30 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committed sync batch length 1 starting with: data/banana
2024/09/26 05:29:30 DEBUG : test.sum: Uploading chunk 1/1
2024/09/26 05:29:30 DEBUG : test.sum: Uploading chunk 2/1
2024/09/26 05:29:31 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Adding "test.sum" to batch
2024/09/26 05:29:31 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Batch idle for 500ms so committing
2024/09/26 05:29:31 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committing sync batch length 1 starting with: test.sum
2024/09/26 05:29:32 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committed sync batch length 1 starting with: test.sum
=== RUN   TestCheckSumDownload/subtest1
2024/09/26 05:29:35 DEBUG : data/potato: Uploading chunk 1/1
2024/09/26 05:29:35 DEBUG : data/potato: Uploading chunk 2/1
2024/09/26 05:29:36 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Adding "data/potato" to batch
2024/09/26 05:29:36 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Batch idle for 500ms so committing
2024/09/26 05:29:36 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committing sync batch length 1 starting with: data/potato
2024/09/26 05:29:37 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committed sync batch length 1 starting with: data/potato
2024/09/26 05:29:37 DEBUG : test.sum: Uploading chunk 1/1
2024/09/26 05:29:38 DEBUG : test.sum: Uploading chunk 2/1
2024/09/26 05:29:38 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Adding "test.sum" to batch
2024/09/26 05:29:38 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Batch idle for 500ms so committing
2024/09/26 05:29:38 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committing sync batch length 1 starting with: test.sum
2024/09/26 05:29:39 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committed sync batch length 1 starting with: test.sum
=== RUN   TestCheckSumDownload/subtest2
2024/09/26 05:29:41 DEBUG : test.sum: Uploading chunk 1/1
2024/09/26 05:29:41 DEBUG : test.sum: Uploading chunk 2/1
2024/09/26 05:29:42 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Adding "test.sum" to batch
2024/09/26 05:29:42 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Batch idle for 500ms so committing
2024/09/26 05:29:42 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committing sync batch length 1 starting with: test.sum
2024/09/26 05:29:44 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committed sync batch length 1 starting with: test.sum
=== RUN   TestCheckSumDownload/subtest3
2024/09/26 05:29:48 DEBUG : test.sum: Uploading chunk 1/1
2024/09/26 05:29:48 DEBUG : test.sum: Uploading chunk 2/1
2024/09/26 05:29:48 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Adding "test.sum" to batch
2024/09/26 05:29:49 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Batch idle for 500ms so committing
2024/09/26 05:29:49 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committing sync batch length 1 starting with: test.sum
2024/09/26 05:29:53 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committed sync batch length 1 starting with: test.sum
=== RUN   TestCheckSumDownload/subtest4
2024/09/26 05:29:55 DEBUG : test.sum: Uploading chunk 1/1
2024/09/26 05:29:55 DEBUG : test.sum: Uploading chunk 2/1
2024/09/26 05:29:56 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Adding "test.sum" to batch
2024/09/26 05:29:56 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Batch idle for 500ms so committing
2024/09/26 05:29:56 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committing sync batch length 1 starting with: test.sum
2024/09/26 05:30:01 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committed sync batch length 1 starting with: test.sum
=== RUN   TestCheckSumDownload/subtest5
2024/09/26 05:30:04 DEBUG : test.sum: Uploading chunk 1/1
2024/09/26 05:30:04 DEBUG : test.sum: Uploading chunk 2/1
2024/09/26 05:30:05 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Adding "test.sum" to batch
2024/09/26 05:30:05 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Batch idle for 500ms so committing
2024/09/26 05:30:05 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committing sync batch length 1 starting with: test.sum
2024/09/26 05:30:06 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committed sync batch length 1 starting with: test.sum
=== RUN   TestCheckSumDownload/subtest6
2024/09/26 05:30:09 DEBUG : data/banana: Uploading chunk 1/1
2024/09/26 05:30:09 DEBUG : data/banana: Uploading chunk 2/1
2024/09/26 05:30:09 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Adding "data/banana" to batch
2024/09/26 05:30:10 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Batch idle for 500ms so committing
2024/09/26 05:30:10 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committing sync batch length 1 starting with: data/banana
2024/09/26 05:30:10 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committed sync batch length 1 starting with: data/banana
2024/09/26 05:30:11 DEBUG : data/potato: Uploading chunk 1/1
2024/09/26 05:30:11 DEBUG : data/potato: Uploading chunk 2/1
2024/09/26 05:30:11 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Adding "data/potato" to batch
2024/09/26 05:30:12 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Batch idle for 500ms so committing
2024/09/26 05:30:12 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committing sync batch length 1 starting with: data/potato
2024/09/26 05:30:13 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committed sync batch length 1 starting with: data/potato
2024/09/26 05:30:13 DEBUG : test.sum: Uploading chunk 1/1
2024/09/26 05:30:13 DEBUG : test.sum: Uploading chunk 2/1
2024/09/26 05:30:14 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Adding "test.sum" to batch
2024/09/26 05:30:14 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Batch idle for 500ms so committing
2024/09/26 05:30:14 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committing sync batch length 1 starting with: test.sum
2024/09/26 05:30:15 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committed sync batch length 1 starting with: test.sum
=== RUN   TestCheckSumDownload/subtest7
--- PASS: TestCheckSumDownload (54.64s)
    --- PASS: TestCheckSumDownload/subtest1 (1.74s)
    --- PASS: TestCheckSumDownload/subtest2 (1.28s)
    --- PASS: TestCheckSumDownload/subtest3 (1.58s)
    --- PASS: TestCheckSumDownload/subtest4 (1.71s)
    --- PASS: TestCheckSumDownload/subtest5 (1.67s)
    --- PASS: TestCheckSumDownload/subtest6 (1.49s)
    --- PASS: TestCheckSumDownload/subtest7 (1.43s)
=== RUN   TestPurge
2024/09/26 05:30:21 DEBUG : Creating backend with remote "TestDropbox:rclone-test-zohobev5tetu"
2024/09/26 05:30:21 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/09/26 05:30:21 DEBUG : Creating backend with remote "/tmp/rclone595699467"
    run.go:180: Remote "Dropbox root 'rclone-test-zohobev5tetu'", Local "Local file system at /tmp/rclone595699467", Modify Window "1s"
2024/09/26 05:30:23 DEBUG : A1/B1/C1/one: Uploading chunk 1/1
2024/09/26 05:30:23 DEBUG : A1/B1/C1/one: Uploading chunk 2/1
2024/09/26 05:30:24 DEBUG : Dropbox root 'rclone-test-zohobev5tetu': Adding "A1/B1/C1/one" to batch
2024/09/26 05:30:24 DEBUG : Dropbox root 'rclone-test-zohobev5tetu': Batch idle for 500ms so committing
2024/09/26 05:30:24 DEBUG : Dropbox root 'rclone-test-zohobev5tetu': Committing sync batch length 1 starting with: A1/B1/C1/one
2024/09/26 05:30:25 DEBUG : Dropbox root 'rclone-test-zohobev5tetu': Committed sync batch length 1 starting with: A1/B1/C1/one
2024/09/26 05:30:25 DEBUG : A2: Making directory
2024/09/26 05:30:25 DEBUG : pacer: low level retry 1/10 (error too_many_write_operations/)
2024/09/26 05:30:25 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2024/09/26 05:30:26 DEBUG : pacer: Reducing sleep to 15ms
2024/09/26 05:30:26 DEBUG : A1/B2: Making directory
2024/09/26 05:30:26 DEBUG : pacer: Reducing sleep to 11.25ms
2024/09/26 05:30:27 DEBUG : pacer: Reducing sleep to 10ms
2024/09/26 05:30:27 DEBUG : A1/B2/C2: Making directory
2024/09/26 05:30:27 DEBUG : A1/B1/C3: Making directory
2024/09/26 05:30:28 DEBUG : A3: Making directory
2024/09/26 05:30:29 DEBUG : A3/B3: Making directory
2024/09/26 05:30:30 DEBUG : A3/B3/C4: Making directory
2024/09/26 05:30:31 DEBUG : A1/two: Uploading chunk 1/1
2024/09/26 05:30:31 DEBUG : A1/two: Uploading chunk 2/1
2024/09/26 05:30:31 DEBUG : Dropbox root 'rclone-test-zohobev5tetu': Adding "A1/two" to batch
2024/09/26 05:30:32 DEBUG : Dropbox root 'rclone-test-zohobev5tetu': Batch idle for 500ms so committing
2024/09/26 05:30:32 DEBUG : Dropbox root 'rclone-test-zohobev5tetu': Committing sync batch length 1 starting with: A1/two
2024/09/26 05:30:32 DEBUG : Dropbox root 'rclone-test-zohobev5tetu': Committed sync batch length 1 starting with: A1/two
2024/09/26 05:30:37 ERROR : : error listing: directory not found
2024/09/26 05:30:37 DEBUG : Dropbox root 'rclone-test-zohobev5tetu': Purge remote
2024/09/26 05:30:37 NOTICE: purge failed: path_lookup/not_found/...
--- PASS: TestPurge (16.37s)
=== RUN   TestRcat
=== RUN   TestRcat/withChecksum=false,ignoreChecksum=false
    run.go:180: Remote "Dropbox root 'rclone-test-lotituw4tugo'", Local "Local file system at /tmp/rclone1983328452", Modify Window "1s"
2024/09/26 05:30:38 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': File to upload is small (34 bytes), uploading instead of streaming
2024/09/26 05:30:38 DEBUG : no_checksum_small_file_from_pipe: Uploading chunk 1/1
2024/09/26 05:30:38 DEBUG : no_checksum_small_file_from_pipe: Uploading chunk 2/1
2024/09/26 05:30:39 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Adding "no_checksum_small_file_from_pipe" to batch
2024/09/26 05:30:39 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Batch idle for 500ms so committing
2024/09/26 05:30:39 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committing sync batch length 1 starting with: no_checksum_small_file_from_pipe
2024/09/26 05:30:40 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committed sync batch length 1 starting with: no_checksum_small_file_from_pipe
2024/09/26 05:30:40 DEBUG : no_checksum_small_file_from_pipe: dropbox = 6167057cad26d021a22944146dfef827ec973d33996a25ece54f17508427cf5f OK
2024/09/26 05:30:40 DEBUG : no_checksum_small_file_from_pipe: Size and dropbox of src and dst objects identical
2024/09/26 05:30:40 DEBUG : no_checksum_big_file_from_pipe: Uploading chunk 1/0
2024/09/26 05:30:40 DEBUG : no_checksum_big_file_from_pipe: Uploading chunk 2/0
2024/09/26 05:30:41 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Adding "no_checksum_big_file_from_pipe" to batch
2024/09/26 05:30:41 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Batch idle for 500ms so committing
2024/09/26 05:30:41 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committing sync batch length 1 starting with: no_checksum_big_file_from_pipe
2024/09/26 05:30:42 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Committed sync batch length 1 starting with: no_checksum_big_file_from_pipe
2024/09/26 05:30:42 DEBUG : no_checksum_big_file_from_pipe: dropbox = 134292f7f01dbc9fa2e8230e98def0b183c01ca9fce46a144f90bee4ef0c4ef3 OK
2024/09/26 05:30:42 DEBUG : no_checksum_big_file_from_pipe: Size and dropbox of src and dst objects identical
--- PASS: TestRcat (6.37s)
    --- PASS: TestRcat/withChecksum=false,ignoreChecksum=false (6.37s)
PASS
2024/09/26 05:30:44 DEBUG : Dropbox root 'rclone-test-lotituw4tugo': Purge remote
"./operations.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^(TestCheckSumDownload|TestPurge)$|^TestRcat$/^withChecksum=false,ignoreChecksum=false$'" - Finished OK in 1m18.336948336s (try 2/5)