"./vfs.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestDirCreate|TestDirFileOpen|TestDirMkdirSub|TestDirRemoveName|TestDirRename|TestZipManyFiles)$'" - Starting (try 2/5) 2025/10/15 04:28:09 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-zedovet1bapi" 2025/10/15 04:28:09 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/10/15 04:28:10 DEBUG : Starting OpenDrive session with ID: 104df95ac8422686bc69ee3fdf1588bdab711a6c9aba23eb98f24e379f6c1cc4 2025/10/15 04:28:10 DEBUG : Creating backend with remote "/tmp/rclone3995101965" === RUN TestDirCreate run.go:180: Remote "OpenDrive root 'rclone-test-zedovet1bapi'", Local "Local file system at /tmp/rclone3995101965", Modify Window "1s" 2025/10/15 04:28:10 INFO : OpenDrive root 'rclone-test-zedovet1bapi': poll-interval is not supported by this remote 2025/10/15 04:28:10 NOTICE: OpenDrive root 'rclone-test-zedovet1bapi': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/10/15 04:28:12 DEBUG : dir/file1: Uploading chunk 0, size=14, remain=0 dir_test.go:354: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:354 Error: Should be true Test: TestDirCreate 2025/10/15 04:28:13 DEBUG : dir/potato: Open: flags=O_WRONLY|O_CREATE 2025/10/15 04:28:13 DEBUG : dir: Added virtual directory entry vAddFile: "potato" 2025/10/15 04:28:13 DEBUG : dir/potato: >Open: fd=dir/potato (w), err= 2025/10/15 04:28:13 DEBUG : dir: Added virtual directory entry vAddFile: "potato" 2025/10/15 04:28:13 DEBUG : OpenDrive root 'rclone-test-zedovet1bapi': File to upload is small (5 bytes), uploading instead of streaming 2025/10/15 04:28:14 DEBUG : dir/potato: Uploading chunk 0, size=5, remain=0 2025/10/15 04:28:15 DEBUG : dir/potato: md5 = 5d41402abc4b2a76b9719d911017c592 OK 2025/10/15 04:28:15 DEBUG : dir/potato: Size and md5 of src and dst objects identical 2025/10/15 04:28:15 DEBUG : dir: Added virtual directory entry vAddFile: "potato" 2025/10/15 04:28:15 DEBUG : WaitForWriters: timeout=30s 2025/10/15 04:28:15 DEBUG : dir: Looking for writers 2025/10/15 04:28:15 DEBUG : file1: reading active writers 2025/10/15 04:28:15 DEBUG : potato: reading active writers 2025/10/15 04:28:15 DEBUG : Looking for writers 2025/10/15 04:28:15 DEBUG : dir: reading active writers 2025/10/15 04:28:15 DEBUG : >WaitForWriters: --- FAIL: TestDirCreate (6.42s) === RUN TestDirMkdirSub run.go:180: Remote "OpenDrive root 'rclone-test-zedovet1bapi'", Local "Local file system at /tmp/rclone3995101965", Modify Window "1s" 2025/10/15 04:28:16 INFO : OpenDrive root 'rclone-test-zedovet1bapi': poll-interval is not supported by this remote 2025/10/15 04:28:16 NOTICE: OpenDrive root 'rclone-test-zedovet1bapi': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/10/15 04:28:18 DEBUG : dir/file1: Uploading chunk 0, size=14, remain=0 2025/10/15 04:28:20 DEBUG : dir: Added virtual directory entry vAddDir: "sub" 2025/10/15 04:28:20 DEBUG : dir/sub: Added virtual directory entry vAddDir: "subsub" 2025/10/15 04:28:21 DEBUG : WaitForWriters: timeout=30s 2025/10/15 04:28:21 DEBUG : dir/sub/subsub: Looking for writers 2025/10/15 04:28:21 DEBUG : dir/sub: Looking for writers 2025/10/15 04:28:21 DEBUG : subsub: reading active writers 2025/10/15 04:28:21 DEBUG : dir: Looking for writers 2025/10/15 04:28:21 DEBUG : file1: reading active writers 2025/10/15 04:28:21 DEBUG : sub: reading active writers 2025/10/15 04:28:21 DEBUG : Looking for writers 2025/10/15 04:28:21 DEBUG : dir: reading active writers 2025/10/15 04:28:21 DEBUG : >WaitForWriters: --- PASS: TestDirMkdirSub (6.89s) === RUN TestDirRemoveName run.go:180: Remote "OpenDrive root 'rclone-test-zedovet1bapi'", Local "Local file system at /tmp/rclone3995101965", Modify Window "1s" 2025/10/15 04:28:23 INFO : OpenDrive root 'rclone-test-zedovet1bapi': poll-interval is not supported by this remote 2025/10/15 04:28:23 NOTICE: OpenDrive root 'rclone-test-zedovet1bapi': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/10/15 04:28:25 DEBUG : dir/file1: Uploading chunk 0, size=14, remain=0 2025/10/15 04:28:26 DEBUG : dir/file1: Remove: 2025/10/15 04:28:26 DEBUG : dir: Added virtual directory entry vDel: "file1" 2025/10/15 04:28:26 DEBUG : dir/file1: >Remove: err= dir_test.go:504: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:504 Error: Should be true Test: TestDirRemoveName 2025/10/15 04:28:27 DEBUG : WaitForWriters: timeout=30s 2025/10/15 04:28:27 DEBUG : dir: Looking for writers 2025/10/15 04:28:27 DEBUG : Looking for writers 2025/10/15 04:28:27 DEBUG : dir: reading active writers 2025/10/15 04:28:27 DEBUG : >WaitForWriters: --- FAIL: TestDirRemoveName (4.29s) === RUN TestDirRename run.go:180: Remote "OpenDrive root 'rclone-test-zedovet1bapi'", Local "Local file system at /tmp/rclone3995101965", Modify Window "1s" 2025/10/15 04:28:28 INFO : OpenDrive root 'rclone-test-zedovet1bapi': poll-interval is not supported by this remote 2025/10/15 04:28:28 NOTICE: OpenDrive root 'rclone-test-zedovet1bapi': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/10/15 04:28:29 DEBUG : dir/file1: Uploading chunk 0, size=14, remain=0 2025/10/15 04:28:31 DEBUG : dir/file3: Uploading chunk 0, size=15, remain=0 2025/10/15 04:28:33 ERROR : dir/not found: Dir.Rename error: file does not exist 2025/10/15 04:28:33 DEBUG : dir2: same parent dir (ODFfOTQ4MDI3Nl9KemRzNg) - using folder/rename instead of move_copy 2025/10/15 04:28:33 DEBUG : dir: Updating dir with dir2 0xc0007640d0 2025/10/15 04:28:33 DEBUG : dir: forgetting directory cache 2025/10/15 04:28:33 DEBUG : Added virtual directory entry vDel: "dir" 2025/10/15 04:28:33 DEBUG : Added virtual directory entry vAddDir: "dir2" 2025/10/15 04:28:35 INFO : dir2/file1: Moved (server-side) to: file2 2025/10/15 04:28:35 DEBUG : file2: Updating file with file2 0xc00069c000 2025/10/15 04:28:35 DEBUG : dir2: Added virtual directory entry vDel: "file1" 2025/10/15 04:28:35 DEBUG : Added virtual directory entry vAddFile: "file2" 2025/10/15 04:28:35 INFO : dir2/file3: Deleted 2025/10/15 04:28:36 INFO : file2: Moved (server-side) to: dir2/file3 2025/10/15 04:28:36 DEBUG : dir2/file3: Updating file with dir2/file3 0xc00069c000 2025/10/15 04:28:36 DEBUG : Added virtual directory entry vDel: "file2" 2025/10/15 04:28:36 DEBUG : dir2: Added virtual directory entry vAddFile: "file3" 2025/10/15 04:28:36 DEBUG : Added virtual directory entry vAddDir: "empty directory" 2025/10/15 04:28:37 DEBUG : renamed empty directory: same parent dir (ODFfOTQ4MDI3Nl9KemRzNg) - using folder/rename instead of move_copy 2025/10/15 04:28:37 DEBUG : empty directory: Updating dir with renamed empty directory 0xc000764a90 2025/10/15 04:28:37 DEBUG : empty directory: forgetting directory cache 2025/10/15 04:28:37 DEBUG : Added virtual directory entry vDel: "empty directory" 2025/10/15 04:28:37 DEBUG : Added virtual directory entry vAddDir: "renamed empty directory" 2025/10/15 04:28:37 DEBUG : dir2: Renaming to "dir3" 2025/10/15 04:28:37 DEBUG : WaitForWriters: timeout=30s 2025/10/15 04:28:37 DEBUG : renamed empty directory: Looking for writers 2025/10/15 04:28:37 DEBUG : dir3: Looking for writers 2025/10/15 04:28:37 DEBUG : file3: reading active writers 2025/10/15 04:28:37 DEBUG : Looking for writers 2025/10/15 04:28:37 DEBUG : dir3: reading active writers 2025/10/15 04:28:37 DEBUG : renamed empty directory: reading active writers 2025/10/15 04:28:37 DEBUG : >WaitForWriters: --- PASS: TestDirRename (10.69s) === RUN TestDirFileOpen run.go:180: Remote "OpenDrive root 'rclone-test-zedovet1bapi'", Local "Local file system at /tmp/rclone3995101965", Modify Window "1s" 2025/10/15 04:28:38 INFO : OpenDrive root 'rclone-test-zedovet1bapi': poll-interval is not supported by this remote 2025/10/15 04:28:38 NOTICE: OpenDrive root 'rclone-test-zedovet1bapi': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/10/15 04:28:39 DEBUG : dir/file1: Uploading chunk 0, size=14, remain=0 2025/10/15 04:28:42 DEBUG : dir: Added virtual directory entry vAddDir: "sub" 2025/10/15 04:28:42 DEBUG : dir/sub/file0: OpenFile: flags=O_RDWR|O_CREATE|O_TRUNC, perm=-rw-rw-rw- 2025/10/15 04:28:42 DEBUG : dir/sub/file0: Open: flags=O_RDWR|O_CREATE|O_TRUNC 2025/10/15 04:28:42 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file0" 2025/10/15 04:28:42 DEBUG : dir/sub/file0: >Open: fd=dir/sub/file0 (w), err= 2025/10/15 04:28:42 DEBUG : dir/sub/file0: >OpenFile: fd=dir/sub/file0 (w), err= 2025/10/15 04:28:42 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file0" 2025/10/15 04:28:42 DEBUG : dir/sub/file2: OpenFile: flags=O_RDWR|O_CREATE|O_TRUNC, perm=-rw-rw-rw- 2025/10/15 04:28:42 DEBUG : dir/sub/file2: Open: flags=O_RDWR|O_CREATE|O_TRUNC 2025/10/15 04:28:42 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file2" 2025/10/15 04:28:42 DEBUG : dir/sub/file2: >Open: fd=dir/sub/file2 (w), err= 2025/10/15 04:28:42 DEBUG : dir/sub/file2: >OpenFile: fd=dir/sub/file2 (w), err= 2025/10/15 04:28:42 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file2" 2025/10/15 04:28:42 DEBUG : OpenDrive root 'rclone-test-zedovet1bapi': File to upload is small (12 bytes), uploading instead of streaming 2025/10/15 04:28:43 DEBUG : dir/sub/file2: Uploading chunk 0, size=12, remain=0 2025/10/15 04:28:44 DEBUG : dir/sub/file2: md5 = fc3ff98e8c6a0d3087d515c0473f8677 OK 2025/10/15 04:28:44 DEBUG : dir/sub/file2: Size and md5 of src and dst objects identical 2025/10/15 04:28:44 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file2" 2025/10/15 04:28:44 DEBUG : forgetting directory cache 2025/10/15 04:28:44 DEBUG : dir: forgetting directory cache 2025/10/15 04:28:44 DEBUG : dir/sub: forgetting directory cache 2025/10/15 04:28:44 DEBUG : dir/sub: Removed virtual directory entry vAddFile: "file2" 2025/10/15 04:28:44 DEBUG : dir: Removed virtual directory entry vAddDir: "sub" 2025/10/15 04:28:44 DEBUG : OpenDrive root 'rclone-test-zedovet1bapi': File to upload is small (5 bytes), uploading instead of streaming 2025/10/15 04:28:44 DEBUG : dir/sub/file0: Uploading chunk 0, size=5, remain=0 2025/10/15 04:28:45 DEBUG : dir/sub/file0: md5 = 5d41402abc4b2a76b9719d911017c592 OK 2025/10/15 04:28:45 DEBUG : dir/sub/file0: Size and md5 of src and dst objects identical 2025/10/15 04:28:45 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file0" 2025/10/15 04:28:45 DEBUG : WaitForWriters: timeout=30s 2025/10/15 04:28:45 DEBUG : dir/sub: Looking for writers 2025/10/15 04:28:45 DEBUG : file0: reading active writers 2025/10/15 04:28:45 DEBUG : file2: reading active writers 2025/10/15 04:28:45 DEBUG : dir: Looking for writers 2025/10/15 04:28:45 DEBUG : file1: reading active writers 2025/10/15 04:28:45 DEBUG : sub: reading active writers 2025/10/15 04:28:45 DEBUG : Looking for writers 2025/10/15 04:28:45 DEBUG : dir: reading active writers 2025/10/15 04:28:45 DEBUG : >WaitForWriters: --- PASS: TestDirFileOpen (9.02s) === RUN TestZipManyFiles run.go:180: Remote "OpenDrive root 'rclone-test-zedovet1bapi'", Local "Local file system at /tmp/rclone3995101965", Modify Window "1s" 2025/10/15 04:28:47 INFO : OpenDrive root 'rclone-test-zedovet1bapi': poll-interval is not supported by this remote 2025/10/15 04:28:47 NOTICE: OpenDrive root 'rclone-test-zedovet1bapi': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/10/15 04:28:49 DEBUG : flat/f000.txt: Uploading chunk 0, size=7, remain=0 2025/10/15 04:28:50 DEBUG : flat/f001.txt: Uploading chunk 0, size=14, remain=0 run.go:285: Failed to put "flat/f001.txt" to "OpenDrive root 'rclone-test-zedovet1bapi'": failed to get fileinfo: File was not found (Error 404) 2025/10/15 04:28:51 DEBUG : WaitForWriters: timeout=30s 2025/10/15 04:28:51 DEBUG : Looking for writers 2025/10/15 04:28:51 DEBUG : >WaitForWriters: run.go:125: removing dir "flat" failed - try 1/3: folder not empty run.go:125: removing dir "flat" failed - try 2/3: folder not empty run.go:125: removing dir "flat" failed - try 3/3: folder not empty run.go:128: removing dir "flat" failed: folder not empty fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:301: Flushing the directory cache fstest.go:305: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:173 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:388 /usr/local/go/src/testing/testing.go:1211 /usr/local/go/src/testing/testing.go:1445 /usr/local/go/src/testing/testing.go:1786 /usr/local/go/src/runtime/panic.go:636 /usr/local/go/src/testing/testing.go:1041 /usr/local/go/src/testing/testing.go:1125 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:285 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:292 /home/rclone/go/src/github.com/rclone/rclone/vfs/zip_test.go:61 Error: Should be true Test: TestZipManyFiles Messages: listing wrong, want got flat/f000.txt (7), flat/f001.txt (14) fstest.go:191: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:191 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:308 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:173 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:388 /usr/local/go/src/testing/testing.go:1211 /usr/local/go/src/testing/testing.go:1445 /usr/local/go/src/testing/testing.go:1786 /usr/local/go/src/runtime/panic.go:636 /usr/local/go/src/testing/testing.go:1041 /usr/local/go/src/testing/testing.go:1125 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:285 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:292 /home/rclone/go/src/github.com/rclone/rclone/vfs/zip_test.go:61 Error: Should be true Test: TestZipManyFiles Messages: Unexpected file "flat/f000.txt" fstest.go:191: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:191 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:308 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:173 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:388 /usr/local/go/src/testing/testing.go:1211 /usr/local/go/src/testing/testing.go:1445 /usr/local/go/src/testing/testing.go:1786 /usr/local/go/src/runtime/panic.go:636 /usr/local/go/src/testing/testing.go:1041 /usr/local/go/src/testing/testing.go:1125 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:285 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:292 /home/rclone/go/src/github.com/rclone/rclone/vfs/zip_test.go:61 Error: Should be true Test: TestZipManyFiles Messages: Unexpected file "flat/f001.txt" fstest.go:327: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:327 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:173 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:388 /usr/local/go/src/testing/testing.go:1211 /usr/local/go/src/testing/testing.go:1445 /usr/local/go/src/testing/testing.go:1786 /usr/local/go/src/runtime/panic.go:636 /usr/local/go/src/testing/testing.go:1041 /usr/local/go/src/testing/testing.go:1125 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:285 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:292 /home/rclone/go/src/github.com/rclone/rclone/vfs/zip_test.go:61 Error: Not equal: expected: []string{} actual : []string{"flat"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) { +([]string) (len=1) { + (string) (len=4) "flat" } Test: TestZipManyFiles Messages: directories --- FAIL: TestZipManyFiles (16.10s) FAIL 2025/10/15 04:29:03 DEBUG : OpenDrive root 'rclone-test-zedovet1bapi': Purge remote "./vfs.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestDirCreate|TestDirFileOpen|TestDirMkdirSub|TestDirRemoveName|TestDirRename|TestZipManyFiles)$'" - Finished ERROR in 55.012502941s (try 2/5): exit status 1: Failed [TestDirCreate TestDirRemoveName TestZipManyFiles]