"./operations.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestCheckSum|TestCopyFileCompareDest|TestDeduplicateNewestByHash|TestRemoveExisting|TestRmdirsNoLeaveRoot)$|^TestHashSums$/^Md5$'" - Starting (try 2/5) 2025/03/09 02:32:07 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-mupoxix3rule" 2025/03/09 02:32:07 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/03/09 02:32:07 DEBUG : Creating backend with remote "/tmp/rclone1474338428" === RUN TestCheckSum run.go:180: Remote "files root 'rclone-test-mupoxix3rule'", Local "Local file system at /tmp/rclone1474338428", Modify Window "1s" 2025/03/09 02:32:07 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-mupoxix3rule/data" === RUN TestCheckSum/subtest1 === RUN TestCheckSum/subtest2 === RUN TestCheckSum/subtest3 === RUN TestCheckSum/subtest4 === NAME TestCheckSum check_test.go:411: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:411 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:432 Error: An error is expected but got nil. Test: TestCheckSum Messages: no expected error in run 4 check_test.go:413: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:413 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:432 Error: Not equal: expected: 1 actual : 0 Test: TestCheckSum Messages: wrong error count in run 4 check_test.go:387: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:387 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:421 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:432 Error: Not equal: expected: []string{"", "* banana", "= potato"} actual : []string{"", "= banana", "= potato"} Diff: --- Expected +++ Actual @@ -2,3 +2,3 @@ (string) "", - (string) (len=8) "* banana", + (string) (len=8) "= banana", (string) (len=8) "= potato" Test: TestCheckSum Messages: wrong combined result in run 4 check_test.go:387: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:387 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:424 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:432 Error: Not equal: expected: []string{"", "potato"} actual : []string{"", "banana", "potato"} Diff: --- Expected +++ Actual @@ -1,3 +1,4 @@ -([]string) (len=2) { +([]string) (len=3) { (string) "", + (string) (len=6) "banana", (string) (len=6) "potato" Test: TestCheckSum Messages: wrong match result in run 4 check_test.go:387: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:387 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:425 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:432 Error: Not equal: expected: []string{"", "banana"} actual : []string{} Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=2) { - (string) "", - (string) (len=6) "banana" +([]string) { } Test: TestCheckSum Messages: wrong differ result in run 4 === RUN TestCheckSum/subtest5 === RUN TestCheckSum/subtest6 === NAME TestCheckSum check_test.go:413: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:413 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:432 Error: Not equal: expected: 2 actual : 1 Test: TestCheckSum Messages: wrong error count in run 6 check_test.go:387: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:387 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:421 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:432 Error: Not equal: expected: []string{"", "* potato", "+ orange", "= banana"} actual : []string{"", "+ orange", "= banana", "= potato"} Diff: --- Expected +++ Actual @@ -2,5 +2,5 @@ (string) "", - (string) (len=8) "* potato", (string) (len=8) "+ orange", - (string) (len=8) "= banana" + (string) (len=8) "= banana", + (string) (len=8) "= potato" } Test: TestCheckSum Messages: wrong combined result in run 6 check_test.go:387: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:387 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:424 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:432 Error: Not equal: expected: []string{"", "banana"} actual : []string{"", "banana", "potato"} Diff: --- Expected +++ Actual @@ -1,4 +1,5 @@ -([]string) (len=2) { +([]string) (len=3) { (string) "", - (string) (len=6) "banana" + (string) (len=6) "banana", + (string) (len=6) "potato" } Test: TestCheckSum Messages: wrong match result in run 6 check_test.go:387: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:387 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:425 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:432 Error: Not equal: expected: []string{"", "potato"} actual : []string{} Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=2) { - (string) "", - (string) (len=6) "potato" +([]string) { } Test: TestCheckSum Messages: wrong differ result in run 6 === RUN TestCheckSum/subtest7 --- FAIL: TestCheckSum (16.61s) --- PASS: TestCheckSum/subtest1 (0.51s) --- PASS: TestCheckSum/subtest2 (0.52s) --- PASS: TestCheckSum/subtest3 (0.52s) --- PASS: TestCheckSum/subtest4 (0.60s) --- PASS: TestCheckSum/subtest5 (0.66s) --- PASS: TestCheckSum/subtest6 (0.68s) --- PASS: TestCheckSum/subtest7 (0.66s) === RUN TestCopyFileCompareDest run.go:180: Remote "files root 'rclone-test-mupoxix3rule'", Local "Local file system at /tmp/rclone1474338428", Modify Window "1s" 2025/03/09 02:32:24 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-mupoxix3rule/dst" 2025/03/09 02:32:25 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-mupoxix3rule/CompareDest" 2025/03/09 02:32:26 DEBUG : one: Need to transfer - File not found at Destination 2025/03/09 02:32:27 DEBUG : one: Dst hash empty - aborting Src hash check 2025/03/09 02:32:27 INFO : one: Copied (new) 2025/03/09 02:32:28 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/09 02:32:29 DEBUG : one: Dst hash empty - aborting Src hash check 2025/03/09 02:32:29 INFO : one: Copied (replaced existing) 2025/03/09 02:32:32 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/09 02:32:32 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/03/09 02:32:32 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/09 02:32:33 DEBUG : two: Need to transfer - File not found at Destination 2025/03/09 02:32:33 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/03/09 02:32:33 DEBUG : two: Destination found in --compare-dest, skipping 2025/03/09 02:32:34 DEBUG : two: Need to transfer - File not found at Destination 2025/03/09 02:32:34 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/03/09 02:32:34 DEBUG : two: Destination found in --compare-dest, skipping 2025/03/09 02:32:34 DEBUG : two: Need to transfer - File not found at Destination 2025/03/09 02:32:35 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/03/09 02:32:35 DEBUG : two: Dst hash empty - aborting Src hash check 2025/03/09 02:32:35 INFO : two: Copied (new) --- PASS: TestCopyFileCompareDest (13.04s) === RUN TestDeduplicateNewestByHash run.go:180: Remote "files root 'rclone-test-mupoxix3rule'", Local "Local file system at /tmp/rclone1474338428", Modify Window "1s" 2025/03/09 02:32:40 INFO : files root 'rclone-test-mupoxix3rule': Looking for duplicate md5 hashes using newest mode. fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:299: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:299 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/dedupe_test.go:164 Error: Should be true Test: TestDeduplicateNewestByHash Messages: listing wrong, want another (100), not-one (5) got also/one (100), another (100), not-one (5), one (100) fstest.go:185: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:185 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/dedupe_test.go:164 Error: Should be true Test: TestDeduplicateNewestByHash Messages: Unexpected file "one" fstest.go:185: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:185 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/dedupe_test.go:164 Error: Should be true Test: TestDeduplicateNewestByHash Messages: Unexpected file "also/one" --- FAIL: TestDeduplicateNewestByHash (12.29s) === RUN TestHashSums run.go:180: Remote "files root 'rclone-test-mupoxix3rule'", Local "Local file system at /tmp/rclone1474338428", Modify Window "1s" === RUN TestHashSums/Md5 operations_test.go:280: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:280 Error: " empty space\n potato2\n" does not contain "336d5ebc5436534e61d16e63ddfca327 empty space\n" Test: TestHashSums/Md5 operations_test.go:280: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:280 Error: " empty space\n potato2\n" does not contain "d6548b156ea68a4e003e786df99eee76 potato2\n" Test: TestHashSums/Md5 --- FAIL: TestHashSums (2.59s) --- FAIL: TestHashSums/Md5 (0.13s) === RUN TestRmdirsNoLeaveRoot run.go:180: Remote "files root 'rclone-test-mupoxix3rule'", Local "Local file system at /tmp/rclone1474338428", Modify Window "1s" 2025/03/09 02:32:53 INFO : A2: Making directory 2025/03/09 02:32:53 INFO : A1/B2: Making directory 2025/03/09 02:32:53 INFO : A1/B2/C2: Making directory 2025/03/09 02:32:54 INFO : A1/B1/C3: Making directory 2025/03/09 02:32:54 INFO : A3: Making directory 2025/03/09 02:32:54 INFO : A3/B3: Making directory 2025/03/09 02:32:54 INFO : A3/B3/C4: Making directory 2025/03/09 02:32:56 DEBUG : removing 1 level 3 directories 2025/03/09 02:32:56 INFO : A3/B3/C4: Removing directory 2025/03/09 02:32:57 DEBUG : removing 2 level 3 directories 2025/03/09 02:32:57 INFO : A1/B2/C2: Removing directory 2025/03/09 02:32:57 INFO : A1/B1/C3: Removing directory 2025/03/09 02:32:57 DEBUG : removing 2 level 2 directories 2025/03/09 02:32:57 INFO : A3/B3: Removing directory 2025/03/09 02:32:57 INFO : A1/B2: Removing directory 2025/03/09 02:32:57 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-mupoxix3rule/A1/B2 not empty`) 2025/03/09 02:32:57 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/03/09 02:32:57 DEBUG : pacer: Reducing sleep to 15ms 2025/03/09 02:32:57 DEBUG : removing 2 level 1 directories 2025/03/09 02:32:57 INFO : A3: Removing directory 2025/03/09 02:32:57 INFO : A2: Removing directory 2025/03/09 02:32:58 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-mupoxix3rule/A3 not empty`) 2025/03/09 02:32:58 DEBUG : pacer: Rate limited, increasing sleep to 30ms 2025/03/09 02:32:58 DEBUG : pacer: Reducing sleep to 22.5ms 2025/03/09 02:32:58 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-mupoxix3rule/A3 not empty`) 2025/03/09 02:32:58 DEBUG : pacer: Rate limited, increasing sleep to 45ms 2025/03/09 02:32:58 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-mupoxix3rule/A3 not empty`) 2025/03/09 02:32:58 DEBUG : pacer: Rate limited, increasing sleep to 90ms 2025/03/09 02:32:58 DEBUG : pacer: low level retry 4/10 (error Folder Not Empty - `Folder rclone-test-mupoxix3rule/A3 not empty`) 2025/03/09 02:32:58 DEBUG : pacer: Rate limited, increasing sleep to 180ms 2025/03/09 02:32:58 DEBUG : pacer: low level retry 5/10 (error Folder Not Empty - `Folder rclone-test-mupoxix3rule/A3 not empty`) 2025/03/09 02:32:58 DEBUG : pacer: Rate limited, increasing sleep to 360ms 2025/03/09 02:32:58 DEBUG : pacer: low level retry 6/10 (error Folder Not Empty - `Folder rclone-test-mupoxix3rule/A3 not empty`) 2025/03/09 02:32:58 DEBUG : pacer: Rate limited, increasing sleep to 720ms 2025/03/09 02:32:59 DEBUG : pacer: low level retry 7/10 (error Folder Not Empty - `Folder rclone-test-mupoxix3rule/A3 not empty`) 2025/03/09 02:32:59 DEBUG : pacer: Rate limited, increasing sleep to 1.44s 2025/03/09 02:32:59 DEBUG : pacer: low level retry 8/10 (error Folder Not Empty - `Folder rclone-test-mupoxix3rule/A3 not empty`) 2025/03/09 02:32:59 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/03/09 02:33:01 DEBUG : pacer: Reducing sleep to 1.5s 2025/03/09 02:33:03 DEBUG : pacer: Reducing sleep to 1.125s 2025/03/09 02:33:04 DEBUG : pacer: Reducing sleep to 843.75ms 2025/03/09 02:33:05 DEBUG : pacer: Reducing sleep to 632.8125ms 2025/03/09 02:33:06 DEBUG : pacer: Reducing sleep to 474.609375ms 2025/03/09 02:33:07 DEBUG : pacer: Reducing sleep to 355.957031ms 2025/03/09 02:33:07 DEBUG : pacer: Reducing sleep to 266.967773ms 2025/03/09 02:33:08 DEBUG : pacer: Reducing sleep to 200.225829ms 2025/03/09 02:33:08 DEBUG : pacer: Reducing sleep to 150.169371ms 2025/03/09 02:33:08 DEBUG : pacer: Reducing sleep to 112.627028ms 2025/03/09 02:33:08 DEBUG : pacer: Reducing sleep to 84.470271ms 2025/03/09 02:33:08 DEBUG : pacer: Reducing sleep to 63.352703ms 2025/03/09 02:33:08 DEBUG : pacer: Reducing sleep to 47.514527ms 2025/03/09 02:33:09 DEBUG : removing 1 level 3 directories 2025/03/09 02:33:09 INFO : A1/B1/C1: Removing directory 2025/03/09 02:33:09 DEBUG : pacer: Reducing sleep to 35.635895ms 2025/03/09 02:33:09 DEBUG : removing 1 level 2 directories 2025/03/09 02:33:09 INFO : A1/B1: Removing directory 2025/03/09 02:33:09 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-mupoxix3rule/A1/B1 not empty`) 2025/03/09 02:33:09 DEBUG : pacer: Rate limited, increasing sleep to 71.27179ms 2025/03/09 02:33:09 DEBUG : pacer: Reducing sleep to 53.453842ms 2025/03/09 02:33:09 DEBUG : removing 1 level 1 directories 2025/03/09 02:33:09 INFO : A1: Removing directory 2025/03/09 02:33:09 DEBUG : pacer: Reducing sleep to 40.090381ms 2025/03/09 02:33:09 DEBUG : removing 1 level 0 directories 2025/03/09 02:33:09 INFO : files root 'rclone-test-mupoxix3rule': Removing directory 2025/03/09 02:33:09 DEBUG : pacer: Reducing sleep to 30.067785ms 2025/03/09 02:33:09 DEBUG : pacer: Reducing sleep to 22.550838ms 2025/03/09 02:33:10 DEBUG : pacer: Reducing sleep to 16.913128ms 2025/03/09 02:33:10 ERROR : : error listing: directory not found --- PASS: TestRmdirsNoLeaveRoot (17.64s) === RUN TestRemoveExisting run.go:180: Remote "files root 'rclone-test-mupoxix3rule'", Local "Local file system at /tmp/rclone1474338428", Modify Window "1s" 2025/03/09 02:33:11 DEBUG : pacer: Reducing sleep to 12.684846ms 2025/03/09 02:33:11 DEBUG : pacer: Reducing sleep to 10ms 2025/03/09 02:33:12 DEBUG : sub dir/test remove existing: TEST: renaming existing object to "sub dir/test remove existing.zofizaq8" before starting 2025/03/09 02:33:13 DEBUG : sub dir/test remove existing.zofizaq8: TEST: removing renamed existing file after operation 2025/03/09 02:33:14 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890123456789: TEST: renaming existing object to "sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.fafuvaq6" before starting 2025/03/09 02:33:15 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.fafuvaq6: TEST: renaming existing back after failed operation 2025/03/09 02:33:15 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890123456789: TEST: renaming existing object to "sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.kodojiq4" before starting 2025/03/09 02:33:16 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.kodojiq4: TEST: removing renamed existing file after operation --- PASS: TestRemoveExisting (7.56s) FAIL 2025/03/09 02:33:17 DEBUG : files root 'rclone-test-mupoxix3rule': Purge remote "./operations.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestCheckSum|TestCopyFileCompareDest|TestDeduplicateNewestByHash|TestRemoveExisting|TestRmdirsNoLeaveRoot)$|^TestHashSums$/^Md5$'" - Finished ERROR in 1m10.707012818s (try 2/5): exit status 1: Failed [TestCheckSum TestDeduplicateNewestByHash TestHashSums/Md5]