"./vfs.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestDirRemoveName|TestReadFileHandleSeek)$|^TestFileSetModTime$/^(cache=off,open=false,write=false|cache=off,open=true,write=true)$'" - Starting (try 2/5) 2025/08/20 01:19:04 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-figiyoh9cevo" 2025/08/20 01:19:04 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/08/20 01:19:04 DEBUG : Starting OpenDrive session with ID: de4c1230f2f8a659086005f65ba98802d28d0d18f8af8148fdee25854c979608 2025/08/20 01:19:05 DEBUG : Creating backend with remote "/tmp/rclone2504914666" === RUN TestDirRemoveName run.go:180: Remote "OpenDrive root 'rclone-test-figiyoh9cevo'", Local "Local file system at /tmp/rclone2504914666", Modify Window "1s" 2025/08/20 01:19:05 INFO : OpenDrive root 'rclone-test-figiyoh9cevo': poll-interval is not supported by this remote 2025/08/20 01:19:05 NOTICE: OpenDrive root 'rclone-test-figiyoh9cevo': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/08/20 01:19:06 DEBUG : dir/file1: Uploading chunk 0, size=14, remain=0 2025/08/20 01:19:09 DEBUG : dir/file1: Remove: 2025/08/20 01:19:09 DEBUG : dir: Added virtual directory entry vDel: "file1" 2025/08/20 01:19:09 DEBUG : dir/file1: >Remove: err= 2025/08/20 01:19:10 DEBUG : WaitForWriters: timeout=30s 2025/08/20 01:19:10 DEBUG : dir: Looking for writers 2025/08/20 01:19:10 DEBUG : Looking for writers 2025/08/20 01:19:10 DEBUG : dir: reading active writers 2025/08/20 01:19:10 DEBUG : >WaitForWriters: --- PASS: TestDirRemoveName (6.03s) === RUN TestFileSetModTime === RUN TestFileSetModTime/cache=off,open=false,write=false run.go:180: Remote "OpenDrive root 'rclone-test-figiyoh9cevo'", Local "Local file system at /tmp/rclone2504914666", Modify Window "1s" 2025/08/20 01:19:11 INFO : OpenDrive root 'rclone-test-figiyoh9cevo': poll-interval is not supported by this remote 2025/08/20 01:19:11 NOTICE: OpenDrive root 'rclone-test-figiyoh9cevo': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/08/20 01:19:12 DEBUG : dir/file1: Uploading chunk 0, size=14, remain=0 2025/08/20 01:19:15 DEBUG : time_test: Uploading chunk 0, size=5, remain=0 2025/08/20 01:19:17 DEBUG : Can set mod time: true 2025/08/20 01:19:17 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK 2025/08/20 01:19:18 DEBUG : WaitForWriters: timeout=30s 2025/08/20 01:19:18 DEBUG : dir: Looking for writers 2025/08/20 01:19:18 DEBUG : file1: reading active writers 2025/08/20 01:19:18 DEBUG : Looking for writers 2025/08/20 01:19:18 DEBUG : dir: reading active writers 2025/08/20 01:19:18 DEBUG : >WaitForWriters: === RUN TestFileSetModTime/cache=off,open=true,write=true run.go:180: Remote "OpenDrive root 'rclone-test-figiyoh9cevo'", Local "Local file system at /tmp/rclone2504914666", Modify Window "1s" 2025/08/20 01:19:19 INFO : OpenDrive root 'rclone-test-figiyoh9cevo': poll-interval is not supported by this remote 2025/08/20 01:19:19 NOTICE: OpenDrive root 'rclone-test-figiyoh9cevo': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/08/20 01:19:20 DEBUG : dir/file1: Uploading chunk 0, size=14, remain=0 2025/08/20 01:19:22 DEBUG : dir/file1: Open: flags=O_WRONLY|O_TRUNC 2025/08/20 01:19:22 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err= 2025/08/20 01:19:22 DEBUG : dir: Added virtual directory entry vAddFile: "file1" 2025/08/20 01:19:22 DEBUG : OpenDrive root 'rclone-test-figiyoh9cevo': File to upload is small (5 bytes), uploading instead of streaming 2025/08/20 01:19:23 DEBUG : dir/file1: Uploading chunk 0, size=5, remain=0 2025/08/20 01:19:24 DEBUG : dir/file1: md5 = 5d41402abc4b2a76b9719d911017c592 OK 2025/08/20 01:19:24 DEBUG : dir/file1: Size and md5 of src and dst objects identical 2025/08/20 01:19:24 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK 2025/08/20 01:19:24 DEBUG : dir: Added virtual directory entry vAddFile: "file1" 2025/08/20 01:19:24 DEBUG : WaitForWriters: timeout=30s 2025/08/20 01:19:24 DEBUG : dir: Looking for writers 2025/08/20 01:19:24 DEBUG : file1: reading active writers 2025/08/20 01:19:24 DEBUG : Looking for writers 2025/08/20 01:19:24 DEBUG : dir: reading active writers 2025/08/20 01:19:24 DEBUG : >WaitForWriters: 2025/08/20 01:19:24 DEBUG : WaitForWriters: timeout=30s 2025/08/20 01:19:24 DEBUG : dir: Looking for writers 2025/08/20 01:19:24 DEBUG : file1: reading active writers 2025/08/20 01:19:24 DEBUG : Looking for writers 2025/08/20 01:19:24 DEBUG : dir: reading active writers 2025/08/20 01:19:24 DEBUG : >WaitForWriters: run.go:125: removing dir "dir" failed - try 1/3: folder not empty fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Flushing the directory cache fstest.go:289: Sleeping for 6s just to make sure --- PASS: TestFileSetModTime (23.70s) --- PASS: TestFileSetModTime/cache=off,open=false,write=false (8.16s) --- PASS: TestFileSetModTime/cache=off,open=true,write=true (15.54s) === RUN TestReadFileHandleSeek run.go:180: Remote "OpenDrive root 'rclone-test-figiyoh9cevo'", Local "Local file system at /tmp/rclone2504914666", Modify Window "1s" 2025/08/20 01:19:34 INFO : OpenDrive root 'rclone-test-figiyoh9cevo': poll-interval is not supported by this remote 2025/08/20 01:19:34 NOTICE: OpenDrive root 'rclone-test-figiyoh9cevo': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/08/20 01:19:36 DEBUG : dir/file1: Uploading chunk 0, size=16, remain=0 2025/08/20 01:19:37 DEBUG : dir/file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2025/08/20 01:19:38 DEBUG : dir/file1: Open: flags=O_RDONLY 2025/08/20 01:19:38 DEBUG : dir/file1: >Open: fd=dir/file1 (r), err= 2025/08/20 01:19:38 DEBUG : dir/file1: >OpenFile: fd=dir/file1 (r), err= 2025/08/20 01:19:38 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728 2025/08/20 01:19:38 DEBUG : dir/file1: ChunkedReader.Read at 0 length 1 chunkOffset 0 chunkSize 134217728 2025/08/20 01:19:38 DEBUG : dir/file1: waiting for in-sequence read to 5 for 20ms 2025/08/20 01:19:38 DEBUG : dir/file1: aborting in-sequence read wait, off=5 2025/08/20 01:19:38 DEBUG : dir/file1: failed to wait for in-sequence read to 5 2025/08/20 01:19:38 DEBUG : dir/file1: ReadFileHandle.seek from 1 to 5 (fs.RangeSeeker) 2025/08/20 01:19:38 DEBUG : dir/file1: ChunkedReader.RangeSeek from 1 to 5 length -1 2025/08/20 01:19:38 DEBUG : dir/file1: ChunkedReader.Read at -1 length 1 chunkOffset 5 chunkSize 134217728 2025/08/20 01:19:38 DEBUG : dir/file1: ChunkedReader.openRange at 5 length 134217728 2025/08/20 01:19:38 DEBUG : dir/file1: ReadFileHandle.seek from 6 to 3 (fs.RangeSeeker) 2025/08/20 01:19:38 DEBUG : dir/file1: ChunkedReader.RangeSeek from 6 to 3 length -1 2025/08/20 01:19:38 DEBUG : dir/file1: ChunkedReader.Read at -1 length 1 chunkOffset 3 chunkSize 134217728 2025/08/20 01:19:38 DEBUG : dir/file1: ChunkedReader.openRange at 3 length 134217728 2025/08/20 01:19:39 DEBUG : dir/file1: ReadFileHandle.seek from 4 to 13 (fs.RangeSeeker) 2025/08/20 01:19:39 DEBUG : dir/file1: ChunkedReader.RangeSeek from 4 to 13 length -1 2025/08/20 01:19:39 DEBUG : dir/file1: ChunkedReader.Read at -1 length 1 chunkOffset 13 chunkSize 134217728 2025/08/20 01:19:39 DEBUG : dir/file1: ChunkedReader.openRange at 13 length 134217728 2025/08/20 01:19:40 DEBUG : WaitForWriters: timeout=30s 2025/08/20 01:19:40 DEBUG : dir: Looking for writers 2025/08/20 01:19:40 DEBUG : file1: reading active writers 2025/08/20 01:19:40 DEBUG : Looking for writers 2025/08/20 01:19:40 DEBUG : dir: reading active writers 2025/08/20 01:19:40 DEBUG : >WaitForWriters: --- PASS: TestReadFileHandleSeek (6.45s) PASS 2025/08/20 01:19:41 DEBUG : OpenDrive root 'rclone-test-figiyoh9cevo': Purge remote "./vfs.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^(TestDirRemoveName|TestReadFileHandleSeek)$|^TestFileSetModTime$/^(cache=off,open=false,write=false|cache=off,open=true,write=true)$'" - Finished OK in 37.688009024s (try 2/5)