"./operations.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^(TestCheckSumDownload|TestCopyFileBackupDir)$'" - Starting (try 2/5)
2025/09/22 04:29:10 DEBUG : Creating backend with remote "TestDropbox:rclone-test-wukavix5kahi"
2025/09/22 04:29:10 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/09/22 04:29:10 DEBUG : Creating backend with remote "/tmp/rclone3418793086"
=== RUN   TestCheckSumDownload
    run.go:180: Remote "Dropbox root 'rclone-test-wukavix5kahi'", Local "Local file system at /tmp/rclone3418793086", Modify Window "1s"
2025/09/22 04:29:10 DEBUG : Creating backend with remote "TestDropbox:rclone-test-wukavix5kahi/data"
2025/09/22 04:29:11 DEBUG : data/banana: Uploading chunk 1/1
2025/09/22 04:29:13 DEBUG : data/banana: Uploading chunk 2/1
2025/09/22 04:29:13 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Adding "data/banana" to batch
2025/09/22 04:29:14 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Batch idle for 500ms so committing
2025/09/22 04:29:14 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committing sync batch length 1 starting with: data/banana
2025/09/22 04:29:15 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committed sync batch length 1 starting with: data/banana
2025/09/22 04:29:15 DEBUG : test.sum: Uploading chunk 1/1
2025/09/22 04:29:15 DEBUG : test.sum: Uploading chunk 2/1
2025/09/22 04:29:16 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Adding "test.sum" to batch
2025/09/22 04:29:16 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Batch idle for 500ms so committing
2025/09/22 04:29:16 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committing sync batch length 1 starting with: test.sum
2025/09/22 04:29:17 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committed sync batch length 1 starting with: test.sum
=== RUN   TestCheckSumDownload/subtest1
2025/09/22 04:29:19 DEBUG : data/potato: Uploading chunk 1/1
2025/09/22 04:29:20 DEBUG : data/potato: Uploading chunk 2/1
2025/09/22 04:29:20 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Adding "data/potato" to batch
2025/09/22 04:29:21 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Batch idle for 500ms so committing
2025/09/22 04:29:21 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committing sync batch length 1 starting with: data/potato
2025/09/22 04:29:21 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committed sync batch length 1 starting with: data/potato
2025/09/22 04:29:22 DEBUG : test.sum: Uploading chunk 1/1
2025/09/22 04:29:22 DEBUG : test.sum: Uploading chunk 2/1
2025/09/22 04:29:23 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Adding "test.sum" to batch
2025/09/22 04:29:23 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Batch idle for 500ms so committing
2025/09/22 04:29:23 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committing sync batch length 1 starting with: test.sum
2025/09/22 04:29:24 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committed sync batch length 1 starting with: test.sum
=== RUN   TestCheckSumDownload/subtest2
2025/09/22 04:29:26 DEBUG : test.sum: Uploading chunk 1/1
2025/09/22 04:29:27 DEBUG : test.sum: Uploading chunk 2/1
2025/09/22 04:29:27 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Adding "test.sum" to batch
2025/09/22 04:29:27 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Batch idle for 500ms so committing
2025/09/22 04:29:27 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committing sync batch length 1 starting with: test.sum
2025/09/22 04:29:28 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committed sync batch length 1 starting with: test.sum
=== RUN   TestCheckSumDownload/subtest3
2025/09/22 04:29:31 DEBUG : test.sum: Uploading chunk 1/1
2025/09/22 04:29:31 DEBUG : test.sum: Uploading chunk 2/1
2025/09/22 04:29:31 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Adding "test.sum" to batch
2025/09/22 04:29:32 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Batch idle for 500ms so committing
2025/09/22 04:29:32 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committing sync batch length 1 starting with: test.sum
2025/09/22 04:29:33 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committed sync batch length 1 starting with: test.sum
=== RUN   TestCheckSumDownload/subtest4
2025/09/22 04:29:35 DEBUG : test.sum: Uploading chunk 1/1
2025/09/22 04:29:36 DEBUG : test.sum: Uploading chunk 2/1
2025/09/22 04:29:36 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Adding "test.sum" to batch
2025/09/22 04:29:37 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Batch idle for 500ms so committing
2025/09/22 04:29:37 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committing sync batch length 1 starting with: test.sum
2025/09/22 04:29:37 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committed sync batch length 1 starting with: test.sum
=== RUN   TestCheckSumDownload/subtest5
2025/09/22 04:29:40 DEBUG : test.sum: Uploading chunk 1/1
2025/09/22 04:29:40 DEBUG : test.sum: Uploading chunk 2/1
2025/09/22 04:29:41 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Adding "test.sum" to batch
2025/09/22 04:29:41 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Batch idle for 500ms so committing
2025/09/22 04:29:41 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committing sync batch length 1 starting with: test.sum
2025/09/22 04:29:42 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committed sync batch length 1 starting with: test.sum
=== RUN   TestCheckSumDownload/subtest6
2025/09/22 04:29:44 DEBUG : data/banana: Uploading chunk 1/1
2025/09/22 04:29:45 DEBUG : data/banana: Uploading chunk 2/1
2025/09/22 04:29:45 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Adding "data/banana" to batch
2025/09/22 04:29:46 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Batch idle for 500ms so committing
2025/09/22 04:29:46 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committing sync batch length 1 starting with: data/banana
2025/09/22 04:29:46 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committed sync batch length 1 starting with: data/banana
2025/09/22 04:29:46 DEBUG : data/potato: Uploading chunk 1/1
2025/09/22 04:29:47 DEBUG : data/potato: Uploading chunk 2/1
2025/09/22 04:29:47 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Adding "data/potato" to batch
2025/09/22 04:29:48 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Batch idle for 500ms so committing
2025/09/22 04:29:48 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committing sync batch length 1 starting with: data/potato
2025/09/22 04:29:48 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committed sync batch length 1 starting with: data/potato
2025/09/22 04:29:49 DEBUG : test.sum: Uploading chunk 1/1
2025/09/22 04:29:49 DEBUG : test.sum: Uploading chunk 2/1
2025/09/22 04:29:50 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Adding "test.sum" to batch
2025/09/22 04:29:50 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Batch idle for 500ms so committing
2025/09/22 04:29:50 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committing sync batch length 1 starting with: test.sum
2025/09/22 04:29:51 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committed sync batch length 1 starting with: test.sum
=== RUN   TestCheckSumDownload/subtest7
--- PASS: TestCheckSumDownload (46.60s)
    --- PASS: TestCheckSumDownload/subtest1 (1.56s)
    --- PASS: TestCheckSumDownload/subtest2 (1.48s)
    --- PASS: TestCheckSumDownload/subtest3 (1.54s)
    --- PASS: TestCheckSumDownload/subtest4 (1.89s)
    --- PASS: TestCheckSumDownload/subtest5 (1.74s)
    --- PASS: TestCheckSumDownload/subtest6 (1.44s)
    --- PASS: TestCheckSumDownload/subtest7 (1.71s)
=== RUN   TestCopyFileBackupDir
    run.go:180: Remote "Dropbox root 'rclone-test-wukavix5kahi'", Local "Local file system at /tmp/rclone3418793086", Modify Window "1s"
2025/09/22 04:29:57 DEBUG : dst/file1: Uploading chunk 1/1
2025/09/22 04:29:57 DEBUG : dst/file1: Uploading chunk 2/1
2025/09/22 04:29:58 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Adding "dst/file1" to batch
2025/09/22 04:29:58 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Batch idle for 500ms so committing
2025/09/22 04:29:58 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committing sync batch length 1 starting with: dst/file1
2025/09/22 04:29:59 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committed sync batch length 1 starting with: dst/file1
2025/09/22 04:30:00 DEBUG : Creating backend with remote "TestDropbox:rclone-test-wukavix5kahi/backup"
2025/09/22 04:30:00 DEBUG : dst/file1: Sizes differ (src 14 vs dst 18)
2025/09/22 04:30:02 INFO  : dst/file1: Moved (server-side)
2025/09/22 04:30:02 DEBUG : dst/file1: Uploading chunk 1/1
2025/09/22 04:30:03 DEBUG : dst/file1: Uploading chunk 2/1
2025/09/22 04:30:03 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Adding "dst/file1" to batch
2025/09/22 04:30:04 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Batch idle for 500ms so committing
2025/09/22 04:30:04 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committing sync batch length 1 starting with: dst/file1
2025/09/22 04:30:05 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Committed sync batch length 1 starting with: dst/file1
2025/09/22 04:30:05 DEBUG : dst/file1: dropbox = d4b8d7e13c592e454a060a60b4606d5e5c5a03b023d97e24bf4682e9535a8778 OK
2025/09/22 04:30:05 INFO  : dst/file1: Copied (new)
2025/09/22 04:30:11 INFO  : Dropbox root 'rclone-test-wukavix5kahi/backup': Committing uploads - please wait...
--- PASS: TestCopyFileBackupDir (14.19s)
PASS
2025/09/22 04:30:11 DEBUG : Dropbox root 'rclone-test-wukavix5kahi': Purge remote
"./operations.test -test.v -test.timeout 1h0m0s -remote TestDropbox: -verbose -test.run '^(TestCheckSumDownload|TestCopyFileBackupDir)$'" - Finished OK in 1m1.796271918s (try 2/5)