"./vfs.test -test.v -test.timeout 1h0m0s -remote TestPikPak: -verbose -test.run '^(TestCaseSensitivity|TestDirCreate|TestDirFileOpen|TestDirForgetAll|TestDirForgetPath|TestDirHandleMethods|TestDirHandleReaddir|TestDirHandleReaddirnames|TestDirMetadataExtension|TestDirMethods|TestDirMkdir|TestDirMkdirSub|TestDirOpen|TestDirReadDirAll|TestDirRemove|TestDirRemoveAll|TestDirRemoveName|TestDirRename|TestDirSetModTime|TestDirStat|TestDirWalk|TestFileMethods|TestFileOpen|TestFileOpenRead|TestFileOpenWrite|TestFileReadAtNonZeroLength|TestFileReadAtZeroLength|TestFileRemove|TestFileRemoveAll|TestRWFileHandleFlushRead|TestRWFileHandleMethodsRead|TestRWFileHandleMethodsWrite|TestRWFileHandleReadAt|TestRWFileHandleReleaseRead|TestRWFileHandleSeek|TestRWFileHandleSizeCreateExisting|TestRWFileHandleSizeTruncateExisting|TestRWFileHandleWriteAt|TestRWFileHandleWriteNoWrite|TestRWFileModTimeWithOpenWriters|TestReadFileHandleFlush|TestReadFileHandleMethods|TestReadFileHandleReadAt|TestReadFileHandleRelease|TestReadFileHandleSeek|TestUnicodeNormalization|TestVFSMkdir|TestVFSMkdirAll|TestVFSOpenFile|TestVFSRename|TestVFSStat|TestVFSStatParent|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleRelease|TestWriteFileHandleWriteAt|TestWriteFileModTimeWithOpenWriters)$|^TestFileRename$/^(full,forceCache=false|minimal,forceCache=false|minimal,forceCache=true|off,forceCache=false|writes,forceCache=false|writes,forceCache=true)$|^TestFileSetModTime$/^(cache=full,open=false,write=false|cache=full,open=true,write=false|cache=full,open=true,write=true|cache=off,open=false,write=false|cache=off,open=true,write=false|cache=off,open=true,write=true)$'" - Starting (try 4/5) 2025/07/04 03:42:13 DEBUG : Creating backend with remote "TestPikPak:rclone-test-gehowin3kahe" 2025/07/04 03:42:13 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/07/04 03:42:14 DEBUG : Creating backend with remote "/tmp/rclone2072917238" === RUN TestDirHandleMethods run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:14 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:14 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:15 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:15 DEBUG : Looking for writers 2025/07/04 03:42:15 DEBUG : >WaitForWriters: 2025/07/04 03:42:15 ERROR : error listing: directory not found --- FAIL: TestDirHandleMethods (0.96s) === RUN TestDirHandleReaddir run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:15 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:15 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:16 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:16 DEBUG : Looking for writers 2025/07/04 03:42:16 DEBUG : >WaitForWriters: 2025/07/04 03:42:16 ERROR : error listing: directory not found --- FAIL: TestDirHandleReaddir (0.95s) === RUN TestDirHandleReaddirnames run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:16 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:16 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:17 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:17 DEBUG : Looking for writers 2025/07/04 03:42:17 DEBUG : >WaitForWriters: 2025/07/04 03:42:17 ERROR : error listing: directory not found --- FAIL: TestDirHandleReaddirnames (0.98s) === RUN TestDirMethods run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:17 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:17 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:18 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:18 DEBUG : Looking for writers 2025/07/04 03:42:18 DEBUG : >WaitForWriters: 2025/07/04 03:42:18 ERROR : error listing: directory not found --- FAIL: TestDirMethods (0.97s) === RUN TestDirForgetAll run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:18 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:18 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:19 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:19 DEBUG : Looking for writers 2025/07/04 03:42:19 DEBUG : >WaitForWriters: 2025/07/04 03:42:19 ERROR : error listing: directory not found --- FAIL: TestDirForgetAll (0.95s) === RUN TestDirForgetPath run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:19 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:19 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:20 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:20 DEBUG : Looking for writers 2025/07/04 03:42:20 DEBUG : >WaitForWriters: 2025/07/04 03:42:20 ERROR : error listing: directory not found --- FAIL: TestDirForgetPath (0.95s) === RUN TestDirWalk run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:20 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:20 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:21 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:21 DEBUG : Looking for writers 2025/07/04 03:42:21 DEBUG : >WaitForWriters: 2025/07/04 03:42:21 ERROR : error listing: directory not found --- FAIL: TestDirWalk (0.98s) === RUN TestDirSetModTime run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:21 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:21 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:22 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:22 DEBUG : Looking for writers 2025/07/04 03:42:22 DEBUG : >WaitForWriters: 2025/07/04 03:42:22 ERROR : error listing: directory not found --- FAIL: TestDirSetModTime (0.94s) === RUN TestDirStat run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:22 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:22 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:23 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:23 DEBUG : Looking for writers 2025/07/04 03:42:23 DEBUG : >WaitForWriters: 2025/07/04 03:42:23 ERROR : error listing: directory not found --- FAIL: TestDirStat (0.99s) === RUN TestDirReadDirAll run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:23 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:23 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:24 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:24 DEBUG : Looking for writers 2025/07/04 03:42:24 DEBUG : >WaitForWriters: 2025/07/04 03:42:24 ERROR : error listing: directory not found --- FAIL: TestDirReadDirAll (1.00s) === RUN TestDirOpen run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:24 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:24 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:25 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:25 DEBUG : Looking for writers 2025/07/04 03:42:25 DEBUG : >WaitForWriters: 2025/07/04 03:42:25 ERROR : error listing: directory not found --- FAIL: TestDirOpen (0.96s) === RUN TestDirCreate run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:25 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:25 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:26 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:26 DEBUG : Looking for writers 2025/07/04 03:42:26 DEBUG : >WaitForWriters: 2025/07/04 03:42:26 ERROR : error listing: directory not found --- FAIL: TestDirCreate (0.97s) === RUN TestDirMkdir run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:26 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:26 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:27 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:27 DEBUG : Looking for writers 2025/07/04 03:42:27 DEBUG : >WaitForWriters: 2025/07/04 03:42:27 ERROR : error listing: directory not found --- FAIL: TestDirMkdir (0.94s) === RUN TestDirMkdirSub run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:27 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:27 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:28 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:28 DEBUG : Looking for writers 2025/07/04 03:42:28 DEBUG : >WaitForWriters: 2025/07/04 03:42:28 ERROR : error listing: directory not found --- FAIL: TestDirMkdirSub (0.97s) === RUN TestDirRemove run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:28 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:28 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:29 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:29 DEBUG : Looking for writers 2025/07/04 03:42:29 DEBUG : >WaitForWriters: 2025/07/04 03:42:29 ERROR : error listing: directory not found --- FAIL: TestDirRemove (0.95s) === RUN TestDirRemoveAll run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:29 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:29 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:30 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:30 DEBUG : Looking for writers 2025/07/04 03:42:30 DEBUG : >WaitForWriters: 2025/07/04 03:42:30 ERROR : error listing: directory not found --- FAIL: TestDirRemoveAll (0.95s) === RUN TestDirRemoveName run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:30 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:30 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:31 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:31 DEBUG : Looking for writers 2025/07/04 03:42:31 DEBUG : >WaitForWriters: 2025/07/04 03:42:31 ERROR : error listing: directory not found --- FAIL: TestDirRemoveName (0.95s) === RUN TestDirRename run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:31 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:31 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:31 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:31 DEBUG : Looking for writers 2025/07/04 03:42:31 DEBUG : >WaitForWriters: 2025/07/04 03:42:32 ERROR : error listing: directory not found --- FAIL: TestDirRename (0.95s) === RUN TestDirFileOpen run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:32 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:32 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:32 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:32 DEBUG : Looking for writers 2025/07/04 03:42:32 DEBUG : >WaitForWriters: 2025/07/04 03:42:33 ERROR : error listing: directory not found --- FAIL: TestDirFileOpen (0.94s) === RUN TestDirMetadataExtension run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:33 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:33 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:33 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:33 DEBUG : Looking for writers 2025/07/04 03:42:33 DEBUG : >WaitForWriters: 2025/07/04 03:42:34 ERROR : error listing: directory not found --- FAIL: TestDirMetadataExtension (0.95s) === RUN TestFileMethods run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:34 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:34 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:34 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:34 DEBUG : Looking for writers 2025/07/04 03:42:34 DEBUG : >WaitForWriters: 2025/07/04 03:42:35 ERROR : error listing: directory not found --- FAIL: TestFileMethods (0.96s) === RUN TestFileSetModTime === RUN TestFileSetModTime/cache=off,open=false,write=false run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:35 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:35 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:35 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:35 DEBUG : Looking for writers 2025/07/04 03:42:35 DEBUG : >WaitForWriters: 2025/07/04 03:42:36 ERROR : error listing: directory not found === RUN TestFileSetModTime/cache=off,open=true,write=false run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:36 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:36 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:36 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:36 DEBUG : Looking for writers 2025/07/04 03:42:36 DEBUG : >WaitForWriters: 2025/07/04 03:42:37 ERROR : error listing: directory not found === RUN TestFileSetModTime/cache=off,open=true,write=true run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:37 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:37 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:37 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:37 DEBUG : Looking for writers 2025/07/04 03:42:37 DEBUG : >WaitForWriters: 2025/07/04 03:42:37 ERROR : error listing: directory not found === RUN TestFileSetModTime/cache=full,open=false,write=false run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:38 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:38 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:42:38 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:38 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:38 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:38 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:38 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:38 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:38 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:38 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:38 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:38 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:38 DEBUG : Looking for writers 2025/07/04 03:42:38 DEBUG : >WaitForWriters: 2025/07/04 03:42:38 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:42:38 ERROR : error listing: directory not found === RUN TestFileSetModTime/cache=full,open=true,write=false run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:38 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:38 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:42:38 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:38 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:38 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:38 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:38 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:38 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:38 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:38 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:38 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:39 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:39 DEBUG : Looking for writers 2025/07/04 03:42:39 DEBUG : >WaitForWriters: 2025/07/04 03:42:39 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:42:39 ERROR : error listing: directory not found === RUN TestFileSetModTime/cache=full,open=true,write=true run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:39 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:39 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:42:39 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:39 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:39 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:39 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:39 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:39 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:39 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:39 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:39 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:40 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:40 DEBUG : Looking for writers 2025/07/04 03:42:40 DEBUG : >WaitForWriters: 2025/07/04 03:42:40 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:42:40 ERROR : error listing: directory not found --- FAIL: TestFileSetModTime (5.78s) --- FAIL: TestFileSetModTime/cache=off,open=false,write=false (0.96s) --- FAIL: TestFileSetModTime/cache=off,open=true,write=false (0.97s) --- FAIL: TestFileSetModTime/cache=off,open=true,write=true (0.96s) --- FAIL: TestFileSetModTime/cache=full,open=false,write=false (0.96s) --- FAIL: TestFileSetModTime/cache=full,open=true,write=false (0.96s) --- FAIL: TestFileSetModTime/cache=full,open=true,write=true (0.97s) === RUN TestFileOpenRead run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:40 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:40 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:41 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:41 DEBUG : Looking for writers 2025/07/04 03:42:41 DEBUG : >WaitForWriters: 2025/07/04 03:42:41 ERROR : error listing: directory not found --- FAIL: TestFileOpenRead (0.95s) === RUN TestFileOpenWrite run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:41 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:41 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:42 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:42 DEBUG : Looking for writers 2025/07/04 03:42:42 DEBUG : >WaitForWriters: 2025/07/04 03:42:42 ERROR : error listing: directory not found --- FAIL: TestFileOpenWrite (1.09s) === RUN TestFileRemove run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:42 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:42 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:43 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:43 DEBUG : Looking for writers 2025/07/04 03:42:43 DEBUG : >WaitForWriters: 2025/07/04 03:42:43 ERROR : error listing: directory not found --- FAIL: TestFileRemove (0.96s) === RUN TestFileRemoveAll run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:43 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:43 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:44 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:44 DEBUG : Looking for writers 2025/07/04 03:42:44 DEBUG : >WaitForWriters: 2025/07/04 03:42:44 ERROR : error listing: directory not found --- FAIL: TestFileRemoveAll (0.99s) === RUN TestFileOpen run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:44 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:44 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:45 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:45 DEBUG : Looking for writers 2025/07/04 03:42:45 DEBUG : >WaitForWriters: 2025/07/04 03:42:45 ERROR : error listing: directory not found --- FAIL: TestFileOpen (0.95s) === RUN TestFileRename === RUN TestFileRename/off,forceCache=false run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:45 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:45 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:46 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:46 DEBUG : Looking for writers 2025/07/04 03:42:46 DEBUG : >WaitForWriters: 2025/07/04 03:42:46 ERROR : error listing: directory not found === RUN TestFileRename/minimal,forceCache=false run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:46 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:46 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:42:46 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:42:46 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:46 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:46 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:46 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:46 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:46 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:46 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:46 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:46 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:47 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:47 DEBUG : Looking for writers 2025/07/04 03:42:47 DEBUG : >WaitForWriters: 2025/07/04 03:42:47 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:42:47 ERROR : error listing: directory not found === RUN TestFileRename/minimal,forceCache=true run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:47 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:47 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:42:47 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:42:47 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:47 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:47 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:47 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:47 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:47 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:47 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:47 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:47 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:48 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:48 DEBUG : Looking for writers 2025/07/04 03:42:48 DEBUG : >WaitForWriters: 2025/07/04 03:42:48 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:42:48 ERROR : error listing: directory not found === RUN TestFileRename/writes,forceCache=false run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:48 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:48 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:42:48 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:48 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:48 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:48 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:48 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:48 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:48 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:48 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:48 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:49 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:49 DEBUG : Looking for writers 2025/07/04 03:42:49 DEBUG : >WaitForWriters: 2025/07/04 03:42:49 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:42:49 ERROR : error listing: directory not found === RUN TestFileRename/writes,forceCache=true run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:49 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:49 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:42:49 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:49 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:49 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:49 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:49 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:49 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:49 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:49 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:49 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:50 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:50 DEBUG : Looking for writers 2025/07/04 03:42:50 DEBUG : >WaitForWriters: 2025/07/04 03:42:50 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:42:50 ERROR : error listing: directory not found === RUN TestFileRename/full,forceCache=false run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:50 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:50 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:42:50 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:50 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:50 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:50 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:50 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:50 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:50 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:50 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:50 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:51 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:51 DEBUG : Looking for writers 2025/07/04 03:42:51 DEBUG : >WaitForWriters: 2025/07/04 03:42:51 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:42:51 ERROR : error listing: directory not found --- FAIL: TestFileRename (5.79s) --- FAIL: TestFileRename/off,forceCache=false (0.95s) --- FAIL: TestFileRename/minimal,forceCache=false (0.96s) --- FAIL: TestFileRename/minimal,forceCache=true (0.99s) --- FAIL: TestFileRename/writes,forceCache=false (0.96s) --- FAIL: TestFileRename/writes,forceCache=true (0.98s) --- FAIL: TestFileRename/full,forceCache=false (0.96s) === RUN TestReadFileHandleMethods run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:51 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:51 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:52 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:52 DEBUG : Looking for writers 2025/07/04 03:42:52 DEBUG : >WaitForWriters: 2025/07/04 03:42:52 ERROR : error listing: directory not found --- FAIL: TestReadFileHandleMethods (0.97s) === RUN TestReadFileHandleSeek run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:52 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:52 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:53 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:53 DEBUG : Looking for writers 2025/07/04 03:42:53 DEBUG : >WaitForWriters: 2025/07/04 03:42:53 ERROR : error listing: directory not found --- FAIL: TestReadFileHandleSeek (0.95s) === RUN TestReadFileHandleReadAt run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:53 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:53 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:54 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:54 DEBUG : Looking for writers 2025/07/04 03:42:54 DEBUG : >WaitForWriters: 2025/07/04 03:42:54 ERROR : error listing: directory not found --- FAIL: TestReadFileHandleReadAt (0.98s) === RUN TestReadFileHandleFlush run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:54 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:54 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:55 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:55 DEBUG : Looking for writers 2025/07/04 03:42:55 DEBUG : >WaitForWriters: 2025/07/04 03:42:55 ERROR : error listing: directory not found --- FAIL: TestReadFileHandleFlush (0.99s) === RUN TestReadFileHandleRelease run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:55 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:55 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:56 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:56 DEBUG : Looking for writers 2025/07/04 03:42:56 DEBUG : >WaitForWriters: 2025/07/04 03:42:56 ERROR : error listing: directory not found --- FAIL: TestReadFileHandleRelease (0.99s) === RUN TestRWFileHandleMethodsRead run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:56 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:56 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:42:56 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:56 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:56 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:56 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:56 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:56 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:56 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:56 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:56 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:57 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:57 DEBUG : Looking for writers 2025/07/04 03:42:57 DEBUG : >WaitForWriters: 2025/07/04 03:42:57 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:42:57 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleMethodsRead (0.95s) === RUN TestRWFileHandleSeek run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:57 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:57 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:42:57 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:57 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:57 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:57 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:57 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:57 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:57 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:57 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:57 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:58 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:58 DEBUG : Looking for writers 2025/07/04 03:42:58 DEBUG : >WaitForWriters: 2025/07/04 03:42:58 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:42:58 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleSeek (0.98s) === RUN TestRWFileHandleReadAt run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:58 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:58 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:42:58 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:58 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:58 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:58 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:58 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:58 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:58 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:58 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:58 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:42:59 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:42:59 DEBUG : Looking for writers 2025/07/04 03:42:59 DEBUG : >WaitForWriters: 2025/07/04 03:42:59 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:42:59 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleReadAt (0.99s) === RUN TestRWFileHandleFlushRead run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:42:59 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:42:59 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:42:59 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:59 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:59 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:59 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:59 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:59 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:59 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:42:59 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:42:59 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:43:00 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:43:00 DEBUG : Looking for writers 2025/07/04 03:43:00 DEBUG : >WaitForWriters: 2025/07/04 03:43:00 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:43:00 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleFlushRead (0.96s) === RUN TestRWFileHandleReleaseRead run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:43:00 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:43:00 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:43:00 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:43:00 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:43:00 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:43:00 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:43:00 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:43:00 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:43:00 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:43:00 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:43:00 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:43:01 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:43:01 DEBUG : Looking for writers 2025/07/04 03:43:01 DEBUG : >WaitForWriters: 2025/07/04 03:43:01 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:43:01 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleReleaseRead (0.94s) === RUN TestRWFileHandleMethodsWrite run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:43:01 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:43:01 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:43:01 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:43:01 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:43:01 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:43:01 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:43:01 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:43:01 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:43:01 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:43:01 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:43:01 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:43:01 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2025/07/04 03:43:01 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:43:01 DEBUG : file1: newRWFileHandle: 2025/07/04 03:43:01 DEBUG : file1(0xc00057f000): openPending: 2025/07/04 03:43:01 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2025/07/04 03:43:01 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:43:01 DEBUG : file1(0xc00057f000): >openPending: err= 2025/07/04 03:43:01 DEBUG : file1: >newRWFileHandle: err= 2025/07/04 03:43:01 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:43:01 DEBUG : file1: >Open: fd=file1 (rw), err= 2025/07/04 03:43:01 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2025/07/04 03:43:01 DEBUG : file1(0xc00057f000): _writeAt: size=5, off=0 2025/07/04 03:43:01 DEBUG : file1(0xc00057f000): >_writeAt: n=5, err= 2025/07/04 03:43:01 DEBUG : file1(0xc00057f000): _writeAt: size=7, off=5 2025/07/04 03:43:01 DEBUG : file1(0xc00057f000): >_writeAt: n=7, err= 2025/07/04 03:43:01 DEBUG : file1: vfs cache: truncate to size=11 2025/07/04 03:43:01 DEBUG : file1(0xc00057f000): close: 2025/07/04 03:43:01 DEBUG : file1: vfs cache: setting modification time to 2025-07-04 03:43:01.621654386 +0000 UTC m=+48.257940460 2025/07/04 03:43:01 INFO : file1: vfs cache: queuing for upload in 100ms 2025/07/04 03:43:01 DEBUG : file1(0xc00057f000): >close: err= 2025/07/04 03:43:01 DEBUG : file1(0xc00057f000): close: 2025/07/04 03:43:01 DEBUG : file1(0xc00057f000): >close: err=file already closed 2025/07/04 03:43:01 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:43:01 DEBUG : Looking for writers 2025/07/04 03:43:01 DEBUG : file1: reading active writers 2025/07/04 03:43:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2025/07/04 03:43:01 DEBUG : Looking for writers 2025/07/04 03:43:01 DEBUG : file1: reading active writers 2025/07/04 03:43:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2025/07/04 03:43:01 DEBUG : Looking for writers 2025/07/04 03:43:01 DEBUG : file1: reading active writers 2025/07/04 03:43:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2025/07/04 03:43:01 DEBUG : Looking for writers 2025/07/04 03:43:01 DEBUG : file1: reading active writers 2025/07/04 03:43:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2025/07/04 03:43:01 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:43:01 DEBUG : Looking for writers 2025/07/04 03:43:01 DEBUG : file1: reading active writers 2025/07/04 03:43:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2025/07/04 03:43:01 DEBUG : Looking for writers 2025/07/04 03:43:01 DEBUG : file1: reading active writers 2025/07/04 03:43:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2025/07/04 03:43:02 DEBUG : Looking for writers 2025/07/04 03:43:02 DEBUG : file1: reading active writers 2025/07/04 03:43:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2025/07/04 03:43:02 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:43:02 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:43:02 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:43:02 DEBUG : Looking for writers 2025/07/04 03:43:02 DEBUG : file1: reading active writers 2025/07/04 03:43:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:03 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:43:03 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:43:03 DEBUG : Looking for writers 2025/07/04 03:43:03 DEBUG : file1: reading active writers 2025/07/04 03:43:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:04 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:43:04 DEBUG : Looking for writers 2025/07/04 03:43:04 DEBUG : file1: reading active writers 2025/07/04 03:43:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:05 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:43:05 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:43:05 DEBUG : Looking for writers 2025/07/04 03:43:05 DEBUG : file1: reading active writers 2025/07/04 03:43:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:06 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:43:06 DEBUG : Looking for writers 2025/07/04 03:43:06 DEBUG : file1: reading active writers 2025/07/04 03:43:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:07 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:43:07 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:43:07 DEBUG : Looking for writers 2025/07/04 03:43:07 DEBUG : file1: reading active writers 2025/07/04 03:43:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:08 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:43:08 DEBUG : Looking for writers 2025/07/04 03:43:08 DEBUG : file1: reading active writers 2025/07/04 03:43:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:09 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:43:09 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:43:09 DEBUG : Looking for writers 2025/07/04 03:43:09 DEBUG : file1: reading active writers 2025/07/04 03:43:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:10 DEBUG : Looking for writers 2025/07/04 03:43:10 DEBUG : file1: reading active writers 2025/07/04 03:43:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:11 DEBUG : Looking for writers 2025/07/04 03:43:11 DEBUG : file1: reading active writers 2025/07/04 03:43:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:12 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:43:12 DEBUG : Looking for writers 2025/07/04 03:43:12 DEBUG : file1: reading active writers 2025/07/04 03:43:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:13 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:43:13 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:43:13 DEBUG : Looking for writers 2025/07/04 03:43:13 DEBUG : file1: reading active writers 2025/07/04 03:43:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:14 DEBUG : Looking for writers 2025/07/04 03:43:14 DEBUG : file1: reading active writers 2025/07/04 03:43:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:15 DEBUG : Looking for writers 2025/07/04 03:43:15 DEBUG : file1: reading active writers 2025/07/04 03:43:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:16 DEBUG : Looking for writers 2025/07/04 03:43:16 DEBUG : file1: reading active writers 2025/07/04 03:43:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:17 DEBUG : Looking for writers 2025/07/04 03:43:17 DEBUG : file1: reading active writers 2025/07/04 03:43:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:18 DEBUG : Looking for writers 2025/07/04 03:43:18 DEBUG : file1: reading active writers 2025/07/04 03:43:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:19 DEBUG : Looking for writers 2025/07/04 03:43:19 DEBUG : file1: reading active writers 2025/07/04 03:43:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:20 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:43:20 DEBUG : Looking for writers 2025/07/04 03:43:20 DEBUG : file1: reading active writers 2025/07/04 03:43:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:21 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:43:21 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:43:21 DEBUG : Looking for writers 2025/07/04 03:43:21 DEBUG : file1: reading active writers 2025/07/04 03:43:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:22 DEBUG : Looking for writers 2025/07/04 03:43:22 DEBUG : file1: reading active writers 2025/07/04 03:43:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:23 DEBUG : Looking for writers 2025/07/04 03:43:23 DEBUG : file1: reading active writers 2025/07/04 03:43:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:24 DEBUG : Looking for writers 2025/07/04 03:43:24 DEBUG : file1: reading active writers 2025/07/04 03:43:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:25 DEBUG : Looking for writers 2025/07/04 03:43:25 DEBUG : file1: reading active writers 2025/07/04 03:43:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:26 DEBUG : Looking for writers 2025/07/04 03:43:26 DEBUG : file1: reading active writers 2025/07/04 03:43:26 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:27 DEBUG : Looking for writers 2025/07/04 03:43:27 DEBUG : file1: reading active writers 2025/07/04 03:43:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:28 DEBUG : Looking for writers 2025/07/04 03:43:28 DEBUG : file1: reading active writers 2025/07/04 03:43:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:29 DEBUG : Looking for writers 2025/07/04 03:43:29 DEBUG : file1: reading active writers 2025/07/04 03:43:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:30 DEBUG : Looking for writers 2025/07/04 03:43:30 DEBUG : file1: reading active writers 2025/07/04 03:43:30 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:31 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc000935e00 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc000688008 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824640569408} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13984223649852141938 ext:48257940460 loc:0x3fe46e0} ATime:{wall:13984223649852164821 ext:48257963354 loc:0x3fe46e0} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2025/07/04 03:43:31 DEBUG : >WaitForWriters: 2025/07/04 03:43:31 ERROR : error listing: directory not found fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Flushing the directory cache 2025/07/04 03:43:33 ERROR : error listing: directory not found fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 2025/07/04 03:43:33 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:43:34 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:43:34 ERROR : file1: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. fstest.go:298: Flushing the directory cache 2025/07/04 03:43:35 ERROR : error listing: directory not found fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:298: Flushing the directory cache fstest.go:302: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write_test.go:337 Error: Should be true Test: TestRWFileHandleMethodsWrite Messages: listing wrong, want file1 (11) got fstest.go:200: Not found "file1" fstest.go:203: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:203 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:307 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write_test.go:337 Error: Not equal: expected: 0 actual : 1 Test: TestRWFileHandleMethodsWrite Messages: 1 objects not found 2025/07/04 03:43:39 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:43:39 DEBUG : Looking for writers 2025/07/04 03:43:39 DEBUG : file1: reading active writers 2025/07/04 03:43:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2025/07/04 03:43:39 DEBUG : Looking for writers 2025/07/04 03:43:39 DEBUG : file1: reading active writers 2025/07/04 03:43:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2025/07/04 03:43:39 DEBUG : Looking for writers 2025/07/04 03:43:39 DEBUG : file1: reading active writers 2025/07/04 03:43:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2025/07/04 03:43:39 DEBUG : Looking for writers 2025/07/04 03:43:39 DEBUG : file1: reading active writers 2025/07/04 03:43:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2025/07/04 03:43:39 DEBUG : Looking for writers 2025/07/04 03:43:39 DEBUG : file1: reading active writers 2025/07/04 03:43:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2025/07/04 03:43:39 DEBUG : Looking for writers 2025/07/04 03:43:39 DEBUG : file1: reading active writers 2025/07/04 03:43:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2025/07/04 03:43:40 DEBUG : Looking for writers 2025/07/04 03:43:40 DEBUG : file1: reading active writers 2025/07/04 03:43:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2025/07/04 03:43:40 DEBUG : Looking for writers 2025/07/04 03:43:40 DEBUG : file1: reading active writers 2025/07/04 03:43:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:41 DEBUG : Looking for writers 2025/07/04 03:43:41 DEBUG : file1: reading active writers 2025/07/04 03:43:41 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:42 DEBUG : Looking for writers 2025/07/04 03:43:42 DEBUG : file1: reading active writers 2025/07/04 03:43:42 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:43 DEBUG : Looking for writers 2025/07/04 03:43:43 DEBUG : file1: reading active writers 2025/07/04 03:43:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:44 DEBUG : Looking for writers 2025/07/04 03:43:44 DEBUG : file1: reading active writers 2025/07/04 03:43:44 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:45 DEBUG : Looking for writers 2025/07/04 03:43:45 DEBUG : file1: reading active writers 2025/07/04 03:43:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:46 DEBUG : Looking for writers 2025/07/04 03:43:46 DEBUG : file1: reading active writers 2025/07/04 03:43:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:47 DEBUG : Looking for writers 2025/07/04 03:43:47 DEBUG : file1: reading active writers 2025/07/04 03:43:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:48 DEBUG : Looking for writers 2025/07/04 03:43:48 DEBUG : file1: reading active writers 2025/07/04 03:43:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:49 DEBUG : Looking for writers 2025/07/04 03:43:49 DEBUG : file1: reading active writers 2025/07/04 03:43:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:50 DEBUG : Looking for writers 2025/07/04 03:43:50 DEBUG : file1: reading active writers 2025/07/04 03:43:50 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:51 DEBUG : Looking for writers 2025/07/04 03:43:51 DEBUG : file1: reading active writers 2025/07/04 03:43:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:52 DEBUG : Looking for writers 2025/07/04 03:43:52 DEBUG : file1: reading active writers 2025/07/04 03:43:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:53 DEBUG : Looking for writers 2025/07/04 03:43:53 DEBUG : file1: reading active writers 2025/07/04 03:43:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:54 DEBUG : Looking for writers 2025/07/04 03:43:54 DEBUG : file1: reading active writers 2025/07/04 03:43:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:55 DEBUG : Looking for writers 2025/07/04 03:43:55 DEBUG : file1: reading active writers 2025/07/04 03:43:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:56 DEBUG : Looking for writers 2025/07/04 03:43:56 DEBUG : file1: reading active writers 2025/07/04 03:43:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:57 DEBUG : Looking for writers 2025/07/04 03:43:57 DEBUG : file1: reading active writers 2025/07/04 03:43:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:58 DEBUG : Looking for writers 2025/07/04 03:43:58 DEBUG : file1: reading active writers 2025/07/04 03:43:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:43:59 DEBUG : Looking for writers 2025/07/04 03:43:59 DEBUG : file1: reading active writers 2025/07/04 03:43:59 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:00 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:44:00 DEBUG : Looking for writers 2025/07/04 03:44:00 DEBUG : file1: reading active writers 2025/07/04 03:44:00 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:01 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2025/07/04 03:44:01 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 0, uploading 1, total size 11 (was 11) 2025/07/04 03:44:01 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:44:01 ERROR : file1: vfs cache: failed to upload try #9, will retry in 51.2s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:44:01 DEBUG : Looking for writers 2025/07/04 03:44:01 DEBUG : file1: reading active writers 2025/07/04 03:44:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:02 DEBUG : Looking for writers 2025/07/04 03:44:02 DEBUG : file1: reading active writers 2025/07/04 03:44:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:03 DEBUG : Looking for writers 2025/07/04 03:44:03 DEBUG : file1: reading active writers 2025/07/04 03:44:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:04 DEBUG : Looking for writers 2025/07/04 03:44:04 DEBUG : file1: reading active writers 2025/07/04 03:44:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:05 DEBUG : Looking for writers 2025/07/04 03:44:05 DEBUG : file1: reading active writers 2025/07/04 03:44:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:06 DEBUG : Looking for writers 2025/07/04 03:44:06 DEBUG : file1: reading active writers 2025/07/04 03:44:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:07 DEBUG : Looking for writers 2025/07/04 03:44:07 DEBUG : file1: reading active writers 2025/07/04 03:44:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:08 DEBUG : Looking for writers 2025/07/04 03:44:08 DEBUG : file1: reading active writers 2025/07/04 03:44:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:09 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc000935e00 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc000688008 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824640569408} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13984223649852141938 ext:48257940460 loc:0x3fe46e0} ATime:{wall:13984223649852164821 ext:48257963354 loc:0x3fe46e0} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2025/07/04 03:44:09 DEBUG : >WaitForWriters: 2025/07/04 03:44:09 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:44:09 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleMethodsWrite (68.58s) === RUN TestRWFileHandleWriteAt run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:44:09 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:44:09 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:44:09 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:44:09 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:44:09 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:44:09 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:44:09 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:44:09 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:44:09 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:44:09 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:44:09 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:44:09 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2025/07/04 03:44:10 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:44:10 DEBUG : file1: newRWFileHandle: 2025/07/04 03:44:10 DEBUG : file1(0xc0007793c0): openPending: 2025/07/04 03:44:10 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2025/07/04 03:44:10 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:44:10 DEBUG : file1(0xc0007793c0): >openPending: err= 2025/07/04 03:44:10 DEBUG : file1: >newRWFileHandle: err= 2025/07/04 03:44:10 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:44:10 DEBUG : file1: >Open: fd=file1 (rw), err= 2025/07/04 03:44:10 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2025/07/04 03:44:10 DEBUG : file1(0xc0007793c0): _writeAt: size=7, off=0 2025/07/04 03:44:10 DEBUG : file1(0xc0007793c0): >_writeAt: n=7, err= 2025/07/04 03:44:10 DEBUG : file1(0xc0007793c0): _writeAt: size=6, off=5 2025/07/04 03:44:10 DEBUG : file1(0xc0007793c0): >_writeAt: n=6, err= 2025/07/04 03:44:10 DEBUG : file1(0xc0007793c0): close: 2025/07/04 03:44:10 DEBUG : file1: vfs cache: setting modification time to 2025-07-04 03:44:10.201405559 +0000 UTC m=+116.837691643 2025/07/04 03:44:10 INFO : file1: vfs cache: queuing for upload in 100ms 2025/07/04 03:44:10 DEBUG : file1(0xc0007793c0): >close: err= 2025/07/04 03:44:10 DEBUG : file1(0xc0007793c0): _writeAt: size=5, off=0 2025/07/04 03:44:10 DEBUG : file1(0xc0007793c0): >_writeAt: n=0, err=file already closed 2025/07/04 03:44:10 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:44:10 DEBUG : Looking for writers 2025/07/04 03:44:10 DEBUG : file1: reading active writers 2025/07/04 03:44:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2025/07/04 03:44:10 DEBUG : Looking for writers 2025/07/04 03:44:10 DEBUG : file1: reading active writers 2025/07/04 03:44:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2025/07/04 03:44:10 DEBUG : Looking for writers 2025/07/04 03:44:10 DEBUG : file1: reading active writers 2025/07/04 03:44:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2025/07/04 03:44:10 DEBUG : Looking for writers 2025/07/04 03:44:10 DEBUG : file1: reading active writers 2025/07/04 03:44:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2025/07/04 03:44:10 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:44:10 DEBUG : Looking for writers 2025/07/04 03:44:10 DEBUG : file1: reading active writers 2025/07/04 03:44:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2025/07/04 03:44:10 DEBUG : Looking for writers 2025/07/04 03:44:10 DEBUG : file1: reading active writers 2025/07/04 03:44:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2025/07/04 03:44:10 DEBUG : Looking for writers 2025/07/04 03:44:10 DEBUG : file1: reading active writers 2025/07/04 03:44:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2025/07/04 03:44:11 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:44:11 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:44:11 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:44:11 DEBUG : Looking for writers 2025/07/04 03:44:11 DEBUG : file1: reading active writers 2025/07/04 03:44:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:12 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:44:12 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:44:12 DEBUG : Looking for writers 2025/07/04 03:44:12 DEBUG : file1: reading active writers 2025/07/04 03:44:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:12 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:44:13 DEBUG : Looking for writers 2025/07/04 03:44:13 DEBUG : file1: reading active writers 2025/07/04 03:44:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:13 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:44:13 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:44:14 DEBUG : Looking for writers 2025/07/04 03:44:14 DEBUG : file1: reading active writers 2025/07/04 03:44:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:14 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:44:15 DEBUG : Looking for writers 2025/07/04 03:44:15 DEBUG : file1: reading active writers 2025/07/04 03:44:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:15 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:44:15 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:44:16 DEBUG : Looking for writers 2025/07/04 03:44:16 DEBUG : file1: reading active writers 2025/07/04 03:44:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:17 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:44:17 DEBUG : Looking for writers 2025/07/04 03:44:17 DEBUG : file1: reading active writers 2025/07/04 03:44:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:18 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:44:18 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:44:18 DEBUG : Looking for writers 2025/07/04 03:44:18 DEBUG : file1: reading active writers 2025/07/04 03:44:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:19 DEBUG : Looking for writers 2025/07/04 03:44:19 DEBUG : file1: reading active writers 2025/07/04 03:44:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:20 DEBUG : Looking for writers 2025/07/04 03:44:20 DEBUG : file1: reading active writers 2025/07/04 03:44:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:21 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:44:21 DEBUG : Looking for writers 2025/07/04 03:44:21 DEBUG : file1: reading active writers 2025/07/04 03:44:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:22 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:44:22 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:44:22 DEBUG : Looking for writers 2025/07/04 03:44:22 DEBUG : file1: reading active writers 2025/07/04 03:44:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:23 DEBUG : Looking for writers 2025/07/04 03:44:23 DEBUG : file1: reading active writers 2025/07/04 03:44:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:24 DEBUG : Looking for writers 2025/07/04 03:44:24 DEBUG : file1: reading active writers 2025/07/04 03:44:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:25 DEBUG : Looking for writers 2025/07/04 03:44:25 DEBUG : file1: reading active writers 2025/07/04 03:44:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:26 DEBUG : Looking for writers 2025/07/04 03:44:26 DEBUG : file1: reading active writers 2025/07/04 03:44:26 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:27 DEBUG : Looking for writers 2025/07/04 03:44:27 DEBUG : file1: reading active writers 2025/07/04 03:44:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:28 DEBUG : Looking for writers 2025/07/04 03:44:28 DEBUG : file1: reading active writers 2025/07/04 03:44:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:28 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:44:29 DEBUG : Looking for writers 2025/07/04 03:44:29 DEBUG : file1: reading active writers 2025/07/04 03:44:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:29 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:44:29 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:44:30 DEBUG : Looking for writers 2025/07/04 03:44:30 DEBUG : file1: reading active writers 2025/07/04 03:44:30 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:31 DEBUG : Looking for writers 2025/07/04 03:44:31 DEBUG : file1: reading active writers 2025/07/04 03:44:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:32 DEBUG : Looking for writers 2025/07/04 03:44:32 DEBUG : file1: reading active writers 2025/07/04 03:44:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:33 DEBUG : Looking for writers 2025/07/04 03:44:33 DEBUG : file1: reading active writers 2025/07/04 03:44:33 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:34 DEBUG : Looking for writers 2025/07/04 03:44:34 DEBUG : file1: reading active writers 2025/07/04 03:44:34 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:35 DEBUG : Looking for writers 2025/07/04 03:44:35 DEBUG : file1: reading active writers 2025/07/04 03:44:35 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:36 DEBUG : Looking for writers 2025/07/04 03:44:36 DEBUG : file1: reading active writers 2025/07/04 03:44:36 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:37 DEBUG : Looking for writers 2025/07/04 03:44:37 DEBUG : file1: reading active writers 2025/07/04 03:44:37 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:38 DEBUG : Looking for writers 2025/07/04 03:44:38 DEBUG : file1: reading active writers 2025/07/04 03:44:38 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:39 DEBUG : Looking for writers 2025/07/04 03:44:39 DEBUG : file1: reading active writers 2025/07/04 03:44:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:40 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc0008ae000 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc000780908 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824641587520} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13984223723520078967 ext:116837691643 loc:0x3fe46e0} ATime:{wall:13984223723520100798 ext:116837713474 loc:0x3fe46e0} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2025/07/04 03:44:40 DEBUG : >WaitForWriters: 2025/07/04 03:44:40 ERROR : error listing: directory not found fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Flushing the directory cache 2025/07/04 03:44:41 ERROR : error listing: directory not found fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 2025/07/04 03:44:42 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:44:43 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:44:43 ERROR : file1: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. fstest.go:298: Flushing the directory cache 2025/07/04 03:44:44 ERROR : error listing: directory not found fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:298: Flushing the directory cache fstest.go:302: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write_test.go:387 Error: Should be true Test: TestRWFileHandleWriteAt Messages: listing wrong, want file1 (11) got fstest.go:200: Not found "file1" fstest.go:203: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:203 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:307 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write_test.go:387 Error: Not equal: expected: 0 actual : 1 Test: TestRWFileHandleWriteAt Messages: 1 objects not found 2025/07/04 03:44:48 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:44:48 DEBUG : Looking for writers 2025/07/04 03:44:48 DEBUG : file1: reading active writers 2025/07/04 03:44:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2025/07/04 03:44:48 DEBUG : Looking for writers 2025/07/04 03:44:48 DEBUG : file1: reading active writers 2025/07/04 03:44:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2025/07/04 03:44:48 DEBUG : Looking for writers 2025/07/04 03:44:48 DEBUG : file1: reading active writers 2025/07/04 03:44:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2025/07/04 03:44:48 DEBUG : Looking for writers 2025/07/04 03:44:48 DEBUG : file1: reading active writers 2025/07/04 03:44:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2025/07/04 03:44:48 DEBUG : Looking for writers 2025/07/04 03:44:48 DEBUG : file1: reading active writers 2025/07/04 03:44:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2025/07/04 03:44:48 DEBUG : Looking for writers 2025/07/04 03:44:48 DEBUG : file1: reading active writers 2025/07/04 03:44:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2025/07/04 03:44:48 DEBUG : Looking for writers 2025/07/04 03:44:48 DEBUG : file1: reading active writers 2025/07/04 03:44:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2025/07/04 03:44:49 DEBUG : Looking for writers 2025/07/04 03:44:49 DEBUG : file1: reading active writers 2025/07/04 03:44:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:50 DEBUG : Looking for writers 2025/07/04 03:44:50 DEBUG : file1: reading active writers 2025/07/04 03:44:50 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:51 DEBUG : Looking for writers 2025/07/04 03:44:51 DEBUG : file1: reading active writers 2025/07/04 03:44:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:52 DEBUG : Looking for writers 2025/07/04 03:44:52 DEBUG : file1: reading active writers 2025/07/04 03:44:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:53 DEBUG : Looking for writers 2025/07/04 03:44:53 DEBUG : file1: reading active writers 2025/07/04 03:44:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:54 DEBUG : Looking for writers 2025/07/04 03:44:54 DEBUG : file1: reading active writers 2025/07/04 03:44:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:55 DEBUG : Looking for writers 2025/07/04 03:44:55 DEBUG : file1: reading active writers 2025/07/04 03:44:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:56 DEBUG : Looking for writers 2025/07/04 03:44:56 DEBUG : file1: reading active writers 2025/07/04 03:44:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:57 DEBUG : Looking for writers 2025/07/04 03:44:57 DEBUG : file1: reading active writers 2025/07/04 03:44:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:58 DEBUG : Looking for writers 2025/07/04 03:44:58 DEBUG : file1: reading active writers 2025/07/04 03:44:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:44:59 DEBUG : Looking for writers 2025/07/04 03:44:59 DEBUG : file1: reading active writers 2025/07/04 03:44:59 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:00 DEBUG : Looking for writers 2025/07/04 03:45:00 DEBUG : file1: reading active writers 2025/07/04 03:45:00 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:01 DEBUG : Looking for writers 2025/07/04 03:45:01 DEBUG : file1: reading active writers 2025/07/04 03:45:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:02 DEBUG : Looking for writers 2025/07/04 03:45:02 DEBUG : file1: reading active writers 2025/07/04 03:45:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:03 DEBUG : Looking for writers 2025/07/04 03:45:03 DEBUG : file1: reading active writers 2025/07/04 03:45:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:04 DEBUG : Looking for writers 2025/07/04 03:45:04 DEBUG : file1: reading active writers 2025/07/04 03:45:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:05 DEBUG : Looking for writers 2025/07/04 03:45:05 DEBUG : file1: reading active writers 2025/07/04 03:45:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:06 DEBUG : Looking for writers 2025/07/04 03:45:06 DEBUG : file1: reading active writers 2025/07/04 03:45:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:07 DEBUG : Looking for writers 2025/07/04 03:45:07 DEBUG : file1: reading active writers 2025/07/04 03:45:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:08 DEBUG : Looking for writers 2025/07/04 03:45:08 DEBUG : file1: reading active writers 2025/07/04 03:45:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:09 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:45:09 DEBUG : Looking for writers 2025/07/04 03:45:09 DEBUG : file1: reading active writers 2025/07/04 03:45:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:09 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2025/07/04 03:45:09 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 0, uploading 1, total size 11 (was 11) 2025/07/04 03:45:10 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:10 ERROR : file1: vfs cache: failed to upload try #9, will retry in 51.2s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:10 DEBUG : Looking for writers 2025/07/04 03:45:10 DEBUG : file1: reading active writers 2025/07/04 03:45:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:11 DEBUG : Looking for writers 2025/07/04 03:45:11 DEBUG : file1: reading active writers 2025/07/04 03:45:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:12 DEBUG : Looking for writers 2025/07/04 03:45:12 DEBUG : file1: reading active writers 2025/07/04 03:45:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:13 DEBUG : Looking for writers 2025/07/04 03:45:13 DEBUG : file1: reading active writers 2025/07/04 03:45:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:14 DEBUG : Looking for writers 2025/07/04 03:45:14 DEBUG : file1: reading active writers 2025/07/04 03:45:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:15 DEBUG : Looking for writers 2025/07/04 03:45:15 DEBUG : file1: reading active writers 2025/07/04 03:45:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:16 DEBUG : Looking for writers 2025/07/04 03:45:16 DEBUG : file1: reading active writers 2025/07/04 03:45:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:17 DEBUG : Looking for writers 2025/07/04 03:45:17 DEBUG : file1: reading active writers 2025/07/04 03:45:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:45:18 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc0008ae000 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc000780908 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824641587520} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13984223723520078967 ext:116837691643 loc:0x3fe46e0} ATime:{wall:13984223723520100798 ext:116837713474 loc:0x3fe46e0} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2025/07/04 03:45:18 DEBUG : >WaitForWriters: 2025/07/04 03:45:18 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:45:18 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleWriteAt (68.61s) === RUN TestRWFileHandleWriteNoWrite run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:45:18 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:45:18 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:45:18 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:45:18 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:45:18 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:45:18 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:45:18 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:45:18 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:45:18 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:45:18 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:45:18 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:45:18 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2025/07/04 03:45:18 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:45:18 DEBUG : file1: newRWFileHandle: 2025/07/04 03:45:18 DEBUG : file1(0xc0008ee540): openPending: 2025/07/04 03:45:18 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2025/07/04 03:45:18 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:45:18 DEBUG : file1(0xc0008ee540): >openPending: err= 2025/07/04 03:45:18 DEBUG : file1: >newRWFileHandle: err= 2025/07/04 03:45:18 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:45:18 DEBUG : file1: >Open: fd=file1 (rw), err= 2025/07/04 03:45:18 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2025/07/04 03:45:18 DEBUG : file1(0xc0008ee540): close: 2025/07/04 03:45:18 DEBUG : file1: vfs cache: setting modification time to 2025-07-04 03:45:18.804246976 +0000 UTC m=+185.440533080 2025/07/04 03:45:18 INFO : file1: vfs cache: queuing for upload in 100ms 2025/07/04 03:45:18 DEBUG : file1(0xc0008ee540): >close: err= 2025/07/04 03:45:18 DEBUG : file2: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx 2025/07/04 03:45:18 DEBUG : file2: Open: flags=O_WRONLY|O_CREATE|O_TRUNC 2025/07/04 03:45:18 DEBUG : file2: newRWFileHandle: 2025/07/04 03:45:18 DEBUG : file2(0xc0008ee9c0): openPending: 2025/07/04 03:45:18 DEBUG : file2: vfs cache: truncate to size=0 (not needed as size correct) 2025/07/04 03:45:18 DEBUG : Added virtual directory entry vAddFile: "file2" 2025/07/04 03:45:18 DEBUG : file2(0xc0008ee9c0): >openPending: err= 2025/07/04 03:45:18 DEBUG : file2: >newRWFileHandle: err= 2025/07/04 03:45:18 DEBUG : Added virtual directory entry vAddFile: "file2" 2025/07/04 03:45:18 DEBUG : file2: >Open: fd=file2 (rw), err= 2025/07/04 03:45:18 DEBUG : file2: >OpenFile: fd=file2 (rw), err= 2025/07/04 03:45:18 DEBUG : file2(0xc0008ee9c0): RWFileHandle.Flush 2025/07/04 03:45:18 DEBUG : file2(0xc0008ee9c0): RWFileHandle.Release 2025/07/04 03:45:18 DEBUG : file2(0xc0008ee9c0): close: 2025/07/04 03:45:18 DEBUG : file2: vfs cache: setting modification time to 2025-07-04 03:45:18.80601331 +0000 UTC m=+185.442299414 2025/07/04 03:45:18 INFO : file2: vfs cache: queuing for upload in 100ms 2025/07/04 03:45:18 DEBUG : file2(0xc0008ee9c0): >close: err= 2025/07/04 03:45:18 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:45:18 DEBUG : Looking for writers 2025/07/04 03:45:18 DEBUG : file1: reading active writers 2025/07/04 03:45:18 DEBUG : file2: reading active writers 2025/07/04 03:45:18 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms 2025/07/04 03:45:18 DEBUG : Looking for writers 2025/07/04 03:45:18 DEBUG : file1: reading active writers 2025/07/04 03:45:18 DEBUG : file2: reading active writers 2025/07/04 03:45:18 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms 2025/07/04 03:45:18 DEBUG : Looking for writers 2025/07/04 03:45:18 DEBUG : file1: reading active writers 2025/07/04 03:45:18 DEBUG : file2: reading active writers 2025/07/04 03:45:18 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms 2025/07/04 03:45:18 DEBUG : Looking for writers 2025/07/04 03:45:18 DEBUG : file1: reading active writers 2025/07/04 03:45:18 DEBUG : file2: reading active writers 2025/07/04 03:45:18 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms 2025/07/04 03:45:18 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:45:18 DEBUG : file2: vfs cache: starting upload 2025/07/04 03:45:18 DEBUG : Looking for writers 2025/07/04 03:45:18 DEBUG : file1: reading active writers 2025/07/04 03:45:18 DEBUG : file2: reading active writers 2025/07/04 03:45:18 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms 2025/07/04 03:45:19 DEBUG : Looking for writers 2025/07/04 03:45:19 DEBUG : file1: reading active writers 2025/07/04 03:45:19 DEBUG : file2: reading active writers 2025/07/04 03:45:19 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms 2025/07/04 03:45:19 DEBUG : Looking for writers 2025/07/04 03:45:19 DEBUG : file1: reading active writers 2025/07/04 03:45:19 DEBUG : file2: reading active writers 2025/07/04 03:45:19 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms 2025/07/04 03:45:19 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:19 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:20 DEBUG : Looking for writers 2025/07/04 03:45:20 DEBUG : file2: reading active writers 2025/07/04 03:45:20 DEBUG : file1: reading active writers 2025/07/04 03:45:20 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:20 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:45:20 ERROR : file2: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:20 ERROR : file2: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:21 DEBUG : file2: vfs cache: starting upload 2025/07/04 03:45:21 DEBUG : Looking for writers 2025/07/04 03:45:21 DEBUG : file1: reading active writers 2025/07/04 03:45:21 DEBUG : file2: reading active writers 2025/07/04 03:45:21 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:21 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:21 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:22 DEBUG : Looking for writers 2025/07/04 03:45:22 DEBUG : file1: reading active writers 2025/07/04 03:45:22 DEBUG : file2: reading active writers 2025/07/04 03:45:22 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:22 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:45:22 ERROR : file2: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:22 ERROR : file2: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:23 DEBUG : Looking for writers 2025/07/04 03:45:23 DEBUG : file1: reading active writers 2025/07/04 03:45:23 DEBUG : file2: reading active writers 2025/07/04 03:45:23 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:23 DEBUG : file2: vfs cache: starting upload 2025/07/04 03:45:23 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:23 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:24 DEBUG : Looking for writers 2025/07/04 03:45:24 DEBUG : file1: reading active writers 2025/07/04 03:45:24 DEBUG : file2: reading active writers 2025/07/04 03:45:24 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:24 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:45:24 ERROR : file2: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:24 ERROR : file2: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:25 DEBUG : Looking for writers 2025/07/04 03:45:25 DEBUG : file1: reading active writers 2025/07/04 03:45:25 DEBUG : file2: reading active writers 2025/07/04 03:45:25 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:25 DEBUG : file2: vfs cache: starting upload 2025/07/04 03:45:25 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:25 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:26 DEBUG : Looking for writers 2025/07/04 03:45:26 DEBUG : file1: reading active writers 2025/07/04 03:45:26 DEBUG : file2: reading active writers 2025/07/04 03:45:26 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:26 ERROR : file2: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:26 ERROR : file2: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:27 DEBUG : Looking for writers 2025/07/04 03:45:27 DEBUG : file1: reading active writers 2025/07/04 03:45:27 DEBUG : file2: reading active writers 2025/07/04 03:45:27 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:27 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:45:28 DEBUG : Looking for writers 2025/07/04 03:45:28 DEBUG : file1: reading active writers 2025/07/04 03:45:28 DEBUG : file2: reading active writers 2025/07/04 03:45:28 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:28 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:28 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:28 DEBUG : file2: vfs cache: starting upload 2025/07/04 03:45:29 DEBUG : Looking for writers 2025/07/04 03:45:29 DEBUG : file1: reading active writers 2025/07/04 03:45:29 DEBUG : file2: reading active writers 2025/07/04 03:45:29 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:29 ERROR : file2: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:29 ERROR : file2: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:30 DEBUG : Looking for writers 2025/07/04 03:45:30 DEBUG : file1: reading active writers 2025/07/04 03:45:30 DEBUG : file2: reading active writers 2025/07/04 03:45:30 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:31 DEBUG : Looking for writers 2025/07/04 03:45:31 DEBUG : file2: reading active writers 2025/07/04 03:45:31 DEBUG : file1: reading active writers 2025/07/04 03:45:31 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:31 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:45:32 DEBUG : Looking for writers 2025/07/04 03:45:32 DEBUG : file1: reading active writers 2025/07/04 03:45:32 DEBUG : file2: reading active writers 2025/07/04 03:45:32 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:32 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:32 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:32 DEBUG : file2: vfs cache: starting upload 2025/07/04 03:45:33 DEBUG : Looking for writers 2025/07/04 03:45:33 DEBUG : file1: reading active writers 2025/07/04 03:45:33 DEBUG : file2: reading active writers 2025/07/04 03:45:33 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:33 ERROR : file2: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:33 ERROR : file2: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:34 DEBUG : Looking for writers 2025/07/04 03:45:34 DEBUG : file1: reading active writers 2025/07/04 03:45:34 DEBUG : file2: reading active writers 2025/07/04 03:45:34 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:35 DEBUG : Looking for writers 2025/07/04 03:45:35 DEBUG : file1: reading active writers 2025/07/04 03:45:35 DEBUG : file2: reading active writers 2025/07/04 03:45:35 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:36 DEBUG : Looking for writers 2025/07/04 03:45:36 DEBUG : file1: reading active writers 2025/07/04 03:45:36 DEBUG : file2: reading active writers 2025/07/04 03:45:36 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:37 DEBUG : Looking for writers 2025/07/04 03:45:37 DEBUG : file1: reading active writers 2025/07/04 03:45:37 DEBUG : file2: reading active writers 2025/07/04 03:45:37 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:38 DEBUG : Looking for writers 2025/07/04 03:45:38 DEBUG : file2: reading active writers 2025/07/04 03:45:38 DEBUG : file1: reading active writers 2025/07/04 03:45:38 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:38 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:45:39 DEBUG : Looking for writers 2025/07/04 03:45:39 DEBUG : file1: reading active writers 2025/07/04 03:45:39 DEBUG : file2: reading active writers 2025/07/04 03:45:39 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:39 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:39 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:39 DEBUG : file2: vfs cache: starting upload 2025/07/04 03:45:40 DEBUG : Looking for writers 2025/07/04 03:45:40 DEBUG : file1: reading active writers 2025/07/04 03:45:40 DEBUG : file2: reading active writers 2025/07/04 03:45:40 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:40 ERROR : file2: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:40 ERROR : file2: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:41 DEBUG : Looking for writers 2025/07/04 03:45:41 DEBUG : file2: reading active writers 2025/07/04 03:45:41 DEBUG : file1: reading active writers 2025/07/04 03:45:41 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:42 DEBUG : Looking for writers 2025/07/04 03:45:42 DEBUG : file1: reading active writers 2025/07/04 03:45:42 DEBUG : file2: reading active writers 2025/07/04 03:45:42 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:43 DEBUG : Looking for writers 2025/07/04 03:45:43 DEBUG : file1: reading active writers 2025/07/04 03:45:43 DEBUG : file2: reading active writers 2025/07/04 03:45:43 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:44 DEBUG : Looking for writers 2025/07/04 03:45:44 DEBUG : file1: reading active writers 2025/07/04 03:45:44 DEBUG : file2: reading active writers 2025/07/04 03:45:44 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:45 DEBUG : Looking for writers 2025/07/04 03:45:45 DEBUG : file1: reading active writers 2025/07/04 03:45:45 DEBUG : file2: reading active writers 2025/07/04 03:45:45 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:46 DEBUG : Looking for writers 2025/07/04 03:45:46 DEBUG : file1: reading active writers 2025/07/04 03:45:46 DEBUG : file2: reading active writers 2025/07/04 03:45:46 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:47 DEBUG : Looking for writers 2025/07/04 03:45:47 DEBUG : file1: reading active writers 2025/07/04 03:45:47 DEBUG : file2: reading active writers 2025/07/04 03:45:47 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:48 DEBUG : Looking for writers 2025/07/04 03:45:48 DEBUG : file1: reading active writers 2025/07/04 03:45:48 DEBUG : file2: reading active writers 2025/07/04 03:45:48 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:48 ERROR : Exiting even though 0 writers active and 2 cache items in use after 30s Cache{ "file1": &{c:0xc0008ae5a0 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc000780408 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824641586240} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13984223797137364416 ext:185440533080 loc:0x3fe46e0} ATime:{wall:13984223797137743057 ext:185440911721 loc:0x3fe46e0} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, "file2": &{c:0xc0008ae5a0 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc000780508 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824641586496} name:file2 opens:0 downloaders: o: fd: info:{ModTime:{wall:13984223797139130750 ext:185442299414 loc:0x3fe46e0} ATime:{wall:13984223797139462102 ext:185442630766 loc:0x3fe46e0} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2 pendingAccesses:0 modified:false beingReset:false}, } 2025/07/04 03:45:48 DEBUG : >WaitForWriters: 2025/07/04 03:45:49 ERROR : error listing: directory not found fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Flushing the directory cache 2025/07/04 03:45:50 ERROR : error listing: directory not found fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:298: Flushing the directory cache 2025/07/04 03:45:52 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:45:52 ERROR : error listing: directory not found fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 2025/07/04 03:45:53 DEBUG : file2: vfs cache: starting upload 2025/07/04 03:45:53 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:53 ERROR : file1: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:54 ERROR : file2: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:45:54 ERROR : file2: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. fstest.go:298: Flushing the directory cache fstest.go:302: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write_test.go:420 Error: Should be true Test: TestRWFileHandleWriteNoWrite Messages: listing wrong, want file1 (0), file2 (0) got fstest.go:200: Not found "file1" fstest.go:200: Not found "file2" fstest.go:203: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:203 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:307 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write_test.go:420 Error: Not equal: expected: 0 actual : 2 Test: TestRWFileHandleWriteNoWrite Messages: 2 objects not found 2025/07/04 03:45:56 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:45:56 DEBUG : Looking for writers 2025/07/04 03:45:56 DEBUG : file1: reading active writers 2025/07/04 03:45:56 DEBUG : file2: reading active writers 2025/07/04 03:45:56 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms 2025/07/04 03:45:56 DEBUG : Looking for writers 2025/07/04 03:45:56 DEBUG : file1: reading active writers 2025/07/04 03:45:56 DEBUG : file2: reading active writers 2025/07/04 03:45:56 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms 2025/07/04 03:45:56 DEBUG : Looking for writers 2025/07/04 03:45:56 DEBUG : file1: reading active writers 2025/07/04 03:45:56 DEBUG : file2: reading active writers 2025/07/04 03:45:56 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms 2025/07/04 03:45:56 DEBUG : Looking for writers 2025/07/04 03:45:56 DEBUG : file1: reading active writers 2025/07/04 03:45:56 DEBUG : file2: reading active writers 2025/07/04 03:45:56 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms 2025/07/04 03:45:56 DEBUG : Looking for writers 2025/07/04 03:45:56 DEBUG : file1: reading active writers 2025/07/04 03:45:56 DEBUG : file2: reading active writers 2025/07/04 03:45:56 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms 2025/07/04 03:45:57 DEBUG : Looking for writers 2025/07/04 03:45:57 DEBUG : file2: reading active writers 2025/07/04 03:45:57 DEBUG : file1: reading active writers 2025/07/04 03:45:57 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms 2025/07/04 03:45:57 DEBUG : Looking for writers 2025/07/04 03:45:57 DEBUG : file1: reading active writers 2025/07/04 03:45:57 DEBUG : file2: reading active writers 2025/07/04 03:45:57 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms 2025/07/04 03:45:58 DEBUG : Looking for writers 2025/07/04 03:45:58 DEBUG : file2: reading active writers 2025/07/04 03:45:58 DEBUG : file1: reading active writers 2025/07/04 03:45:58 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:45:59 DEBUG : Looking for writers 2025/07/04 03:45:59 DEBUG : file1: reading active writers 2025/07/04 03:45:59 DEBUG : file2: reading active writers 2025/07/04 03:45:59 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:00 DEBUG : Looking for writers 2025/07/04 03:46:00 DEBUG : file1: reading active writers 2025/07/04 03:46:00 DEBUG : file2: reading active writers 2025/07/04 03:46:00 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:01 DEBUG : Looking for writers 2025/07/04 03:46:01 DEBUG : file1: reading active writers 2025/07/04 03:46:01 DEBUG : file2: reading active writers 2025/07/04 03:46:01 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:02 DEBUG : Looking for writers 2025/07/04 03:46:02 DEBUG : file1: reading active writers 2025/07/04 03:46:02 DEBUG : file2: reading active writers 2025/07/04 03:46:02 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:03 DEBUG : Looking for writers 2025/07/04 03:46:03 DEBUG : file1: reading active writers 2025/07/04 03:46:03 DEBUG : file2: reading active writers 2025/07/04 03:46:03 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:04 DEBUG : Looking for writers 2025/07/04 03:46:04 DEBUG : file2: reading active writers 2025/07/04 03:46:04 DEBUG : file1: reading active writers 2025/07/04 03:46:04 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:05 DEBUG : Looking for writers 2025/07/04 03:46:05 DEBUG : file1: reading active writers 2025/07/04 03:46:05 DEBUG : file2: reading active writers 2025/07/04 03:46:05 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:06 DEBUG : Looking for writers 2025/07/04 03:46:06 DEBUG : file1: reading active writers 2025/07/04 03:46:06 DEBUG : file2: reading active writers 2025/07/04 03:46:06 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:07 DEBUG : Looking for writers 2025/07/04 03:46:07 DEBUG : file1: reading active writers 2025/07/04 03:46:07 DEBUG : file2: reading active writers 2025/07/04 03:46:07 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:08 DEBUG : Looking for writers 2025/07/04 03:46:08 DEBUG : file1: reading active writers 2025/07/04 03:46:08 DEBUG : file2: reading active writers 2025/07/04 03:46:08 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:09 DEBUG : Looking for writers 2025/07/04 03:46:09 DEBUG : file1: reading active writers 2025/07/04 03:46:09 DEBUG : file2: reading active writers 2025/07/04 03:46:09 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:10 DEBUG : Looking for writers 2025/07/04 03:46:10 DEBUG : file1: reading active writers 2025/07/04 03:46:10 DEBUG : file2: reading active writers 2025/07/04 03:46:10 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:11 DEBUG : Looking for writers 2025/07/04 03:46:11 DEBUG : file1: reading active writers 2025/07/04 03:46:11 DEBUG : file2: reading active writers 2025/07/04 03:46:11 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:12 DEBUG : Looking for writers 2025/07/04 03:46:12 DEBUG : file1: reading active writers 2025/07/04 03:46:12 DEBUG : file2: reading active writers 2025/07/04 03:46:12 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:13 DEBUG : Looking for writers 2025/07/04 03:46:13 DEBUG : file1: reading active writers 2025/07/04 03:46:13 DEBUG : file2: reading active writers 2025/07/04 03:46:13 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:14 DEBUG : Looking for writers 2025/07/04 03:46:14 DEBUG : file2: reading active writers 2025/07/04 03:46:14 DEBUG : file1: reading active writers 2025/07/04 03:46:14 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:15 DEBUG : Looking for writers 2025/07/04 03:46:15 DEBUG : file1: reading active writers 2025/07/04 03:46:15 DEBUG : file2: reading active writers 2025/07/04 03:46:15 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:16 DEBUG : Looking for writers 2025/07/04 03:46:16 DEBUG : file1: reading active writers 2025/07/04 03:46:16 DEBUG : file2: reading active writers 2025/07/04 03:46:16 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:17 DEBUG : Looking for writers 2025/07/04 03:46:17 DEBUG : file2: reading active writers 2025/07/04 03:46:17 DEBUG : file1: reading active writers 2025/07/04 03:46:17 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:18 DEBUG : Looking for writers 2025/07/04 03:46:18 DEBUG : file2: reading active writers 2025/07/04 03:46:18 DEBUG : file1: reading active writers 2025/07/04 03:46:18 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:18 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2025/07/04 03:46:18 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file2 not removed, freed 0 bytes 2025/07/04 03:46:18 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 2 (was 2) in use 2, to upload 2, uploading 0, total size 0 (was 0) 2025/07/04 03:46:19 DEBUG : Looking for writers 2025/07/04 03:46:19 DEBUG : file2: reading active writers 2025/07/04 03:46:19 DEBUG : file1: reading active writers 2025/07/04 03:46:19 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:19 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:46:20 DEBUG : Looking for writers 2025/07/04 03:46:20 DEBUG : file1: reading active writers 2025/07/04 03:46:20 DEBUG : file2: reading active writers 2025/07/04 03:46:20 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:20 DEBUG : file2: vfs cache: starting upload 2025/07/04 03:46:20 ERROR : file1: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:46:20 ERROR : file1: vfs cache: failed to upload try #9, will retry in 51.2s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:46:21 DEBUG : Looking for writers 2025/07/04 03:46:21 DEBUG : file1: reading active writers 2025/07/04 03:46:21 DEBUG : file2: reading active writers 2025/07/04 03:46:21 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:21 ERROR : file2: Failed to copy: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:46:21 ERROR : file2: vfs cache: failed to upload try #9, will retry in 51.2s: vfs cache: failed to transfer file from cache to remote: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:46:22 DEBUG : Looking for writers 2025/07/04 03:46:22 DEBUG : file1: reading active writers 2025/07/04 03:46:22 DEBUG : file2: reading active writers 2025/07/04 03:46:22 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:23 DEBUG : Looking for writers 2025/07/04 03:46:23 DEBUG : file1: reading active writers 2025/07/04 03:46:23 DEBUG : file2: reading active writers 2025/07/04 03:46:23 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:24 DEBUG : Looking for writers 2025/07/04 03:46:24 DEBUG : file1: reading active writers 2025/07/04 03:46:24 DEBUG : file2: reading active writers 2025/07/04 03:46:24 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:25 DEBUG : Looking for writers 2025/07/04 03:46:25 DEBUG : file2: reading active writers 2025/07/04 03:46:25 DEBUG : file1: reading active writers 2025/07/04 03:46:25 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:26 DEBUG : Looking for writers 2025/07/04 03:46:26 DEBUG : file1: reading active writers 2025/07/04 03:46:26 DEBUG : file2: reading active writers 2025/07/04 03:46:26 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:46:26 ERROR : Exiting even though 0 writers active and 2 cache items in use after 30s Cache{ "file1": &{c:0xc0008ae5a0 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc000780408 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824641586240} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13984223797137364416 ext:185440533080 loc:0x3fe46e0} ATime:{wall:13984223797137743057 ext:185440911721 loc:0x3fe46e0} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, "file2": &{c:0xc0008ae5a0 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc000780508 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824641586496} name:file2 opens:0 downloaders: o: fd: info:{ModTime:{wall:13984223797139130750 ext:185442299414 loc:0x3fe46e0} ATime:{wall:13984223797139462102 ext:185442630766 loc:0x3fe46e0} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2 pendingAccesses:0 modified:false beingReset:false}, } 2025/07/04 03:46:26 DEBUG : >WaitForWriters: 2025/07/04 03:46:26 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:46:27 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleWriteNoWrite (68.58s) === RUN TestRWFileHandleSizeTruncateExisting run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:46:27 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:46:27 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:46:27 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:46:27 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:46:27 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:46:27 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:46:27 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:46:27 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:46:27 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:46:27 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:46:27 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:46:27 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:46:27 DEBUG : Looking for writers 2025/07/04 03:46:27 DEBUG : >WaitForWriters: 2025/07/04 03:46:27 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:46:28 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleSizeTruncateExisting (0.94s) === RUN TestRWFileHandleSizeCreateExisting run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:46:28 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:46:28 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:46:28 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:46:28 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:46:28 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:46:28 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:46:28 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:46:28 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:46:28 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:46:28 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:46:28 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:46:28 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:46:28 DEBUG : Looking for writers 2025/07/04 03:46:28 DEBUG : >WaitForWriters: 2025/07/04 03:46:28 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:46:28 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleSizeCreateExisting (0.95s) === RUN TestRWFileModTimeWithOpenWriters run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:46:28 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:46:28 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:46:28 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:46:28 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:46:28 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:46:28 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:46:28 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:46:28 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:46:28 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:46:28 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-gehowin3kahe" 2025/07/04 03:46:28 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:46:28 INFO : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2025/07/04 03:46:29 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:46:29 DEBUG : file1: newRWFileHandle: 2025/07/04 03:46:29 DEBUG : file1(0xc0007791c0): openPending: 2025/07/04 03:46:29 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2025/07/04 03:46:29 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:46:29 DEBUG : file1(0xc0007791c0): >openPending: err= 2025/07/04 03:46:29 DEBUG : file1: >newRWFileHandle: err= 2025/07/04 03:46:29 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:46:29 DEBUG : file1: >Open: fd=file1 (rw), err= 2025/07/04 03:46:29 DEBUG : file1: >OpenFile: fd=file1 (rw), err= run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:46:29 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:46:29 DEBUG : Looking for writers 2025/07/04 03:46:29 DEBUG : file1: reading active writers 2025/07/04 03:46:29 DEBUG : file1: active writers 1 2025/07/04 03:46:29 DEBUG : Still 1 writers active and 1 cache items in use, waiting 10ms 2025/07/04 03:46:29 DEBUG : Looking for writers 2025/07/04 03:46:29 DEBUG : file1: reading active writers 2025/07/04 03:46:29 DEBUG : file1: active writers 1 2025/07/04 03:46:29 DEBUG : Still 1 writers active and 1 cache items in use, waiting 20ms 2025/07/04 03:46:29 DEBUG : Looking for writers 2025/07/04 03:46:29 DEBUG : file1: reading active writers 2025/07/04 03:46:29 DEBUG : file1: active writers 1 2025/07/04 03:46:29 DEBUG : Still 1 writers active and 1 cache items in use, waiting 40ms 2025/07/04 03:46:29 DEBUG : Looking for writers 2025/07/04 03:46:29 DEBUG : file1: reading active writers 2025/07/04 03:46:29 DEBUG : file1: active writers 1 2025/07/04 03:46:29 DEBUG : Still 1 writers active and 1 cache items in use, waiting 80ms 2025/07/04 03:46:30 DEBUG : Looking for writers 2025/07/04 03:46:30 DEBUG : file1: reading active writers 2025/07/04 03:46:30 DEBUG : file1: active writers 1 2025/07/04 03:46:30 DEBUG : Still 1 writers active and 1 cache items in use, waiting 160ms 2025/07/04 03:46:30 DEBUG : Looking for writers 2025/07/04 03:46:30 DEBUG : file1: reading active writers 2025/07/04 03:46:30 DEBUG : file1: active writers 1 2025/07/04 03:46:30 DEBUG : Still 1 writers active and 1 cache items in use, waiting 320ms 2025/07/04 03:46:30 DEBUG : Looking for writers 2025/07/04 03:46:30 DEBUG : file1: reading active writers 2025/07/04 03:46:30 DEBUG : file1: active writers 1 2025/07/04 03:46:30 DEBUG : Still 1 writers active and 1 cache items in use, waiting 640ms 2025/07/04 03:46:31 DEBUG : Looking for writers 2025/07/04 03:46:31 DEBUG : file1: reading active writers 2025/07/04 03:46:31 DEBUG : file1: active writers 1 2025/07/04 03:46:31 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:32 DEBUG : Looking for writers 2025/07/04 03:46:32 DEBUG : file1: reading active writers 2025/07/04 03:46:32 DEBUG : file1: active writers 1 2025/07/04 03:46:32 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:33 DEBUG : Looking for writers 2025/07/04 03:46:33 DEBUG : file1: reading active writers 2025/07/04 03:46:33 DEBUG : file1: active writers 1 2025/07/04 03:46:33 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:34 DEBUG : Looking for writers 2025/07/04 03:46:34 DEBUG : file1: reading active writers 2025/07/04 03:46:34 DEBUG : file1: active writers 1 2025/07/04 03:46:34 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:35 DEBUG : Looking for writers 2025/07/04 03:46:35 DEBUG : file1: reading active writers 2025/07/04 03:46:35 DEBUG : file1: active writers 1 2025/07/04 03:46:35 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:36 DEBUG : Looking for writers 2025/07/04 03:46:36 DEBUG : file1: reading active writers 2025/07/04 03:46:36 DEBUG : file1: active writers 1 2025/07/04 03:46:36 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:37 DEBUG : Looking for writers 2025/07/04 03:46:37 DEBUG : file1: reading active writers 2025/07/04 03:46:37 DEBUG : file1: active writers 1 2025/07/04 03:46:37 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:38 DEBUG : Looking for writers 2025/07/04 03:46:38 DEBUG : file1: reading active writers 2025/07/04 03:46:38 DEBUG : file1: active writers 1 2025/07/04 03:46:38 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:39 DEBUG : Looking for writers 2025/07/04 03:46:39 DEBUG : file1: reading active writers 2025/07/04 03:46:39 DEBUG : file1: active writers 1 2025/07/04 03:46:39 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:40 DEBUG : Looking for writers 2025/07/04 03:46:40 DEBUG : file1: reading active writers 2025/07/04 03:46:40 DEBUG : file1: active writers 1 2025/07/04 03:46:40 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:41 DEBUG : Looking for writers 2025/07/04 03:46:41 DEBUG : file1: reading active writers 2025/07/04 03:46:41 DEBUG : file1: active writers 1 2025/07/04 03:46:41 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:42 DEBUG : Looking for writers 2025/07/04 03:46:42 DEBUG : file1: reading active writers 2025/07/04 03:46:42 DEBUG : file1: active writers 1 2025/07/04 03:46:42 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:43 DEBUG : Looking for writers 2025/07/04 03:46:43 DEBUG : file1: reading active writers 2025/07/04 03:46:43 DEBUG : file1: active writers 1 2025/07/04 03:46:43 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:44 DEBUG : Looking for writers 2025/07/04 03:46:44 DEBUG : file1: reading active writers 2025/07/04 03:46:44 DEBUG : file1: active writers 1 2025/07/04 03:46:44 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:45 DEBUG : Looking for writers 2025/07/04 03:46:45 DEBUG : file1: reading active writers 2025/07/04 03:46:45 DEBUG : file1: active writers 1 2025/07/04 03:46:45 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:46 DEBUG : Looking for writers 2025/07/04 03:46:46 DEBUG : file1: reading active writers 2025/07/04 03:46:46 DEBUG : file1: active writers 1 2025/07/04 03:46:46 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:47 DEBUG : Looking for writers 2025/07/04 03:46:47 DEBUG : file1: reading active writers 2025/07/04 03:46:47 DEBUG : file1: active writers 1 2025/07/04 03:46:47 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:48 DEBUG : Looking for writers 2025/07/04 03:46:48 DEBUG : file1: reading active writers 2025/07/04 03:46:48 DEBUG : file1: active writers 1 2025/07/04 03:46:48 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:49 DEBUG : Looking for writers 2025/07/04 03:46:49 DEBUG : file1: reading active writers 2025/07/04 03:46:49 DEBUG : file1: active writers 1 2025/07/04 03:46:49 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:50 DEBUG : Looking for writers 2025/07/04 03:46:50 DEBUG : file1: reading active writers 2025/07/04 03:46:50 DEBUG : file1: active writers 1 2025/07/04 03:46:50 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:51 DEBUG : Looking for writers 2025/07/04 03:46:51 DEBUG : file1: reading active writers 2025/07/04 03:46:51 DEBUG : file1: active writers 1 2025/07/04 03:46:51 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:52 DEBUG : Looking for writers 2025/07/04 03:46:52 DEBUG : file1: reading active writers 2025/07/04 03:46:52 DEBUG : file1: active writers 1 2025/07/04 03:46:52 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:53 DEBUG : Looking for writers 2025/07/04 03:46:53 DEBUG : file1: reading active writers 2025/07/04 03:46:53 DEBUG : file1: active writers 1 2025/07/04 03:46:53 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:54 DEBUG : Looking for writers 2025/07/04 03:46:54 DEBUG : file1: reading active writers 2025/07/04 03:46:54 DEBUG : file1: active writers 1 2025/07/04 03:46:54 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:55 DEBUG : Looking for writers 2025/07/04 03:46:55 DEBUG : file1: reading active writers 2025/07/04 03:46:55 DEBUG : file1: active writers 1 2025/07/04 03:46:55 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:56 DEBUG : Looking for writers 2025/07/04 03:46:56 DEBUG : file1: reading active writers 2025/07/04 03:46:56 DEBUG : file1: active writers 1 2025/07/04 03:46:56 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:57 DEBUG : Looking for writers 2025/07/04 03:46:57 DEBUG : file1: reading active writers 2025/07/04 03:46:57 DEBUG : file1: active writers 1 2025/07/04 03:46:57 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:58 DEBUG : Looking for writers 2025/07/04 03:46:58 DEBUG : file1: reading active writers 2025/07/04 03:46:58 DEBUG : file1: active writers 1 2025/07/04 03:46:58 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:59 DEBUG : Looking for writers 2025/07/04 03:46:59 DEBUG : file1: reading active writers 2025/07/04 03:46:59 DEBUG : file1: active writers 1 2025/07/04 03:46:59 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:46:59 ERROR : Exiting even though 1 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc0009344b0 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc00046f908 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824638372160} name:file1 opens:1 downloaders: o: fd:0xc00008a388 info:{ModTime:{wall:13984223872841246256 ext:255908745386 loc:0x3fe46e0} ATime:{wall:13984223872841246256 ext:255908745386 loc:0x3fe46e0} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:0 pendingAccesses:0 modified:true beingReset:false}, } 2025/07/04 03:46:59 DEBUG : >WaitForWriters: 2025/07/04 03:46:59 DEBUG : PikPak root 'rclone-test-gehowin3kahe': vfs cache: cleaner exiting 2025/07/04 03:47:01 DEBUG : Saving config "captcha_token" in section "TestPikPak" of the config file 2025/07/04 03:47:01 ERROR : error listing: directory not found --- FAIL: TestRWFileModTimeWithOpenWriters (32.59s) === RUN TestCaseSensitivity run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:47:02 ERROR : error listing: directory not found --- FAIL: TestCaseSensitivity (0.96s) === RUN TestUnicodeNormalization run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:47:03 ERROR : error listing: directory not found --- FAIL: TestUnicodeNormalization (0.95s) === RUN TestVFSStat run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:47:03 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:47:03 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:47:04 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:47:04 DEBUG : Looking for writers 2025/07/04 03:47:04 DEBUG : >WaitForWriters: 2025/07/04 03:47:04 ERROR : error listing: directory not found --- FAIL: TestVFSStat (0.95s) === RUN TestVFSStatParent run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:47:04 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:47:04 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:47:05 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:47:05 DEBUG : Looking for writers 2025/07/04 03:47:05 DEBUG : >WaitForWriters: 2025/07/04 03:47:05 ERROR : error listing: directory not found --- FAIL: TestVFSStatParent (0.99s) === RUN TestVFSOpenFile run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:47:05 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:47:05 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:47:06 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:47:06 DEBUG : Looking for writers 2025/07/04 03:47:06 DEBUG : >WaitForWriters: 2025/07/04 03:47:06 ERROR : error listing: directory not found --- FAIL: TestVFSOpenFile (0.95s) === RUN TestVFSRename run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:47:06 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:47:06 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:237: Failed to mkdir "PikPak root 'rclone-test-gehowin3kahe'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:47:07 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:47:07 DEBUG : Looking for writers 2025/07/04 03:47:07 DEBUG : >WaitForWriters: 2025/07/04 03:47:07 ERROR : error listing: directory not found --- FAIL: TestVFSRename (0.95s) === RUN TestVFSMkdir run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:47:07 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:47:07 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:47:07 ERROR : error listing: directory not found 2025/07/04 03:47:08 ERROR : /: Dir.Mkdir failed to create directory: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. vfs_test.go:376: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/vfs_test.go:376 Error: Received unexpected error: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. Test: TestVFSMkdir 2025/07/04 03:47:08 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:47:08 DEBUG : Looking for writers 2025/07/04 03:47:08 DEBUG : >WaitForWriters: 2025/07/04 03:47:08 ERROR : error listing: directory not found --- FAIL: TestVFSMkdir (1.58s) === RUN TestVFSMkdirAll run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:47:08 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:47:08 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:47:09 ERROR : error listing: directory not found 2025/07/04 03:47:09 ERROR : error listing: directory not found 2025/07/04 03:47:10 ERROR : /: Dir.Mkdir failed to create directory: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. vfs_test.go:426: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/vfs_test.go:426 Error: Received unexpected error: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. Test: TestVFSMkdirAll 2025/07/04 03:47:10 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:47:10 DEBUG : Looking for writers 2025/07/04 03:47:10 DEBUG : >WaitForWriters: 2025/07/04 03:47:10 ERROR : error listing: directory not found --- FAIL: TestVFSMkdirAll (1.90s) === RUN TestWriteFileHandleMethods run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:47:10 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:47:10 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:47:10 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:47:11 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:47:11 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:47:11 DEBUG : file1: >Open: fd=file1 (w), err= 2025/07/04 03:47:11 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/07/04 03:47:11 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:47:11 ERROR : file1: WriteFileHandle: Read: Can't read and write to file without --vfs-cache-mode >= minimal 2025/07/04 03:47:11 ERROR : file1: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal 2025/07/04 03:47:11 ERROR : file1: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes 2025/07/04 03:47:11 DEBUG : PikPak root 'rclone-test-gehowin3kahe': File to upload is small (5 bytes), uploading instead of streaming 2025/07/04 03:47:12 ERROR : file1: WriteFileHandle.New Rcat failed: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:47:12 DEBUG : file1: Remove: 2025/07/04 03:47:12 DEBUG : Added virtual directory entry vDel: "file1" 2025/07/04 03:47:12 DEBUG : file1: >Remove: err= write_test.go:144: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:144 Error: Received unexpected error: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. Test: TestWriteFileHandleMethods dir_test.go:250: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:250 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:153 Error: Not equal: expected: []string{"file1,5,false"} actual : []string(nil) Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=1) { - (string) (len=13) "file1,5,false" -} +([]string) Test: TestWriteFileHandleMethods 2025/07/04 03:47:12 ERROR : error listing: directory not found fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Flushing the directory cache 2025/07/04 03:47:13 ERROR : error listing: directory not found fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:298: Flushing the directory cache 2025/07/04 03:47:16 ERROR : error listing: directory not found fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:298: Flushing the directory cache fstest.go:302: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:157 Error: Should be true Test: TestWriteFileHandleMethods Messages: listing wrong, want file1 (5) got fstest.go:200: Not found "file1" fstest.go:203: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:203 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:307 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:157 Error: Not equal: expected: 0 actual : 1 Test: TestWriteFileHandleMethods Messages: 1 objects not found 2025/07/04 03:47:20 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:47:20 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:47:20 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:47:20 DEBUG : file1: >Open: fd=file1 (w), err= 2025/07/04 03:47:20 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/07/04 03:47:20 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:47:20 DEBUG : PikPak root 'rclone-test-gehowin3kahe': File to upload is small (0 bytes), uploading instead of streaming 2025/07/04 03:47:20 ERROR : file1: WriteFileHandle.New Rcat failed: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:47:20 DEBUG : file1: Remove: 2025/07/04 03:47:20 DEBUG : Added virtual directory entry vDel: "file1" 2025/07/04 03:47:20 DEBUG : file1: >Remove: err= write_test.go:163: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:163 Error: Received unexpected error: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. Test: TestWriteFileHandleMethods dir_test.go:250: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:250 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:164 Error: Not equal: expected: []string{"file1,5,false"} actual : []string(nil) Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=1) { - (string) (len=13) "file1,5,false" -} +([]string) Test: TestWriteFileHandleMethods 2025/07/04 03:47:20 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:47:20 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:47:20 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:47:20 DEBUG : file1: >Open: fd=file1 (w), err= 2025/07/04 03:47:20 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/07/04 03:47:20 DEBUG : Added virtual directory entry vAddFile: "file1" write_test.go:171: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:171 Error: Not equal: expected: *errors.errorString(&errors.errorString{s:"permission denied"}) actual : () Test: TestWriteFileHandleMethods 2025/07/04 03:47:20 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:47:20 DEBUG : Looking for writers 2025/07/04 03:47:20 DEBUG : file1: reading active writers 2025/07/04 03:47:20 DEBUG : file1: active writers 1 2025/07/04 03:47:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2025/07/04 03:47:21 DEBUG : Looking for writers 2025/07/04 03:47:21 DEBUG : file1: reading active writers 2025/07/04 03:47:21 DEBUG : file1: active writers 1 2025/07/04 03:47:21 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2025/07/04 03:47:21 DEBUG : Looking for writers 2025/07/04 03:47:21 DEBUG : file1: reading active writers 2025/07/04 03:47:21 DEBUG : file1: active writers 1 2025/07/04 03:47:21 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2025/07/04 03:47:21 DEBUG : Looking for writers 2025/07/04 03:47:21 DEBUG : file1: reading active writers 2025/07/04 03:47:21 DEBUG : file1: active writers 1 2025/07/04 03:47:21 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2025/07/04 03:47:21 DEBUG : Looking for writers 2025/07/04 03:47:21 DEBUG : file1: reading active writers 2025/07/04 03:47:21 DEBUG : file1: active writers 1 2025/07/04 03:47:21 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2025/07/04 03:47:21 DEBUG : Looking for writers 2025/07/04 03:47:21 DEBUG : file1: reading active writers 2025/07/04 03:47:21 DEBUG : file1: active writers 1 2025/07/04 03:47:21 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2025/07/04 03:47:21 DEBUG : Looking for writers 2025/07/04 03:47:21 DEBUG : file1: reading active writers 2025/07/04 03:47:21 DEBUG : file1: active writers 1 2025/07/04 03:47:21 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2025/07/04 03:47:22 DEBUG : Looking for writers 2025/07/04 03:47:22 DEBUG : file1: reading active writers 2025/07/04 03:47:22 DEBUG : file1: active writers 1 2025/07/04 03:47:22 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:23 DEBUG : Looking for writers 2025/07/04 03:47:23 DEBUG : file1: reading active writers 2025/07/04 03:47:23 DEBUG : file1: active writers 1 2025/07/04 03:47:23 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:24 DEBUG : Looking for writers 2025/07/04 03:47:24 DEBUG : file1: reading active writers 2025/07/04 03:47:24 DEBUG : file1: active writers 1 2025/07/04 03:47:24 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:25 DEBUG : Looking for writers 2025/07/04 03:47:25 DEBUG : file1: reading active writers 2025/07/04 03:47:25 DEBUG : file1: active writers 1 2025/07/04 03:47:25 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:26 DEBUG : Looking for writers 2025/07/04 03:47:26 DEBUG : file1: reading active writers 2025/07/04 03:47:26 DEBUG : file1: active writers 1 2025/07/04 03:47:26 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:27 DEBUG : Looking for writers 2025/07/04 03:47:27 DEBUG : file1: reading active writers 2025/07/04 03:47:27 DEBUG : file1: active writers 1 2025/07/04 03:47:27 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:28 DEBUG : Looking for writers 2025/07/04 03:47:28 DEBUG : file1: reading active writers 2025/07/04 03:47:28 DEBUG : file1: active writers 1 2025/07/04 03:47:28 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:29 DEBUG : Looking for writers 2025/07/04 03:47:29 DEBUG : file1: reading active writers 2025/07/04 03:47:29 DEBUG : file1: active writers 1 2025/07/04 03:47:29 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:30 DEBUG : Looking for writers 2025/07/04 03:47:30 DEBUG : file1: reading active writers 2025/07/04 03:47:30 DEBUG : file1: active writers 1 2025/07/04 03:47:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:31 DEBUG : Looking for writers 2025/07/04 03:47:31 DEBUG : file1: reading active writers 2025/07/04 03:47:31 DEBUG : file1: active writers 1 2025/07/04 03:47:31 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:32 DEBUG : Looking for writers 2025/07/04 03:47:32 DEBUG : file1: reading active writers 2025/07/04 03:47:32 DEBUG : file1: active writers 1 2025/07/04 03:47:32 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:33 DEBUG : Looking for writers 2025/07/04 03:47:33 DEBUG : file1: reading active writers 2025/07/04 03:47:33 DEBUG : file1: active writers 1 2025/07/04 03:47:33 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:34 DEBUG : Looking for writers 2025/07/04 03:47:34 DEBUG : file1: reading active writers 2025/07/04 03:47:34 DEBUG : file1: active writers 1 2025/07/04 03:47:34 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:35 DEBUG : Looking for writers 2025/07/04 03:47:35 DEBUG : file1: reading active writers 2025/07/04 03:47:35 DEBUG : file1: active writers 1 2025/07/04 03:47:35 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:36 DEBUG : Looking for writers 2025/07/04 03:47:36 DEBUG : file1: reading active writers 2025/07/04 03:47:36 DEBUG : file1: active writers 1 2025/07/04 03:47:36 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:37 DEBUG : Looking for writers 2025/07/04 03:47:37 DEBUG : file1: reading active writers 2025/07/04 03:47:37 DEBUG : file1: active writers 1 2025/07/04 03:47:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:38 DEBUG : Looking for writers 2025/07/04 03:47:38 DEBUG : file1: reading active writers 2025/07/04 03:47:38 DEBUG : file1: active writers 1 2025/07/04 03:47:38 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:39 DEBUG : Looking for writers 2025/07/04 03:47:39 DEBUG : file1: reading active writers 2025/07/04 03:47:39 DEBUG : file1: active writers 1 2025/07/04 03:47:39 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:40 DEBUG : Looking for writers 2025/07/04 03:47:40 DEBUG : file1: reading active writers 2025/07/04 03:47:40 DEBUG : file1: active writers 1 2025/07/04 03:47:40 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:41 DEBUG : Looking for writers 2025/07/04 03:47:41 DEBUG : file1: reading active writers 2025/07/04 03:47:41 DEBUG : file1: active writers 1 2025/07/04 03:47:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:42 DEBUG : Looking for writers 2025/07/04 03:47:42 DEBUG : file1: reading active writers 2025/07/04 03:47:42 DEBUG : file1: active writers 1 2025/07/04 03:47:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:43 DEBUG : Looking for writers 2025/07/04 03:47:43 DEBUG : file1: reading active writers 2025/07/04 03:47:43 DEBUG : file1: active writers 1 2025/07/04 03:47:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:44 DEBUG : Looking for writers 2025/07/04 03:47:44 DEBUG : file1: reading active writers 2025/07/04 03:47:44 DEBUG : file1: active writers 1 2025/07/04 03:47:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:45 DEBUG : Looking for writers 2025/07/04 03:47:45 DEBUG : file1: reading active writers 2025/07/04 03:47:45 DEBUG : file1: active writers 1 2025/07/04 03:47:45 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:46 DEBUG : Looking for writers 2025/07/04 03:47:46 DEBUG : file1: reading active writers 2025/07/04 03:47:46 DEBUG : file1: active writers 1 2025/07/04 03:47:46 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:47 DEBUG : Looking for writers 2025/07/04 03:47:47 DEBUG : file1: reading active writers 2025/07/04 03:47:47 DEBUG : file1: active writers 1 2025/07/04 03:47:47 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:48 DEBUG : Looking for writers 2025/07/04 03:47:48 DEBUG : file1: reading active writers 2025/07/04 03:47:48 DEBUG : file1: active writers 1 2025/07/04 03:47:48 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:49 DEBUG : Looking for writers 2025/07/04 03:47:49 DEBUG : file1: reading active writers 2025/07/04 03:47:49 DEBUG : file1: active writers 1 2025/07/04 03:47:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:50 DEBUG : Looking for writers 2025/07/04 03:47:50 DEBUG : file1: reading active writers 2025/07/04 03:47:50 DEBUG : file1: active writers 1 2025/07/04 03:47:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:47:50 ERROR : Exiting even though 1 writers active and 0 cache items in use after 30s Cache: 2025/07/04 03:47:50 DEBUG : >WaitForWriters: 2025/07/04 03:47:51 ERROR : error listing: directory not found --- FAIL: TestWriteFileHandleMethods (40.54s) === RUN TestWriteFileHandleWriteAt run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:47:51 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:47:51 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:47:51 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:47:51 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:47:51 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:47:51 DEBUG : file1: >Open: fd=file1 (w), err= 2025/07/04 03:47:51 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/07/04 03:47:51 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:47:51 DEBUG : file1: waiting for in-sequence write to 100 for 1s 2025/07/04 03:47:52 DEBUG : file1: aborting in-sequence write wait, off=100 2025/07/04 03:47:52 DEBUG : file1: failed to wait for in-sequence write to 100 2025/07/04 03:47:52 ERROR : file1: WriteFileHandle.Write: can't seek in file without --vfs-cache-mode >= writes 2025/07/04 03:47:52 DEBUG : PikPak root 'rclone-test-gehowin3kahe': File to upload is small (11 bytes), uploading instead of streaming 2025/07/04 03:47:53 ERROR : file1: WriteFileHandle.New Rcat failed: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:47:53 DEBUG : file1: Remove: 2025/07/04 03:47:53 DEBUG : Added virtual directory entry vDel: "file1" 2025/07/04 03:47:53 DEBUG : file1: >Remove: err= write_test.go:221: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:221 Error: Received unexpected error: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. Test: TestWriteFileHandleWriteAt 2025/07/04 03:47:53 ERROR : file1: WriteFileHandle.Write: error: Bad file descriptor dir_test.go:250: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:250 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:231 Error: Not equal: expected: []string{"file1,11,false"} actual : []string(nil) Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=1) { - (string) (len=14) "file1,11,false" -} +([]string) Test: TestWriteFileHandleWriteAt 2025/07/04 03:47:53 ERROR : error listing: directory not found fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Flushing the directory cache 2025/07/04 03:47:55 ERROR : error listing: directory not found fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:298: Flushing the directory cache 2025/07/04 03:47:57 ERROR : error listing: directory not found fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:298: Flushing the directory cache fstest.go:302: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:235 Error: Should be true Test: TestWriteFileHandleWriteAt Messages: listing wrong, want file1 (11) got fstest.go:200: Not found "file1" fstest.go:203: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:203 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:307 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:235 Error: Not equal: expected: 0 actual : 1 Test: TestWriteFileHandleWriteAt Messages: 1 objects not found 2025/07/04 03:48:01 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:01 DEBUG : Looking for writers 2025/07/04 03:48:01 DEBUG : >WaitForWriters: 2025/07/04 03:48:01 ERROR : error listing: directory not found --- FAIL: TestWriteFileHandleWriteAt (10.51s) === RUN TestWriteFileHandleFlush run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:48:01 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:48:01 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:48:01 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:48:02 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:48:02 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:48:02 DEBUG : file1: >Open: fd=file1 (w), err= 2025/07/04 03:48:02 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/07/04 03:48:02 DEBUG : file1: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions 2025/07/04 03:48:02 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:48:02 DEBUG : PikPak root 'rclone-test-gehowin3kahe': File to upload is small (5 bytes), uploading instead of streaming 2025/07/04 03:48:03 ERROR : file1: WriteFileHandle.New Rcat failed: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:03 DEBUG : file1: Remove: 2025/07/04 03:48:03 DEBUG : Added virtual directory entry vDel: "file1" 2025/07/04 03:48:03 DEBUG : file1: >Remove: err= 2025/07/04 03:48:03 ERROR : file1: WriteFileHandle.Flush error: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. write_test.go:256: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:256 Error: Received unexpected error: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. Test: TestWriteFileHandleFlush 2025/07/04 03:48:03 DEBUG : file1: WriteFileHandle.Flush nothing to do dir_test.go:250: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:250 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:267 Error: Not equal: expected: []string{"file1,5,false"} actual : []string(nil) Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=1) { - (string) (len=13) "file1,5,false" -} +([]string) Test: TestWriteFileHandleFlush 2025/07/04 03:48:03 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:03 DEBUG : Looking for writers 2025/07/04 03:48:03 DEBUG : >WaitForWriters: 2025/07/04 03:48:03 ERROR : error listing: directory not found --- FAIL: TestWriteFileHandleFlush (1.57s) === RUN TestWriteFileHandleRelease run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:48:03 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:48:03 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:48:03 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:48:03 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:48:03 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:48:03 DEBUG : file1: >Open: fd=file1 (w), err= 2025/07/04 03:48:03 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/07/04 03:48:03 DEBUG : file1: WriteFileHandle.Release closing 2025/07/04 03:48:03 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:48:03 DEBUG : PikPak root 'rclone-test-gehowin3kahe': File to upload is small (0 bytes), uploading instead of streaming 2025/07/04 03:48:04 ERROR : file1: WriteFileHandle.New Rcat failed: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:04 DEBUG : file1: Remove: 2025/07/04 03:48:04 DEBUG : Added virtual directory entry vDel: "file1" 2025/07/04 03:48:04 DEBUG : file1: >Remove: err= 2025/07/04 03:48:04 ERROR : file1: WriteFileHandle.Release error: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. write_test.go:279: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:279 Error: Received unexpected error: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. Test: TestWriteFileHandleRelease 2025/07/04 03:48:04 DEBUG : file1: WriteFileHandle.Release nothing to do 2025/07/04 03:48:04 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:04 DEBUG : Looking for writers 2025/07/04 03:48:04 DEBUG : >WaitForWriters: 2025/07/04 03:48:05 ERROR : error listing: directory not found --- FAIL: TestWriteFileHandleRelease (1.59s) === RUN TestWriteFileModTimeWithOpenWriters run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:48:05 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:48:05 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:48:05 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:48:05 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:48:05 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:48:05 DEBUG : file1: >Open: fd=file1 (w), err= 2025/07/04 03:48:05 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/07/04 03:48:05 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:48:05 DEBUG : PikPak root 'rclone-test-gehowin3kahe': File to upload is small (2 bytes), uploading instead of streaming 2025/07/04 03:48:06 ERROR : file1: WriteFileHandle.New Rcat failed: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:06 DEBUG : file1: Remove: 2025/07/04 03:48:06 DEBUG : Added virtual directory entry vDel: "file1" 2025/07/04 03:48:06 DEBUG : file1: >Remove: err= write_test.go:333: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:333 Error: Received unexpected error: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. Test: TestWriteFileModTimeWithOpenWriters 2025/07/04 03:48:06 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:06 DEBUG : Looking for writers 2025/07/04 03:48:06 DEBUG : >WaitForWriters: 2025/07/04 03:48:06 ERROR : error listing: directory not found --- FAIL: TestWriteFileModTimeWithOpenWriters (1.56s) === RUN TestFileReadAtZeroLength run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:48:06 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:48:06 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:48:06 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:48:06 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:48:06 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:48:06 DEBUG : file1: >Open: fd=file1 (w), err= 2025/07/04 03:48:06 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/07/04 03:48:06 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:48:06 DEBUG : PikPak root 'rclone-test-gehowin3kahe': File to upload is small (0 bytes), uploading instead of streaming 2025/07/04 03:48:07 ERROR : file1: WriteFileHandle.New Rcat failed: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:07 DEBUG : file1: Remove: 2025/07/04 03:48:07 DEBUG : Added virtual directory entry vDel: "file1" 2025/07/04 03:48:07 DEBUG : file1: >Remove: err= write_test.go:360: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:360 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:380 Error: Received unexpected error: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. Test: TestFileReadAtZeroLength 2025/07/04 03:48:07 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2025/07/04 03:48:07 DEBUG : file1: >OpenFile: fd=, err=file does not exist write_test.go:365: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:365 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:380 Error: Received unexpected error: file does not exist Test: TestFileReadAtZeroLength 2025/07/04 03:48:07 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:07 DEBUG : Looking for writers 2025/07/04 03:48:07 DEBUG : >WaitForWriters: 2025/07/04 03:48:08 ERROR : error listing: directory not found --- FAIL: TestFileReadAtZeroLength (1.57s) === RUN TestFileReadAtNonZeroLength run.go:180: Remote "PikPak root 'rclone-test-gehowin3kahe'", Local "Local file system at /tmp/rclone2072917238", Modify Window "876000h0m0s" 2025/07/04 03:48:08 INFO : PikPak root 'rclone-test-gehowin3kahe': poll-interval is not supported by this remote 2025/07/04 03:48:08 NOTICE: PikPak root 'rclone-test-gehowin3kahe': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:48:08 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:48:08 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:48:08 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:48:08 DEBUG : file1: >Open: fd=file1 (w), err= 2025/07/04 03:48:08 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/07/04 03:48:08 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:48:08 DEBUG : PikPak root 'rclone-test-gehowin3kahe': File to upload is small (100 bytes), uploading instead of streaming 2025/07/04 03:48:09 ERROR : file1: WriteFileHandle.New Rcat failed: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:09 DEBUG : file1: Remove: 2025/07/04 03:48:09 DEBUG : Added virtual directory entry vDel: "file1" 2025/07/04 03:48:09 DEBUG : file1: >Remove: err= write_test.go:360: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:360 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:384 Error: Received unexpected error: failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. Test: TestFileReadAtNonZeroLength 2025/07/04 03:48:09 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2025/07/04 03:48:09 DEBUG : file1: >OpenFile: fd=, err=file does not exist write_test.go:365: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:365 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:384 Error: Received unexpected error: file does not exist Test: TestFileReadAtNonZeroLength 2025/07/04 03:48:09 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:09 DEBUG : Looking for writers 2025/07/04 03:48:09 DEBUG : >WaitForWriters: 2025/07/04 03:48:09 ERROR : error listing: directory not found --- FAIL: TestFileReadAtNonZeroLength (1.58s) FAIL 2025/07/04 03:48:09 DEBUG : PikPak root 'rclone-test-gehowin3kahe': Purge remote 2025/07/04 03:48:10 NOTICE: purge failed: directory not found "./vfs.test -test.v -test.timeout 1h0m0s -remote TestPikPak: -verbose -test.run '^(TestCaseSensitivity|TestDirCreate|TestDirFileOpen|TestDirForgetAll|TestDirForgetPath|TestDirHandleMethods|TestDirHandleReaddir|TestDirHandleReaddirnames|TestDirMetadataExtension|TestDirMethods|TestDirMkdir|TestDirMkdirSub|TestDirOpen|TestDirReadDirAll|TestDirRemove|TestDirRemoveAll|TestDirRemoveName|TestDirRename|TestDirSetModTime|TestDirStat|TestDirWalk|TestFileMethods|TestFileOpen|TestFileOpenRead|TestFileOpenWrite|TestFileReadAtNonZeroLength|TestFileReadAtZeroLength|TestFileRemove|TestFileRemoveAll|TestRWFileHandleFlushRead|TestRWFileHandleMethodsRead|TestRWFileHandleMethodsWrite|TestRWFileHandleReadAt|TestRWFileHandleReleaseRead|TestRWFileHandleSeek|TestRWFileHandleSizeCreateExisting|TestRWFileHandleSizeTruncateExisting|TestRWFileHandleWriteAt|TestRWFileHandleWriteNoWrite|TestRWFileModTimeWithOpenWriters|TestReadFileHandleFlush|TestReadFileHandleMethods|TestReadFileHandleReadAt|TestReadFileHandleRelease|TestReadFileHandleSeek|TestUnicodeNormalization|TestVFSMkdir|TestVFSMkdirAll|TestVFSOpenFile|TestVFSRename|TestVFSStat|TestVFSStatParent|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleRelease|TestWriteFileHandleWriteAt|TestWriteFileModTimeWithOpenWriters)$|^TestFileRename$/^(full,forceCache=false|minimal,forceCache=false|minimal,forceCache=true|off,forceCache=false|writes,forceCache=false|writes,forceCache=true)$|^TestFileSetModTime$/^(cache=full,open=false,write=false|cache=full,open=true,write=false|cache=full,open=true,write=true|cache=off,open=false,write=false|cache=off,open=true,write=false|cache=off,open=true,write=true)$'" - Finished ERROR in 5m56.673179153s (try 4/5): exit status 1: Failed [TestDirHandleMethods TestDirHandleReaddir TestDirHandleReaddirnames TestDirMethods TestDirForgetAll TestDirForgetPath TestDirWalk TestDirSetModTime TestDirStat TestDirReadDirAll TestDirOpen TestDirCreate TestDirMkdir TestDirMkdirSub TestDirRemove TestDirRemoveAll TestDirRemoveName TestDirRename TestDirFileOpen TestDirMetadataExtension TestFileMethods TestFileSetModTime/cache=off,open=false,write=false TestFileSetModTime/cache=off,open=true,write=false TestFileSetModTime/cache=off,open=true,write=true TestFileSetModTime/cache=full,open=false,write=false TestFileSetModTime/cache=full,open=true,write=false TestFileSetModTime/cache=full,open=true,write=true TestFileOpenRead TestFileOpenWrite TestFileRemove TestFileRemoveAll TestFileOpen TestFileRename/off,forceCache=false TestFileRename/minimal,forceCache=false TestFileRename/minimal,forceCache=true TestFileRename/writes,forceCache=false TestFileRename/writes,forceCache=true TestFileRename/full,forceCache=false TestReadFileHandleMethods TestReadFileHandleSeek TestReadFileHandleReadAt TestReadFileHandleFlush TestReadFileHandleRelease TestRWFileHandleMethodsRead TestRWFileHandleSeek TestRWFileHandleReadAt TestRWFileHandleFlushRead TestRWFileHandleReleaseRead TestRWFileHandleMethodsWrite TestRWFileHandleWriteAt TestRWFileHandleWriteNoWrite TestRWFileHandleSizeTruncateExisting TestRWFileHandleSizeCreateExisting TestRWFileModTimeWithOpenWriters TestCaseSensitivity TestUnicodeNormalization TestVFSStat TestVFSStatParent TestVFSOpenFile TestVFSRename TestVFSMkdir TestVFSMkdirAll TestWriteFileHandleMethods TestWriteFileHandleWriteAt TestWriteFileHandleFlush TestWriteFileHandleRelease TestWriteFileModTimeWithOpenWriters TestFileReadAtZeroLength TestFileReadAtNonZeroLength]