"./vfs.test -test.v -test.timeout 1h0m0s -remote TestImageKit: -verbose -test.run '^(TestDirMetadataExtension|TestDirReadDirAll)$'" - Starting (try 2/5) 2025/04/22 04:34:11 DEBUG : Creating backend with remote "TestImageKit:rclone-test-ziwowoh1dabe" 2025/04/22 04:34:11 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/04/22 04:34:12 DEBUG : Creating backend with remote "/tmp/rclone1531028639" === RUN TestDirReadDirAll run.go:180: Remote "FS imagekit: /rclone-test-ziwowoh1dabe", Local "Local file system at /tmp/rclone1531028639", Modify Window "876000h0m0s" 2025/04/22 04:34:12 INFO : FS imagekit: /rclone-test-ziwowoh1dabe: poll-interval is not supported by this remote 2025/04/22 04:34:12 NOTICE: FS imagekit: /rclone-test-ziwowoh1dabe: --vfs-cache-mode writes or full is recommended for this remote as it can't stream === RUN TestDirReadDirAll/Virtual 2025/04/22 04:34:18 DEBUG : dir: Added virtual directory entry vAddFile: "virtualFile" 2025/04/22 04:34:18 DEBUG : dir: Added virtual directory entry vAddDir: "virtualDir" 2025/04/22 04:34:18 DEBUG : dir: Added virtual directory entry vDel: "file2" 2025/04/22 04:34:18 DEBUG : dir: Added virtual directory entry vDel: "subdir" 2025/04/22 04:34:21 DEBUG : dir: invalidating directory cache 2025/04/22 04:34:21 DEBUG : dir: Removed virtual directory entry vDel: "subdir" 2025/04/22 04:34:21 DEBUG : dir: Removed virtual directory entry vAddDir: "virtualDir" 2025/04/22 04:34:21 DEBUG : dir: Removed virtual directory entry vDel: "file2" 2025/04/22 04:34:21 DEBUG : dir/file1: Reset virtual modtime 2025/04/22 04:34:21 DEBUG : dir: Removed virtual directory entry vAddFile: "virtualFile" 2025/04/22 04:34:21 DEBUG : dir/virtualFile: Reset virtual modtime 2025/04/22 04:34:21 DEBUG : dir: Added virtual directory entry vAddFile: "virtualFile2" 2025/04/22 04:34:21 DEBUG : dir: Added virtual directory entry vAddDir: "virtualDir2" 2025/04/22 04:34:21 DEBUG : dir: Added virtual directory entry vDel: "file1" 2025/04/22 04:34:21 DEBUG : dir: invalidating directory cache 2025/04/22 04:34:22 DEBUG : dir: Removed virtual directory entry vAddDir: "virtualDir2" 2025/04/22 04:34:22 DEBUG : dir: Removed virtual directory entry vDel: "file1" 2025/04/22 04:34:22 DEBUG : dir/virtualFile: Reset virtual modtime 2025/04/22 04:34:22 DEBUG : : forgetting directory cache 2025/04/22 04:34:22 DEBUG : dir: forgetting directory cache 2025/04/22 04:34:22 DEBUG : dir/virtualDir: forgetting directory cache 2025/04/22 04:34:22 DEBUG : WaitForWriters: timeout=30s 2025/04/22 04:34:22 DEBUG : dir/virtualDir: Looking for writers 2025/04/22 04:34:22 DEBUG : dir: Looking for writers 2025/04/22 04:34:22 DEBUG : file1: reading active writers 2025/04/22 04:34:22 DEBUG : virtualFile2: reading active writers 2025/04/22 04:34:22 DEBUG : virtualFile: reading active writers 2025/04/22 04:34:22 DEBUG : virtualDir: reading active writers 2025/04/22 04:34:22 DEBUG : : Looking for writers 2025/04/22 04:34:22 DEBUG : dir: reading active writers 2025/04/22 04:34:22 DEBUG : >WaitForWriters: --- PASS: TestDirReadDirAll (12.69s) --- PASS: TestDirReadDirAll/Virtual (3.81s) === RUN TestDirMetadataExtension run.go:180: Remote "FS imagekit: /rclone-test-ziwowoh1dabe", Local "Local file system at /tmp/rclone1531028639", Modify Window "876000h0m0s" 2025/04/22 04:34:24 INFO : FS imagekit: /rclone-test-ziwowoh1dabe: poll-interval is not supported by this remote 2025/04/22 04:34:24 NOTICE: FS imagekit: /rclone-test-ziwowoh1dabe: --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/04/22 04:34:27 DEBUG : dir: Added virtual directory entry vAddFile: "file1.metadata" 2025/04/22 04:34:27 DEBUG : dir/file1.metadata: Set virtual modtime to 2025-04-22 04:34:25.658 +0000 UTC 2025/04/22 04:34:27 DEBUG : dir/file1.metadata: OpenFile: flags=O_RDONLY, perm=---------- 2025/04/22 04:34:27 DEBUG : dir/file1.metadata: Open: flags=O_RDONLY 2025/04/22 04:34:27 DEBUG : dir/file1.metadata: >Open: fd=dir/file1.metadata (r), err= 2025/04/22 04:34:27 DEBUG : dir/file1.metadata: >OpenFile: fd=dir/file1.metadata (r), err= 2025/04/22 04:34:27 DEBUG : dir/file1.metadata: ChunkedReader.openRange at 0 length 134217728 2025/04/22 04:34:27 DEBUG : dir/file1.metadata: ChunkedReader.Read at 0 length 512 chunkOffset 0 chunkSize 134217728 dir_test.go:741: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:741 Error: Not equal: expected: "2025-04-22T04:34:25.658Z" actual : "" Diff: --- Expected +++ Actual @@ -1 +1 @@ -2025-04-22T04:34:25.658Z + Test: TestDirMetadataExtension 2025/04/22 04:34:27 DEBUG : : Added virtual directory entry vAddFile: "dir.metadata" 2025/04/22 04:34:27 DEBUG : dir.metadata: Set virtual modtime to 2025-04-22 04:34:25.437 +0000 UTC 2025/04/22 04:34:27 DEBUG : dir.metadata: OpenFile: flags=O_RDONLY, perm=---------- 2025/04/22 04:34:27 DEBUG : dir.metadata: Open: flags=O_RDONLY 2025/04/22 04:34:27 DEBUG : dir.metadata: >Open: fd=dir.metadata (r), err= 2025/04/22 04:34:27 DEBUG : dir.metadata: >OpenFile: fd=dir.metadata (r), err= 2025/04/22 04:34:27 DEBUG : dir.metadata: ChunkedReader.openRange at 0 length 134217728 2025/04/22 04:34:27 DEBUG : dir.metadata: ChunkedReader.Read at 0 length 512 chunkOffset 0 chunkSize 134217728 2025/04/22 04:34:27 DEBUG : WaitForWriters: timeout=30s 2025/04/22 04:34:27 DEBUG : dir: Looking for writers 2025/04/22 04:34:27 DEBUG : file1: reading active writers 2025/04/22 04:34:27 DEBUG : file1.metadata: reading active writers 2025/04/22 04:34:27 DEBUG : : Looking for writers 2025/04/22 04:34:27 DEBUG : dir: reading active writers 2025/04/22 04:34:27 DEBUG : dir.metadata: reading active writers 2025/04/22 04:34:27 DEBUG : >WaitForWriters: --- FAIL: TestDirMetadataExtension (4.21s) FAIL 2025/04/22 04:34:29 DEBUG : FS imagekit: /rclone-test-ziwowoh1dabe: Purge remote "./vfs.test -test.v -test.timeout 1h0m0s -remote TestImageKit: -verbose -test.run '^(TestDirMetadataExtension|TestDirReadDirAll)$'" - Finished ERROR in 17.524671694s (try 2/5): exit status 1: Failed [TestDirMetadataExtension]