"./vfs.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestDirCreate|TestDirFileOpen|TestRWFileHandleMethodsWrite|TestReadFileHandleMethods|TestUnicodeNormalization|TestWriteFileHandleFlush)$|^TestFileRename$/^minimal,forceCache=false$|^TestFileSetModTime$/^cache=off,open=true,write=true$'" - Starting (try 2/5) 2026/03/10 02:33:04 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-copoquf1moro" 2026/03/10 02:33:04 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/03/10 02:33:05 DEBUG : Starting OpenDrive session with ID: 6f63ced675e97f237e7c0c318a6823dcc348a8dc1e093dfb79ba541d4dc9bce6 2026/03/10 02:33:05 DEBUG : Creating backend with remote "/tmp/rclone4093091061" === RUN TestDirCreate run.go:185: Remote "OpenDrive root 'rclone-test-copoquf1moro'", Local "Local file system at /tmp/rclone4093091061", Modify Window "1s" 2026/03/10 02:33:05 INFO : OpenDrive root 'rclone-test-copoquf1moro': poll-interval is not supported by this remote 2026/03/10 02:33:05 NOTICE: OpenDrive root 'rclone-test-copoquf1moro': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/03/10 02:33:07 DEBUG : dir/file1: Uploading chunk 0, size=14, remain=0 2026/03/10 02:33:09 DEBUG : dir/potato: Open: flags=O_WRONLY|O_CREATE 2026/03/10 02:33:09 DEBUG : dir: Added virtual directory entry vAddFile: "potato" 2026/03/10 02:33:09 DEBUG : dir/potato: >Open: fd=dir/potato (w), err= 2026/03/10 02:33:09 DEBUG : dir: Added virtual directory entry vAddFile: "potato" 2026/03/10 02:33:09 DEBUG : OpenDrive root 'rclone-test-copoquf1moro': File to upload is small (5 bytes), uploading instead of streaming 2026/03/10 02:33:10 DEBUG : dir/potato: Uploading chunk 0, size=5, remain=0 2026/03/10 02:33:11 DEBUG : dir/potato: size = 5 OK 2026/03/10 02:33:11 DEBUG : dir/potato: md5 = 5d41402abc4b2a76b9719d911017c592 OK 2026/03/10 02:33:11 DEBUG : dir/potato: Size and md5 of src and dst objects identical 2026/03/10 02:33:11 DEBUG : dir: Added virtual directory entry vAddFile: "potato" 2026/03/10 02:33:11 DEBUG : WaitForWriters: timeout=30s 2026/03/10 02:33:11 DEBUG : dir: Looking for writers 2026/03/10 02:33:11 DEBUG : file1: reading active writers 2026/03/10 02:33:11 DEBUG : potato: reading active writers 2026/03/10 02:33:11 DEBUG : Looking for writers 2026/03/10 02:33:11 DEBUG : dir: reading active writers 2026/03/10 02:33:11 DEBUG : >WaitForWriters: --- PASS: TestDirCreate (7.05s) === RUN TestDirFileOpen run.go:185: Remote "OpenDrive root 'rclone-test-copoquf1moro'", Local "Local file system at /tmp/rclone4093091061", Modify Window "1s" 2026/03/10 02:33:12 INFO : OpenDrive root 'rclone-test-copoquf1moro': poll-interval is not supported by this remote 2026/03/10 02:33:12 NOTICE: OpenDrive root 'rclone-test-copoquf1moro': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/03/10 02:33:13 DEBUG : dir/file1: Uploading chunk 0, size=14, remain=0 2026/03/10 02:33:15 DEBUG : dir: Added virtual directory entry vAddDir: "sub" 2026/03/10 02:33:15 DEBUG : dir/sub/file0: OpenFile: flags=O_RDWR|O_CREATE|O_TRUNC, perm=-rw-rw-rw- 2026/03/10 02:33:15 ERROR : dir/sub/: Dir.Stat error: failed to get folder list: Directory doesn't exist (Error 404) 2026/03/10 02:33:15 DEBUG : dir/sub/file0: >OpenFile: fd=, err=failed to get folder list: Directory doesn't exist (Error 404) dir_test.go:628: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:628 Error: Received unexpected error: failed to get folder list: Directory doesn't exist (Error 404) Test: TestDirFileOpen 2026/03/10 02:33:15 DEBUG : WaitForWriters: timeout=30s 2026/03/10 02:33:15 DEBUG : dir/sub: Looking for writers 2026/03/10 02:33:15 DEBUG : dir: Looking for writers 2026/03/10 02:33:15 DEBUG : file1: reading active writers 2026/03/10 02:33:15 DEBUG : sub: reading active writers 2026/03/10 02:33:15 DEBUG : Looking for writers 2026/03/10 02:33:15 DEBUG : dir: reading active writers 2026/03/10 02:33:15 DEBUG : >WaitForWriters: run.go:130: removing dir "dir" failed - try 1/3: folder not empty --- FAIL: TestDirFileOpen (5.56s) === RUN TestFileSetModTime === RUN TestFileSetModTime/cache=off,open=true,write=true run.go:185: Remote "OpenDrive root 'rclone-test-copoquf1moro'", Local "Local file system at /tmp/rclone4093091061", Modify Window "1s" 2026/03/10 02:33:17 INFO : OpenDrive root 'rclone-test-copoquf1moro': poll-interval is not supported by this remote 2026/03/10 02:33:17 NOTICE: OpenDrive root 'rclone-test-copoquf1moro': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/03/10 02:33:19 DEBUG : dir/file1: Uploading chunk 0, size=14, remain=0 2026/03/10 02:33:21 DEBUG : time_test: Uploading chunk 0, size=5, remain=0 2026/03/10 02:33:23 DEBUG : Can set mod time: true 2026/03/10 02:33:23 DEBUG : dir/file1: Open: flags=O_WRONLY|O_TRUNC 2026/03/10 02:33:23 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err= 2026/03/10 02:33:23 DEBUG : dir: Added virtual directory entry vAddFile: "file1" 2026/03/10 02:33:23 DEBUG : OpenDrive root 'rclone-test-copoquf1moro': File to upload is small (5 bytes), uploading instead of streaming 2026/03/10 02:33:23 DEBUG : dir/file1: Uploading chunk 0, size=5, remain=0 2026/03/10 02:33:24 DEBUG : dir/file1: size = 5 OK 2026/03/10 02:33:24 DEBUG : dir/file1: md5 = 5d41402abc4b2a76b9719d911017c592 OK 2026/03/10 02:33:24 DEBUG : dir/file1: Size and md5 of src and dst objects identical 2026/03/10 02:33:25 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK 2026/03/10 02:33:25 DEBUG : dir: Added virtual directory entry vAddFile: "file1" 2026/03/10 02:33:25 DEBUG : WaitForWriters: timeout=30s 2026/03/10 02:33:25 DEBUG : dir: Looking for writers 2026/03/10 02:33:25 DEBUG : file1: reading active writers 2026/03/10 02:33:25 DEBUG : Looking for writers 2026/03/10 02:33:25 DEBUG : dir: reading active writers 2026/03/10 02:33:25 DEBUG : >WaitForWriters: 2026/03/10 02:33:25 DEBUG : WaitForWriters: timeout=30s 2026/03/10 02:33:25 DEBUG : dir: Looking for writers 2026/03/10 02:33:25 DEBUG : file1: reading active writers 2026/03/10 02:33:25 DEBUG : Looking for writers 2026/03/10 02:33:25 DEBUG : dir: reading active writers 2026/03/10 02:33:25 DEBUG : >WaitForWriters: --- PASS: TestFileSetModTime (8.42s) --- PASS: TestFileSetModTime/cache=off,open=true,write=true (8.42s) === RUN TestFileRename === RUN TestFileRename/minimal,forceCache=false run.go:185: Remote "OpenDrive root 'rclone-test-copoquf1moro'", Local "Local file system at /tmp/rclone4093091061", Modify Window "1s" 2026/03/10 02:33:26 INFO : OpenDrive root 'rclone-test-copoquf1moro': poll-interval is not supported by this remote 2026/03/10 02:33:26 NOTICE: OpenDrive root 'rclone-test-copoquf1moro': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/03/10 02:33:26 DEBUG : OpenDrive root 'rclone-test-copoquf1moro': vfs cache: root is "/home/rclone/.cache/rclone" 2026/03/10 02:33:26 DEBUG : OpenDrive root 'rclone-test-copoquf1moro': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestOpenDrive/rclone-test-copoquf1moro" 2026/03/10 02:33:26 DEBUG : OpenDrive root 'rclone-test-copoquf1moro': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestOpenDrive/rclone-test-copoquf1moro" 2026/03/10 02:33:26 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestOpenDrive/rclone-test-copoquf1moro" 2026/03/10 02:33:26 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/03/10 02:33:26 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestOpenDrive/rclone-test-copoquf1moro" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestOpenDrive/rclone-test-copoquf1moro" 2026/03/10 02:33:26 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestOpenDrive/rclone-test-copoquf1moro" 2026/03/10 02:33:26 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/03/10 02:33:26 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestOpenDrive/rclone-test-copoquf1moro" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestOpenDrive/rclone-test-copoquf1moro" 2026/03/10 02:33:26 INFO : OpenDrive root 'rclone-test-copoquf1moro': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2026/03/10 02:33:27 DEBUG : dir/file1: Uploading chunk 0, size=14, remain=0 2026/03/10 02:33:29 DEBUG : WaitForWriters: timeout=30s 2026/03/10 02:33:29 DEBUG : dir: Looking for writers 2026/03/10 02:33:29 DEBUG : file1: reading active writers 2026/03/10 02:33:29 DEBUG : Looking for writers 2026/03/10 02:33:29 DEBUG : dir: reading active writers 2026/03/10 02:33:29 DEBUG : >WaitForWriters: 2026/03/10 02:33:30 INFO : dir/file1: Moved (server-side) to: newLeaf 2026/03/10 02:33:30 DEBUG : newLeaf: Updating file with newLeaf 0xc0001a9080 2026/03/10 02:33:30 DEBUG : dir: Added virtual directory entry vDel: "file1" 2026/03/10 02:33:30 DEBUG : Added virtual directory entry vAddFile: "newLeaf" fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure 2026/03/10 02:33:39 INFO : newLeaf: Moved (server-side) to: dir/file1 2026/03/10 02:33:39 DEBUG : dir/file1: Updating file with dir/file1 0xc0001a9080 2026/03/10 02:33:39 DEBUG : Added virtual directory entry vDel: "newLeaf" 2026/03/10 02:33:39 DEBUG : dir: Added virtual directory entry vAddFile: "file1" fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure 2026/03/10 02:33:47 DEBUG : dir/file1: Open: flags=O_WRONLY|O_TRUNC 2026/03/10 02:33:47 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err= 2026/03/10 02:33:47 DEBUG : dir: Added virtual directory entry vAddFile: "file1" 2026/03/10 02:33:47 DEBUG : dir/file1: File is currently open, delaying rename 0xc0001a9080 2026/03/10 02:33:47 DEBUG : dir: Added virtual directory entry vDel: "file1" 2026/03/10 02:33:47 DEBUG : Added virtual directory entry vAddFile: "newLeaf" 2026/03/10 02:33:47 DEBUG : OpenDrive root 'rclone-test-copoquf1moro': File to upload is small (25 bytes), uploading instead of streaming 2026/03/10 02:33:47 DEBUG : dir/file1: Uploading chunk 0, size=25, remain=0 2026/03/10 02:33:49 DEBUG : dir/file1: size = 25 OK 2026/03/10 02:33:49 DEBUG : dir/file1: md5 = c7247bead226dfd7bd970c17229f4044 OK 2026/03/10 02:33:49 DEBUG : dir/file1: Size and md5 of src and dst objects identical 2026/03/10 02:33:49 DEBUG : Added virtual directory entry vAddFile: "newLeaf" 2026/03/10 02:33:49 DEBUG : newLeaf: Running delayed rename now 2026/03/10 02:33:49 INFO : dir/file1: Moved (server-side) to: newLeaf 2026/03/10 02:33:49 DEBUG : newLeaf: Updating file with newLeaf 0xc0001a9080 2026/03/10 02:33:49 DEBUG : WaitForWriters: timeout=30s 2026/03/10 02:33:49 DEBUG : dir: Looking for writers 2026/03/10 02:33:49 DEBUG : Looking for writers 2026/03/10 02:33:49 DEBUG : dir: reading active writers 2026/03/10 02:33:49 DEBUG : newLeaf: reading active writers 2026/03/10 02:33:49 DEBUG : >WaitForWriters: 2026/03/10 02:33:50 DEBUG : WaitForWriters: timeout=30s 2026/03/10 02:33:50 DEBUG : dir: Looking for writers 2026/03/10 02:33:50 DEBUG : Looking for writers 2026/03/10 02:33:50 DEBUG : dir: reading active writers 2026/03/10 02:33:50 DEBUG : newLeaf: reading active writers 2026/03/10 02:33:50 DEBUG : >WaitForWriters: 2026/03/10 02:33:50 DEBUG : OpenDrive root 'rclone-test-copoquf1moro': vfs cache: cleaner exiting --- PASS: TestFileRename (24.85s) --- PASS: TestFileRename/minimal,forceCache=false (24.85s) === RUN TestReadFileHandleMethods run.go:185: Remote "OpenDrive root 'rclone-test-copoquf1moro'", Local "Local file system at /tmp/rclone4093091061", Modify Window "1s" 2026/03/10 02:33:51 INFO : OpenDrive root 'rclone-test-copoquf1moro': poll-interval is not supported by this remote 2026/03/10 02:33:51 NOTICE: OpenDrive root 'rclone-test-copoquf1moro': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/03/10 02:33:52 DEBUG : dir/file1: Uploading chunk 0, size=16, remain=0 2026/03/10 02:33:54 DEBUG : dir/file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 02:33:54 DEBUG : dir/file1: Open: flags=O_RDONLY 2026/03/10 02:33:54 DEBUG : dir/file1: >Open: fd=dir/file1 (r), err= 2026/03/10 02:33:54 DEBUG : dir/file1: >OpenFile: fd=dir/file1 (r), err= 2026/03/10 02:33:54 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728 2026/03/10 02:33:54 DEBUG : dir/file1: ChunkedReader.Read at 0 length 1 chunkOffset 0 chunkSize 134217728 2026/03/10 02:33:54 DEBUG : dir/file1: ChunkedReader.Read at 1 length 256 chunkOffset 0 chunkSize 134217728 2026/03/10 02:33:54 DEBUG : WaitForWriters: timeout=30s 2026/03/10 02:33:54 DEBUG : dir: Looking for writers 2026/03/10 02:33:54 DEBUG : file1: reading active writers 2026/03/10 02:33:54 DEBUG : Looking for writers 2026/03/10 02:33:54 DEBUG : dir: reading active writers 2026/03/10 02:33:54 DEBUG : >WaitForWriters: run.go:130: removing dir "dir" failed - try 1/3: folder not empty fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure --- PASS: TestReadFileHandleMethods (13.81s) === RUN TestRWFileHandleMethodsWrite run.go:185: Remote "OpenDrive root 'rclone-test-copoquf1moro'", Local "Local file system at /tmp/rclone4093091061", Modify Window "1s" 2026/03/10 02:34:05 INFO : OpenDrive root 'rclone-test-copoquf1moro': poll-interval is not supported by this remote 2026/03/10 02:34:05 DEBUG : OpenDrive root 'rclone-test-copoquf1moro': vfs cache: root is "/home/rclone/.cache/rclone" 2026/03/10 02:34:05 DEBUG : OpenDrive root 'rclone-test-copoquf1moro': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestOpenDrive/rclone-test-copoquf1moro" 2026/03/10 02:34:05 DEBUG : OpenDrive root 'rclone-test-copoquf1moro': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestOpenDrive/rclone-test-copoquf1moro" 2026/03/10 02:34:05 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestOpenDrive/rclone-test-copoquf1moro" 2026/03/10 02:34:05 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/03/10 02:34:05 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestOpenDrive/rclone-test-copoquf1moro" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestOpenDrive/rclone-test-copoquf1moro" 2026/03/10 02:34:05 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestOpenDrive/rclone-test-copoquf1moro" 2026/03/10 02:34:05 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/03/10 02:34:05 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestOpenDrive/rclone-test-copoquf1moro" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestOpenDrive/rclone-test-copoquf1moro" 2026/03/10 02:34:05 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/03/10 02:34:05 INFO : OpenDrive root 'rclone-test-copoquf1moro': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2026/03/10 02:34:05 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/03/10 02:34:05 DEBUG : file1: newRWFileHandle: 2026/03/10 02:34:05 DEBUG : file1(0xc000137ac0): openPending: 2026/03/10 02:34:05 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2026/03/10 02:34:05 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 02:34:05 DEBUG : file1(0xc000137ac0): >openPending: err= 2026/03/10 02:34:05 DEBUG : file1: >newRWFileHandle: err= 2026/03/10 02:34:05 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 02:34:05 DEBUG : file1: >Open: fd=file1 (rw), err= 2026/03/10 02:34:05 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2026/03/10 02:34:05 DEBUG : file1(0xc000137ac0): _writeAt: size=5, off=0 2026/03/10 02:34:05 DEBUG : file1(0xc000137ac0): >_writeAt: n=5, err= 2026/03/10 02:34:05 DEBUG : file1(0xc000137ac0): _writeAt: size=7, off=5 2026/03/10 02:34:05 DEBUG : file1(0xc000137ac0): >_writeAt: n=7, err= 2026/03/10 02:34:05 DEBUG : file1: vfs cache: truncate to size=11 2026/03/10 02:34:05 DEBUG : file1(0xc000137ac0): close: 2026/03/10 02:34:05 DEBUG : file1: vfs cache: setting modification time to 2026-03-10 02:34:05.23891432 +0000 UTC m=+60.762038657 2026/03/10 02:34:05 INFO : file1: vfs cache: queuing for upload in 100ms 2026/03/10 02:34:05 DEBUG : file1(0xc000137ac0): >close: err= 2026/03/10 02:34:05 DEBUG : file1(0xc000137ac0): close: 2026/03/10 02:34:05 DEBUG : file1(0xc000137ac0): >close: err=file already closed 2026/03/10 02:34:05 DEBUG : WaitForWriters: timeout=30s 2026/03/10 02:34:05 DEBUG : Looking for writers 2026/03/10 02:34:05 DEBUG : file1: reading active writers 2026/03/10 02:34:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2026/03/10 02:34:05 DEBUG : Looking for writers 2026/03/10 02:34:05 DEBUG : file1: reading active writers 2026/03/10 02:34:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2026/03/10 02:34:05 DEBUG : Looking for writers 2026/03/10 02:34:05 DEBUG : file1: reading active writers 2026/03/10 02:34:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2026/03/10 02:34:05 DEBUG : Looking for writers 2026/03/10 02:34:05 DEBUG : file1: reading active writers 2026/03/10 02:34:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2026/03/10 02:34:05 DEBUG : file1: vfs cache: starting upload 2026/03/10 02:34:05 DEBUG : Looking for writers 2026/03/10 02:34:05 DEBUG : file1: reading active writers 2026/03/10 02:34:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2026/03/10 02:34:05 DEBUG : Looking for writers 2026/03/10 02:34:05 DEBUG : file1: reading active writers 2026/03/10 02:34:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2026/03/10 02:34:05 DEBUG : Looking for writers 2026/03/10 02:34:05 DEBUG : file1: reading active writers 2026/03/10 02:34:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2026/03/10 02:34:06 DEBUG : file1: Uploading chunk 0, size=11, remain=0 2026/03/10 02:34:06 DEBUG : Looking for writers 2026/03/10 02:34:06 DEBUG : file1: reading active writers 2026/03/10 02:34:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/03/10 02:34:07 DEBUG : file1: size = 11 OK 2026/03/10 02:34:07 DEBUG : file1: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2026/03/10 02:34:07 INFO : file1: Copied (new) 2026/03/10 02:34:07 DEBUG : file1: vfs cache: fingerprint now "11,2026-03-10 02:34:05 +0000 UTC,5eb63bbbe01eeed093cb22bb8f5acdc3" 2026/03/10 02:34:07 DEBUG : file1: vfs cache: writeback object to VFS layer 2026/03/10 02:34:07 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 02:34:07 INFO : file1: vfs cache: upload succeeded try #1 2026/03/10 02:34:07 DEBUG : Looking for writers 2026/03/10 02:34:07 DEBUG : file1: reading active writers 2026/03/10 02:34:07 DEBUG : >WaitForWriters: 2026/03/10 02:34:07 DEBUG : WaitForWriters: timeout=30s 2026/03/10 02:34:07 DEBUG : Looking for writers 2026/03/10 02:34:07 DEBUG : file1: reading active writers 2026/03/10 02:34:07 DEBUG : >WaitForWriters: 2026/03/10 02:34:07 DEBUG : OpenDrive root 'rclone-test-copoquf1moro': vfs cache: cleaner exiting --- PASS: TestRWFileHandleMethodsWrite (3.16s) === RUN TestUnicodeNormalization run.go:185: Remote "OpenDrive root 'rclone-test-copoquf1moro'", Local "Local file system at /tmp/rclone4093091061", Modify Window "1s" 2026/03/10 02:34:09 DEBUG : normal name with no special characters.txt: Uploading chunk 0, size=5, remain=0 2026/03/10 02:34:11 DEBUG : 測試_Русский___ě_áñ: Uploading chunk 0, size=5, remain=0 2026/03/10 02:34:12 INFO : OpenDrive root 'rclone-test-copoquf1moro': poll-interval is not supported by this remote 2026/03/10 02:34:12 NOTICE: OpenDrive root 'rclone-test-copoquf1moro': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/03/10 02:34:12 DEBUG : normal name with no special characters.txt: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 02:34:13 DEBUG : normal name with no special characters.txt: Open: flags=O_RDONLY 2026/03/10 02:34:13 DEBUG : normal name with no special characters.txt: >Open: fd=normal name with no special characters.txt (r), err= 2026/03/10 02:34:13 DEBUG : normal name with no special characters.txt: >OpenFile: fd=normal name with no special characters.txt (r), err= 2026/03/10 02:34:13 DEBUG : normal name with no special characters.txt: ChunkedReader.openRange at 0 length 134217728 2026/03/10 02:34:13 DEBUG : normal name with no special characters.txt: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2026/03/10 02:34:13 DEBUG : 測試_Русский___ě_áñ: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 02:34:13 DEBUG : 測試_Русский___ě_áñ: Open: flags=O_RDONLY 2026/03/10 02:34:13 DEBUG : 測試_Русский___ě_áñ: >Open: fd=測試_Русский___ě_áñ (r), err= 2026/03/10 02:34:13 DEBUG : 測試_Русский___ě_áñ: >OpenFile: fd=測試_Русский___ě_áñ (r), err= 2026/03/10 02:34:13 DEBUG : 測試_Русский___ě_áñ: ChunkedReader.openRange at 0 length 134217728 2026/03/10 02:34:13 DEBUG : 測試_Русский___ě_áñ: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2026/03/10 02:34:13 DEBUG : normal name with no special characters.txt: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 02:34:13 DEBUG : normal name with no special characters.txt: Open: flags=O_RDONLY 2026/03/10 02:34:13 DEBUG : normal name with no special characters.txt: >Open: fd=normal name with no special characters.txt (r), err= 2026/03/10 02:34:13 DEBUG : normal name with no special characters.txt: >OpenFile: fd=normal name with no special characters.txt (r), err= 2026/03/10 02:34:13 DEBUG : normal name with no special characters.txt: ChunkedReader.openRange at 0 length 134217728 2026/03/10 02:34:14 DEBUG : normal name with no special characters.txt: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2026/03/10 02:34:14 DEBUG : 測試_Русский___ě_áñ: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 02:34:14 DEBUG : 測試_Русский___ě_áñ: >OpenFile: fd=, err=file does not exist 2026/03/10 02:34:14 DEBUG : WaitForWriters: timeout=30s 2026/03/10 02:34:14 DEBUG : Looking for writers 2026/03/10 02:34:14 DEBUG : normal name with no special characters.txt: reading active writers 2026/03/10 02:34:14 DEBUG : 測試_Русский___ě_áñ: reading active writers 2026/03/10 02:34:14 DEBUG : >WaitForWriters: fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure --- PASS: TestUnicodeNormalization (14.03s) === RUN TestWriteFileHandleFlush run.go:185: Remote "OpenDrive root 'rclone-test-copoquf1moro'", Local "Local file system at /tmp/rclone4093091061", Modify Window "1s" 2026/03/10 02:34:22 INFO : OpenDrive root 'rclone-test-copoquf1moro': poll-interval is not supported by this remote 2026/03/10 02:34:22 NOTICE: OpenDrive root 'rclone-test-copoquf1moro': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/03/10 02:34:22 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/03/10 02:34:22 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/03/10 02:34:22 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 02:34:22 DEBUG : file1: >Open: fd=file1 (w), err= 2026/03/10 02:34:22 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/03/10 02:34:22 DEBUG : file1: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions 2026/03/10 02:34:22 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 02:34:22 DEBUG : OpenDrive root 'rclone-test-copoquf1moro': File to upload is small (5 bytes), uploading instead of streaming 2026/03/10 02:34:23 DEBUG : file1: Uploading chunk 0, size=5, remain=0 2026/03/10 02:34:24 DEBUG : file1: size = 5 OK 2026/03/10 02:34:24 DEBUG : file1: md5 = 5d41402abc4b2a76b9719d911017c592 OK 2026/03/10 02:34:24 DEBUG : file1: Size and md5 of src and dst objects identical 2026/03/10 02:34:24 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 02:34:24 DEBUG : file1: WriteFileHandle.Flush nothing to do 2026/03/10 02:34:24 DEBUG : WaitForWriters: timeout=30s 2026/03/10 02:34:24 DEBUG : Looking for writers 2026/03/10 02:34:24 DEBUG : file1: reading active writers 2026/03/10 02:34:24 DEBUG : >WaitForWriters: fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure --- PASS: TestWriteFileHandleFlush (9.92s) FAIL 2026/03/10 02:34:32 DEBUG : OpenDrive root 'rclone-test-copoquf1moro': Purge remote "./vfs.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestDirCreate|TestDirFileOpen|TestRWFileHandleMethodsWrite|TestReadFileHandleMethods|TestUnicodeNormalization|TestWriteFileHandleFlush)$|^TestFileRename$/^minimal,forceCache=false$|^TestFileSetModTime$/^cache=off,open=true,write=true$'" - Finished ERROR in 1m28.064470658s (try 2/5): exit status 1: Failed [TestDirFileOpen]