"./operations.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestCheck|TestCheckDownload|TestCheckSizeOnly|TestCheckSum|TestCheckSumDownload|TestCopyFile|TestCopyURL|TestMaxDeleteSize|TestMoveFile|TestParseSumFile|TestPurge|TestRemoveExisting|TestRmdirsNoLeaveRoot)$'" - Starting (try 2/5) 2025/01/21 01:18:12 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-yuzonud8heto" 2025/01/21 01:18:12 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/01/21 01:18:12 DEBUG : Starting OpenDrive session with ID: c9d47f5f877a2ed1fc889ab1e5837469ea18e612e700cfdb639d83a68eb3af72 2025/01/21 01:18:13 DEBUG : Creating backend with remote "/tmp/rclone1505049525" === RUN TestCheck run.go:180: Remote "OpenDrive root 'rclone-test-yuzonud8heto'", Local "Local file system at /tmp/rclone1505049525", Modify Window "1s" 2025/01/21 01:18:14 DEBUG : rutabaga: Uploading chunk 0, size=8, remain=0 === RUN TestCheck/1 === RUN TestCheck/2 2025/01/21 01:18:16 DEBUG : empty space: Uploading chunk 0, size=1, remain=0 === NAME TestCheck fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:286: Sleeping for 6s just to make sure === RUN TestCheck/3 2025/01/21 01:18:27 DEBUG : potato2: Uploading chunk 0, size=60, remain=0 === RUN TestCheck/4 === RUN TestCheck/5 2025/01/21 01:18:30 DEBUG : remotepotato: Uploading chunk 0, size=60, remain=0 === RUN TestCheck/6 === RUN TestCheck/7 --- PASS: TestCheck (19.40s) --- PASS: TestCheck/1 (0.18s) --- PASS: TestCheck/2 (0.18s) --- PASS: TestCheck/3 (0.19s) --- PASS: TestCheck/4 (0.18s) --- PASS: TestCheck/5 (0.19s) --- PASS: TestCheck/6 (0.18s) --- PASS: TestCheck/7 (0.18s) === RUN TestCheckDownload run.go:180: Remote "OpenDrive root 'rclone-test-yuzonud8heto'", Local "Local file system at /tmp/rclone1505049525", Modify Window "1s" 2025/01/21 01:18:32 DEBUG : rutabaga: Uploading chunk 0, size=8, remain=0 fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:286: Sleeping for 6s just to make sure === RUN TestCheckDownload/1 === RUN TestCheckDownload/2 2025/01/21 01:18:43 DEBUG : empty space: Uploading chunk 0, size=1, remain=0 === RUN TestCheckDownload/3 2025/01/21 01:18:45 DEBUG : potato2: Uploading chunk 0, size=60, remain=0 === RUN TestCheckDownload/4 === RUN TestCheckDownload/5 2025/01/21 01:18:49 DEBUG : remotepotato: Uploading chunk 0, size=60, remain=0 === RUN TestCheckDownload/6 === RUN TestCheckDownload/7 --- PASS: TestCheckDownload (19.95s) --- PASS: TestCheckDownload/1 (0.36s) --- PASS: TestCheckDownload/2 (0.53s) --- PASS: TestCheckDownload/3 (0.35s) --- PASS: TestCheckDownload/4 (0.73s) --- PASS: TestCheckDownload/5 (0.53s) --- PASS: TestCheckDownload/6 (0.35s) --- PASS: TestCheckDownload/7 (0.55s) === RUN TestCheckSizeOnly run.go:180: Remote "OpenDrive root 'rclone-test-yuzonud8heto'", Local "Local file system at /tmp/rclone1505049525", Modify Window "1s" 2025/01/21 01:18:53 DEBUG : rutabaga: Uploading chunk 0, size=8, remain=0 === RUN TestCheckSizeOnly/1 === RUN TestCheckSizeOnly/2 2025/01/21 01:18:55 DEBUG : empty space: Uploading chunk 0, size=1, remain=0 === RUN TestCheckSizeOnly/3 2025/01/21 01:18:57 DEBUG : potato2: Uploading chunk 0, size=60, remain=0 === RUN TestCheckSizeOnly/4 === RUN TestCheckSizeOnly/5 2025/01/21 01:18:59 DEBUG : remotepotato: Uploading chunk 0, size=60, remain=0 === RUN TestCheckSizeOnly/6 === RUN TestCheckSizeOnly/7 --- PASS: TestCheckSizeOnly (9.99s) --- PASS: TestCheckSizeOnly/1 (0.17s) --- PASS: TestCheckSizeOnly/2 (0.17s) --- PASS: TestCheckSizeOnly/3 (0.17s) --- PASS: TestCheckSizeOnly/4 (0.18s) --- PASS: TestCheckSizeOnly/5 (0.20s) --- PASS: TestCheckSizeOnly/6 (0.17s) --- PASS: TestCheckSizeOnly/7 (0.19s) === RUN TestParseSumFile run.go:180: Remote "OpenDrive root 'rclone-test-yuzonud8heto'", Local "Local file system at /tmp/rclone1505049525", Modify Window "1s" 2025/01/21 01:19:03 DEBUG : test.sum: Uploading chunk 0, size=81, remain=0 2025/01/21 01:19:04 NOTICE: test.sum: improperly formatted checksum line 4 2025/01/21 01:19:04 NOTICE: test.sum: improperly formatted checksum line 5 2025/01/21 01:19:04 NOTICE: test.sum: improperly formatted checksum line 6 2025/01/21 01:19:04 NOTICE: test.sum: 2 warning(s) suppressed... 2025/01/21 01:19:05 DEBUG : test.sum: Uploading chunk 0, size=90, remain=0 2025/01/21 01:19:06 NOTICE: test.sum: improperly formatted checksum line 4 2025/01/21 01:19:06 NOTICE: test.sum: improperly formatted checksum line 5 2025/01/21 01:19:06 NOTICE: test.sum: improperly formatted checksum line 6 2025/01/21 01:19:06 NOTICE: test.sum: 2 warning(s) suppressed... --- PASS: TestParseSumFile (4.75s) === RUN TestCheckSum run.go:180: Remote "OpenDrive root 'rclone-test-yuzonud8heto'", Local "Local file system at /tmp/rclone1505049525", Modify Window "1s" 2025/01/21 01:19:07 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-yuzonud8heto/data" 2025/01/21 01:19:07 DEBUG : Starting OpenDrive session with ID: 6ed57722771d098ce871ebe534a9c2ae6bf3c8d7f47d13f9bcd87c64481b4591 2025/01/21 01:19:09 DEBUG : data/banana: Uploading chunk 0, size=13, remain=0 2025/01/21 01:19:11 DEBUG : test.sum: Uploading chunk 0, size=41, remain=0 === RUN TestCheckSum/subtest1 2025/01/21 01:19:14 DEBUG : data/potato: Uploading chunk 0, size=15, remain=0 2025/01/21 01:19:15 DEBUG : test.sum: Uploading chunk 0, size=41, remain=0 === RUN TestCheckSum/subtest2 2025/01/21 01:19:17 DEBUG : test.sum: Uploading chunk 0, size=82, remain=0 === NAME TestCheckSum fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:286: Sleeping for 6s just to make sure === RUN TestCheckSum/subtest3 2025/01/21 01:19:27 DEBUG : test.sum: Uploading chunk 0, size=82, remain=0 === RUN TestCheckSum/subtest4 2025/01/21 01:19:30 DEBUG : test.sum: Uploading chunk 0, size=123, remain=0 === NAME TestCheckSum fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:286: Sleeping for 6s just to make sure === RUN TestCheckSum/subtest5 2025/01/21 01:19:40 DEBUG : test.sum: Uploading chunk 0, size=123, remain=0 === RUN TestCheckSum/subtest6 2025/01/21 01:19:43 DEBUG : data/banana: Uploading chunk 0, size=13, remain=0 2025/01/21 01:19:44 DEBUG : data/potato: Uploading chunk 0, size=15, remain=0 2025/01/21 01:19:46 DEBUG : test.sum: Uploading chunk 0, size=82, remain=0 === RUN TestCheckSum/subtest7 --- PASS: TestCheckSum (42.43s) --- PASS: TestCheckSum/subtest1 (0.69s) --- PASS: TestCheckSum/subtest2 (0.51s) --- PASS: TestCheckSum/subtest3 (0.68s) --- PASS: TestCheckSum/subtest4 (0.52s) --- PASS: TestCheckSum/subtest5 (0.52s) --- PASS: TestCheckSum/subtest6 (0.91s) --- PASS: TestCheckSum/subtest7 (0.51s) === RUN TestCheckSumDownload run.go:180: Remote "OpenDrive root 'rclone-test-yuzonud8heto'", Local "Local file system at /tmp/rclone1505049525", Modify Window "1s" 2025/01/21 01:19:49 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-yuzonud8heto/data" 2025/01/21 01:19:50 DEBUG : Starting OpenDrive session with ID: a2ed7c17e95faf745e71361c9ee040acf536f2f37981244cb840edf4e5a22ed9 2025/01/21 01:19:52 DEBUG : data/banana: Uploading chunk 0, size=13, remain=0 2025/01/21 01:19:53 DEBUG : test.sum: Uploading chunk 0, size=41, remain=0 fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:286: Sleeping for 6s just to make sure === RUN TestCheckSumDownload/subtest1 2025/01/21 01:20:04 DEBUG : data/potato: Uploading chunk 0, size=15, remain=0 2025/01/21 01:20:06 DEBUG : test.sum: Uploading chunk 0, size=41, remain=0 === RUN TestCheckSumDownload/subtest2 2025/01/21 01:20:10 DEBUG : test.sum: Uploading chunk 0, size=82, remain=0 === RUN TestCheckSumDownload/subtest3 2025/01/21 01:20:13 DEBUG : test.sum: Uploading chunk 0, size=82, remain=0 === RUN TestCheckSumDownload/subtest4 2025/01/21 01:20:15 DEBUG : test.sum: Uploading chunk 0, size=123, remain=0 === RUN TestCheckSumDownload/subtest5 2025/01/21 01:20:19 DEBUG : test.sum: Uploading chunk 0, size=123, remain=0 === RUN TestCheckSumDownload/subtest6 2025/01/21 01:20:22 DEBUG : data/banana: Uploading chunk 0, size=13, remain=0 2025/01/21 01:20:23 DEBUG : data/potato: Uploading chunk 0, size=15, remain=0 2025/01/21 01:20:25 DEBUG : test.sum: Uploading chunk 0, size=82, remain=0 === RUN TestCheckSumDownload/subtest7 --- PASS: TestCheckSumDownload (38.88s) --- PASS: TestCheckSumDownload/subtest1 (0.85s) --- PASS: TestCheckSumDownload/subtest2 (1.15s) --- PASS: TestCheckSumDownload/subtest3 (1.07s) --- PASS: TestCheckSumDownload/subtest4 (0.72s) --- PASS: TestCheckSumDownload/subtest5 (0.77s) --- PASS: TestCheckSumDownload/subtest6 (0.78s) --- PASS: TestCheckSumDownload/subtest7 (0.74s) === RUN TestCopyFile run.go:180: Remote "OpenDrive root 'rclone-test-yuzonud8heto'", Local "Local file system at /tmp/rclone1505049525", Modify Window "1s" 2025/01/21 01:20:28 DEBUG : file1: Need to transfer - File not found at Destination 2025/01/21 01:20:30 DEBUG : sub/file2: Uploading chunk 0, size=14, remain=0 2025/01/21 01:20:31 DEBUG : file1: md5 = 0ef726ce9b1a7692357ff70dd321d595 OK 2025/01/21 01:20:31 INFO : file1: Copied (new) to: sub/file2 2025/01/21 01:20:31 DEBUG : file1: Need to transfer - File not found at Destination 2025/01/21 01:20:31 DEBUG : sub/file2: Uploading chunk 0, size=14, remain=0 2025/01/21 01:20:32 DEBUG : file1: md5 = 0ef726ce9b1a7692357ff70dd321d595 OK 2025/01/21 01:20:32 INFO : file1: Copied (new) to: sub/file2 2025/01/21 01:20:33 DEBUG : OpenDrive root 'rclone-test-yuzonud8heto': don't need to copy/move sub/file2, it is already at target location --- PASS: TestCopyFile (6.25s) === RUN TestMaxDeleteSize run.go:180: Remote "OpenDrive root 'rclone-test-yuzonud8heto'", Local "Local file system at /tmp/rclone1505049525", Modify Window "1s" 2025/01/21 01:20:35 DEBUG : small: Uploading chunk 0, size=10, remain=0 2025/01/21 01:20:37 DEBUG : medium: Uploading chunk 0, size=60, remain=0 2025/01/21 01:20:40 DEBUG : large: Uploading chunk 0, size=100, remain=0 2025/01/21 01:20:41 DEBUG : Waiting for deletions to finish 2025/01/21 01:20:41 ERROR : small: Got fatal error on delete: --max-delete-size threshold reached 2025/01/21 01:20:41 INFO : large: Deleted 2025/01/21 01:20:41 INFO : medium: Deleted operations_test.go:492: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:492 Error: Not equal: expected: 1 actual : 3 Test: TestMaxDeleteSize fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:286: Sleeping for 6s just to make sure --- FAIL: TestMaxDeleteSize (15.50s) === RUN TestPurge 2025/01/21 01:20:50 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-tozaziv7kubi" 2025/01/21 01:20:50 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/01/21 01:20:50 DEBUG : Starting OpenDrive session with ID: cd4116bcd81b9a200ae8864e4e3acc22361df0b9b9fe1655eade4a461c07e921 2025/01/21 01:20:51 DEBUG : Creating backend with remote "/tmp/rclone2143584312" run.go:180: Remote "OpenDrive root 'rclone-test-tozaziv7kubi'", Local "Local file system at /tmp/rclone2143584312", Modify Window "1s" run.go:285: Failed to put "A1/B1/C1/one" to "OpenDrive root 'rclone-test-tozaziv7kubi'": failed to get folder list: Directory doesn't exist (Error 404) 2025/01/21 01:20:51 DEBUG : OpenDrive root 'rclone-test-tozaziv7kubi': Purge remote --- FAIL: TestPurge (1.83s) === RUN TestRmdirsNoLeaveRoot run.go:180: Remote "OpenDrive root 'rclone-test-yuzonud8heto'", Local "Local file system at /tmp/rclone1505049525", Modify Window "1s" 2025/01/21 01:20:53 DEBUG : A1/B1/C1/one: Uploading chunk 0, size=3, remain=0 2025/01/21 01:20:55 INFO : A2: Making directory 2025/01/21 01:20:55 INFO : A1/B2: Making directory 2025/01/21 01:20:55 INFO : A1/B2/C2: Making directory 2025/01/21 01:20:56 INFO : A1/B1/C3: Making directory 2025/01/21 01:20:56 INFO : A3: Making directory 2025/01/21 01:20:57 INFO : A3/B3: Making directory operations_test.go:657: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:657 Error: Received unexpected error: failed to get folder list: Directory doesn't exist (Error 404) Test: TestRmdirsNoLeaveRoot fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:286: Sleeping for 6s just to make sure --- FAIL: TestRmdirsNoLeaveRoot (16.67s) === RUN TestCopyURL run.go:180: Remote "OpenDrive root 'rclone-test-yuzonud8heto'", Local "Local file system at /tmp/rclone1505049525", Modify Window "1s" 2025/01/21 01:21:09 DEBUG : file1: Uploading chunk 0, size=14, remain=0 2025/01/21 01:21:10 DEBUG : filename.txt: File name found in url 2025/01/21 01:21:11 DEBUG : filename.txt: Uploading chunk 0, size=14, remain=0 2025/01/21 01:21:12 DEBUG : headerfilename.txt: filename found in Content-Disposition header. 2025/01/21 01:21:13 DEBUG : headerfilename.txt: Uploading chunk 0, size=14, remain=0 2025/01/21 01:21:15 DEBUG : file2: Uploading chunk 0, size=14, remain=0 --- PASS: TestCopyURL (8.80s) === RUN TestMoveFile run.go:180: Remote "OpenDrive root 'rclone-test-yuzonud8heto'", Local "Local file system at /tmp/rclone1505049525", Modify Window "1s" 2025/01/21 01:21:17 DEBUG : file1: Need to transfer - File not found at Destination 2025/01/21 01:21:18 DEBUG : sub/file2: Uploading chunk 0, size=14, remain=0 2025/01/21 01:21:19 DEBUG : file1: md5 = 0ef726ce9b1a7692357ff70dd321d595 OK 2025/01/21 01:21:19 INFO : file1: Copied (new) to: sub/file2 2025/01/21 01:21:19 INFO : file1: Deleted 2025/01/21 01:21:20 DEBUG : file1: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2025/01/21 01:21:20 DEBUG : file1: Unchanged skipping 2025/01/21 01:21:20 INFO : file1: Deleted 2025/01/21 01:21:20 DEBUG : OpenDrive root 'rclone-test-yuzonud8heto': don't need to copy/move sub/file2, it is already at target location fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:286: Sleeping for 6s just to make sure --- PASS: TestMoveFile (12.30s) === RUN TestRemoveExisting run.go:180: Remote "OpenDrive root 'rclone-test-yuzonud8heto'", Local "Local file system at /tmp/rclone1505049525", Modify Window "1s" 2025/01/21 01:21:30 DEBUG : sub dir/test remove existing: Uploading chunk 0, size=11, remain=0 2025/01/21 01:21:32 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890123456789: Uploading chunk 0, size=21, remain=0 2025/01/21 01:21:35 DEBUG : sub dir/test remove existing: TEST: renaming existing object to "sub dir/test remove existing.sopujov2" before starting 2025/01/21 01:21:35 DEBUG : sub dir/test remove existing: same parent dir (ODFfNzk4NzUyMF9XWlFyMA) - using file/rename instead of move_copy for sub dir/test remove existing.sopujov2 2025/01/21 01:21:35 DEBUG : sub dir/test remove existing.sopujov2: TEST: removing renamed existing file after operation 2025/01/21 01:21:36 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890123456789: TEST: renaming existing object to "sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.yirunuz6" before starting 2025/01/21 01:21:36 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890123456789: same parent dir (ODFfNzk4NzUyMF9XWlFyMA) - using file/rename instead of move_copy for sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.yirunuz6 2025/01/21 01:21:37 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.yirunuz6: TEST: renaming existing back after failed operation 2025/01/21 01:21:37 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.yirunuz6: same parent dir (ODFfNzk4NzUyMF9XWlFyMA) - using file/rename instead of move_copy for sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890123456789 2025/01/21 01:21:38 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890123456789: TEST: renaming existing object to "sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.rosahun2" before starting 2025/01/21 01:21:38 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890123456789: same parent dir (ODFfNzk4NzUyMF9XWlFyMA) - using file/rename instead of move_copy for sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.rosahun2 2025/01/21 01:21:39 DEBUG : sub dir/test remove existing with long name 123456789012345678901234567890123456789012345678901234567890.rosahun2: TEST: removing renamed existing file after operation --- PASS: TestRemoveExisting (10.52s) FAIL 2025/01/21 01:21:40 DEBUG : OpenDrive root 'rclone-test-yuzonud8heto': Purge remote "./operations.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestCheck|TestCheckDownload|TestCheckSizeOnly|TestCheckSum|TestCheckSumDownload|TestCopyFile|TestCopyURL|TestMaxDeleteSize|TestMoveFile|TestParseSumFile|TestPurge|TestRemoveExisting|TestRmdirsNoLeaveRoot)$'" - Finished ERROR in 3m28.860846806s (try 2/5): exit status 1: Failed [TestMaxDeleteSize TestPurge TestRmdirsNoLeaveRoot]