"./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 5/5) 2025/07/04 03:48:15 DEBUG : Creating backend with remote "TestPikPak:rclone-test-tunokup2wonu" 2025/07/04 03:48:15 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/07/04 03:48:16 DEBUG : Creating backend with remote "/tmp/rclone3145784039" === RUN TestDirHandleMethods run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:16 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:16 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:17 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:17 DEBUG : Looking for writers 2025/07/04 03:48:17 DEBUG : >WaitForWriters: 2025/07/04 03:48:17 ERROR : error listing: directory not found --- FAIL: TestDirHandleMethods (0.95s) === RUN TestDirHandleReaddir run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:17 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:17 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:18 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:18 DEBUG : Looking for writers 2025/07/04 03:48:18 DEBUG : >WaitForWriters: 2025/07/04 03:48:18 ERROR : error listing: directory not found --- FAIL: TestDirHandleReaddir (0.92s) === RUN TestDirHandleReaddirnames run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:18 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:18 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:19 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:19 DEBUG : Looking for writers 2025/07/04 03:48:19 DEBUG : >WaitForWriters: 2025/07/04 03:48:19 ERROR : error listing: directory not found --- FAIL: TestDirHandleReaddirnames (0.96s) === RUN TestDirMethods run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:19 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:19 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:20 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:20 DEBUG : Looking for writers 2025/07/04 03:48:20 DEBUG : >WaitForWriters: 2025/07/04 03:48:20 ERROR : error listing: directory not found --- FAIL: TestDirMethods (0.92s) === RUN TestDirForgetAll run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:20 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:20 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:21 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:21 DEBUG : Looking for writers 2025/07/04 03:48:21 DEBUG : >WaitForWriters: 2025/07/04 03:48:21 ERROR : error listing: directory not found --- FAIL: TestDirForgetAll (0.99s) === RUN TestDirForgetPath run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:21 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:21 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:22 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:22 DEBUG : Looking for writers 2025/07/04 03:48:22 DEBUG : >WaitForWriters: 2025/07/04 03:48:22 ERROR : error listing: directory not found --- FAIL: TestDirForgetPath (0.93s) === RUN TestDirWalk run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:22 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:22 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:23 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:23 DEBUG : Looking for writers 2025/07/04 03:48:23 DEBUG : >WaitForWriters: 2025/07/04 03:48:23 ERROR : error listing: directory not found --- FAIL: TestDirWalk (0.96s) === RUN TestDirSetModTime run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:23 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:23 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:24 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:24 DEBUG : Looking for writers 2025/07/04 03:48:24 DEBUG : >WaitForWriters: 2025/07/04 03:48:24 ERROR : error listing: directory not found --- FAIL: TestDirSetModTime (1.09s) === RUN TestDirStat run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:24 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:24 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:25 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:25 DEBUG : Looking for writers 2025/07/04 03:48:25 DEBUG : >WaitForWriters: 2025/07/04 03:48:25 ERROR : error listing: directory not found --- FAIL: TestDirStat (0.93s) === RUN TestDirReadDirAll run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:25 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:25 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:26 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:26 DEBUG : Looking for writers 2025/07/04 03:48:26 DEBUG : >WaitForWriters: 2025/07/04 03:48:26 ERROR : error listing: directory not found --- FAIL: TestDirReadDirAll (0.98s) === RUN TestDirOpen run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:26 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:26 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:27 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:27 DEBUG : Looking for writers 2025/07/04 03:48:27 DEBUG : >WaitForWriters: 2025/07/04 03:48:27 ERROR : error listing: directory not found --- FAIL: TestDirOpen (0.97s) === RUN TestDirCreate run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:27 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:27 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:28 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:28 DEBUG : Looking for writers 2025/07/04 03:48:28 DEBUG : >WaitForWriters: 2025/07/04 03:48:28 ERROR : error listing: directory not found --- FAIL: TestDirCreate (0.94s) === RUN TestDirMkdir run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:28 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:28 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:28 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:28 DEBUG : Looking for writers 2025/07/04 03:48:28 DEBUG : >WaitForWriters: 2025/07/04 03:48:29 ERROR : error listing: directory not found --- FAIL: TestDirMkdir (0.93s) === RUN TestDirMkdirSub run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:29 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:29 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:29 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:29 DEBUG : Looking for writers 2025/07/04 03:48:29 DEBUG : >WaitForWriters: 2025/07/04 03:48:30 ERROR : error listing: directory not found --- FAIL: TestDirMkdirSub (0.92s) === RUN TestDirRemove run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:30 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:30 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:30 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:30 DEBUG : Looking for writers 2025/07/04 03:48:30 DEBUG : >WaitForWriters: 2025/07/04 03:48:31 ERROR : error listing: directory not found --- FAIL: TestDirRemove (0.93s) === RUN TestDirRemoveAll run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:31 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:31 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:31 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:31 DEBUG : Looking for writers 2025/07/04 03:48:31 DEBUG : >WaitForWriters: 2025/07/04 03:48:32 ERROR : error listing: directory not found --- FAIL: TestDirRemoveAll (0.95s) === RUN TestDirRemoveName run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:32 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:32 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:32 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:32 DEBUG : Looking for writers 2025/07/04 03:48:32 DEBUG : >WaitForWriters: 2025/07/04 03:48:32 ERROR : error listing: directory not found --- FAIL: TestDirRemoveName (0.94s) === RUN TestDirRename run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:32 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:32 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:33 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:33 DEBUG : Looking for writers 2025/07/04 03:48:33 DEBUG : >WaitForWriters: 2025/07/04 03:48:33 ERROR : error listing: directory not found --- FAIL: TestDirRename (0.94s) === RUN TestDirFileOpen run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:33 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:33 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:34 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:34 DEBUG : Looking for writers 2025/07/04 03:48:34 DEBUG : >WaitForWriters: 2025/07/04 03:48:34 ERROR : error listing: directory not found --- FAIL: TestDirFileOpen (0.93s) === RUN TestDirMetadataExtension run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:34 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:34 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:35 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:35 DEBUG : Looking for writers 2025/07/04 03:48:35 DEBUG : >WaitForWriters: 2025/07/04 03:48:35 ERROR : error listing: directory not found --- FAIL: TestDirMetadataExtension (0.98s) === RUN TestFileMethods run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:35 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:35 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:36 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:36 DEBUG : Looking for writers 2025/07/04 03:48:36 DEBUG : >WaitForWriters: 2025/07/04 03:48:36 ERROR : error listing: directory not found --- FAIL: TestFileMethods (0.92s) === RUN TestFileSetModTime === RUN TestFileSetModTime/cache=off,open=false,write=false run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:36 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:36 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:37 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:37 DEBUG : Looking for writers 2025/07/04 03:48:37 DEBUG : >WaitForWriters: 2025/07/04 03:48:37 ERROR : error listing: directory not found === RUN TestFileSetModTime/cache=off,open=true,write=false run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:37 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:37 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:38 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:38 DEBUG : Looking for writers 2025/07/04 03:48:38 DEBUG : >WaitForWriters: 2025/07/04 03:48:38 ERROR : error listing: directory not found === RUN TestFileSetModTime/cache=off,open=true,write=true run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:38 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:38 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:39 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:39 DEBUG : Looking for writers 2025/07/04 03:48:39 DEBUG : >WaitForWriters: 2025/07/04 03:48:39 ERROR : error listing: directory not found === RUN TestFileSetModTime/cache=full,open=false,write=false run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:39 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:39 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:48:39 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:39 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:39 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:39 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:39 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:39 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:39 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:39 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:39 INFO : PikPak root 'rclone-test-tunokup2wonu': 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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:40 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:40 DEBUG : Looking for writers 2025/07/04 03:48:40 DEBUG : >WaitForWriters: 2025/07/04 03:48:40 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:48:40 ERROR : error listing: directory not found === RUN TestFileSetModTime/cache=full,open=true,write=false run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:40 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:40 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:48:40 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:40 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:40 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:40 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:40 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:40 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:40 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:40 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:40 INFO : PikPak root 'rclone-test-tunokup2wonu': 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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:41 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:41 DEBUG : Looking for writers 2025/07/04 03:48:41 DEBUG : >WaitForWriters: 2025/07/04 03:48:41 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:48:41 ERROR : error listing: directory not found === RUN TestFileSetModTime/cache=full,open=true,write=true run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:41 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:41 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:48:41 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:41 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:41 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:41 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:41 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:41 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:41 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:41 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:41 INFO : PikPak root 'rclone-test-tunokup2wonu': 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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:42 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:42 DEBUG : Looking for writers 2025/07/04 03:48:42 DEBUG : >WaitForWriters: 2025/07/04 03:48:42 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:48:42 ERROR : error listing: directory not found --- FAIL: TestFileSetModTime (5.65s) --- FAIL: TestFileSetModTime/cache=off,open=false,write=false (0.96s) --- FAIL: TestFileSetModTime/cache=off,open=true,write=false (0.93s) --- FAIL: TestFileSetModTime/cache=off,open=true,write=true (0.94s) --- FAIL: TestFileSetModTime/cache=full,open=false,write=false (0.93s) --- FAIL: TestFileSetModTime/cache=full,open=true,write=false (0.93s) --- FAIL: TestFileSetModTime/cache=full,open=true,write=true (0.95s) === RUN TestFileOpenRead run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:42 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:42 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:43 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:43 DEBUG : Looking for writers 2025/07/04 03:48:43 DEBUG : >WaitForWriters: 2025/07/04 03:48:43 ERROR : error listing: directory not found --- FAIL: TestFileOpenRead (0.92s) === RUN TestFileOpenWrite run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:43 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:43 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:43 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:43 DEBUG : Looking for writers 2025/07/04 03:48:43 DEBUG : >WaitForWriters: 2025/07/04 03:48:44 ERROR : error listing: directory not found --- FAIL: TestFileOpenWrite (0.94s) === RUN TestFileRemove run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:44 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:44 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:44 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:44 DEBUG : Looking for writers 2025/07/04 03:48:44 DEBUG : >WaitForWriters: 2025/07/04 03:48:45 ERROR : error listing: directory not found --- FAIL: TestFileRemove (0.93s) === RUN TestFileRemoveAll run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:45 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:45 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:45 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:45 DEBUG : Looking for writers 2025/07/04 03:48:45 DEBUG : >WaitForWriters: 2025/07/04 03:48:46 ERROR : error listing: directory not found --- FAIL: TestFileRemoveAll (0.92s) === RUN TestFileOpen run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:46 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:46 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:46 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:46 DEBUG : Looking for writers 2025/07/04 03:48:46 DEBUG : >WaitForWriters: 2025/07/04 03:48:47 ERROR : error listing: directory not found --- FAIL: TestFileOpen (0.96s) === RUN TestFileRename === RUN TestFileRename/off,forceCache=false run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:47 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:47 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:47 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:47 DEBUG : Looking for writers 2025/07/04 03:48:47 DEBUG : >WaitForWriters: 2025/07/04 03:48:48 ERROR : error listing: directory not found === RUN TestFileRename/minimal,forceCache=false run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:48 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:48 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:48:48 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:48:48 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:48 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:48 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:48 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:48 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:48 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:48 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:48 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:48 INFO : PikPak root 'rclone-test-tunokup2wonu': 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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:48 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:48 DEBUG : Looking for writers 2025/07/04 03:48:48 DEBUG : >WaitForWriters: 2025/07/04 03:48:48 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:48:48 ERROR : error listing: directory not found === RUN TestFileRename/minimal,forceCache=true run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:48 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:48 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:48:48 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:48:48 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:48 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:48 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:48 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:48 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:48 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:48 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:48 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:48 INFO : PikPak root 'rclone-test-tunokup2wonu': 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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:49 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:49 DEBUG : Looking for writers 2025/07/04 03:48:49 DEBUG : >WaitForWriters: 2025/07/04 03:48:49 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:48:49 ERROR : error listing: directory not found === RUN TestFileRename/writes,forceCache=false run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:49 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:49 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:48:49 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:49 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:49 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:49 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:49 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:49 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:49 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:49 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:49 INFO : PikPak root 'rclone-test-tunokup2wonu': 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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:50 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:50 DEBUG : Looking for writers 2025/07/04 03:48:50 DEBUG : >WaitForWriters: 2025/07/04 03:48:50 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:48:50 ERROR : error listing: directory not found === RUN TestFileRename/writes,forceCache=true run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:50 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:50 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:48:50 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:50 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:50 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:50 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:50 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:50 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:50 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:50 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:50 INFO : PikPak root 'rclone-test-tunokup2wonu': 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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:51 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:51 DEBUG : Looking for writers 2025/07/04 03:48:51 DEBUG : >WaitForWriters: 2025/07/04 03:48:51 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:48:51 ERROR : error listing: directory not found === RUN TestFileRename/full,forceCache=false run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:51 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:51 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:48:51 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:51 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:51 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:51 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:51 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:51 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:51 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:51 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:51 INFO : PikPak root 'rclone-test-tunokup2wonu': 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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:52 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:52 DEBUG : Looking for writers 2025/07/04 03:48:52 DEBUG : >WaitForWriters: 2025/07/04 03:48:52 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:48:52 ERROR : error listing: directory not found --- FAIL: TestFileRename (5.70s) --- FAIL: TestFileRename/off,forceCache=false (0.93s) --- FAIL: TestFileRename/minimal,forceCache=false (0.96s) --- FAIL: TestFileRename/minimal,forceCache=true (0.95s) --- FAIL: TestFileRename/writes,forceCache=false (0.96s) --- FAIL: TestFileRename/writes,forceCache=true (0.94s) --- FAIL: TestFileRename/full,forceCache=false (0.95s) === RUN TestReadFileHandleMethods run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:52 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:52 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:53 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:53 DEBUG : Looking for writers 2025/07/04 03:48:53 DEBUG : >WaitForWriters: 2025/07/04 03:48:53 ERROR : error listing: directory not found --- FAIL: TestReadFileHandleMethods (0.95s) === RUN TestReadFileHandleSeek run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:53 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:53 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:54 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:54 DEBUG : Looking for writers 2025/07/04 03:48:54 DEBUG : >WaitForWriters: 2025/07/04 03:48:54 ERROR : error listing: directory not found --- FAIL: TestReadFileHandleSeek (0.92s) === RUN TestReadFileHandleReadAt run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:54 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:54 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:55 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:55 DEBUG : Looking for writers 2025/07/04 03:48:55 DEBUG : >WaitForWriters: 2025/07/04 03:48:55 ERROR : error listing: directory not found --- FAIL: TestReadFileHandleReadAt (0.94s) === RUN TestReadFileHandleFlush run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:55 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:55 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:56 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:56 DEBUG : Looking for writers 2025/07/04 03:48:56 DEBUG : >WaitForWriters: 2025/07/04 03:48:56 ERROR : error listing: directory not found --- FAIL: TestReadFileHandleFlush (0.94s) === RUN TestReadFileHandleRelease run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:56 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:56 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:57 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:57 DEBUG : Looking for writers 2025/07/04 03:48:57 DEBUG : >WaitForWriters: 2025/07/04 03:48:57 ERROR : error listing: directory not found --- FAIL: TestReadFileHandleRelease (0.97s) === RUN TestRWFileHandleMethodsRead run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:57 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:57 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:48:57 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:57 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:57 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:57 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:57 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:57 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:57 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:57 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:57 INFO : PikPak root 'rclone-test-tunokup2wonu': 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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:58 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:58 DEBUG : Looking for writers 2025/07/04 03:48:58 DEBUG : >WaitForWriters: 2025/07/04 03:48:58 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:48:58 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleMethodsRead (0.94s) === RUN TestRWFileHandleSeek run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:58 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:58 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:48:58 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:58 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:58 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:58 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:58 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:58 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:58 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:58 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:58 INFO : PikPak root 'rclone-test-tunokup2wonu': 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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:48:59 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:48:59 DEBUG : Looking for writers 2025/07/04 03:48:59 DEBUG : >WaitForWriters: 2025/07/04 03:48:59 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:48:59 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleSeek (0.96s) === RUN TestRWFileHandleReadAt run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:48:59 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:48:59 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:48:59 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:59 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:59 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:59 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:59 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:59 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:59 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:48:59 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:48:59 INFO : PikPak root 'rclone-test-tunokup2wonu': 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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:49:00 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:49:00 DEBUG : Looking for writers 2025/07/04 03:49:00 DEBUG : >WaitForWriters: 2025/07/04 03:49:00 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:49:00 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleReadAt (0.93s) === RUN TestRWFileHandleFlushRead run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:49:00 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:49:00 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:49:00 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:49:00 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:49:00 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:49:00 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:49:00 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:49:00 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:49:00 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:49:00 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:49:00 INFO : PikPak root 'rclone-test-tunokup2wonu': 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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:49:00 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:49:00 DEBUG : Looking for writers 2025/07/04 03:49:00 DEBUG : >WaitForWriters: 2025/07/04 03:49:00 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:49:01 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleFlushRead (0.93s) === RUN TestRWFileHandleReleaseRead run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:49:01 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:49:01 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:49:01 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:49:01 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:49:01 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:49:01 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:49:01 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:49:01 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:49:01 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:49:01 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:49:01 INFO : PikPak root 'rclone-test-tunokup2wonu': 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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:49:01 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:49:01 DEBUG : Looking for writers 2025/07/04 03:49:01 DEBUG : >WaitForWriters: 2025/07/04 03:49:01 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:49:02 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleReleaseRead (0.94s) === RUN TestRWFileHandleMethodsWrite run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:49:02 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:49:02 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:49:02 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:49:02 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:49:02 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:49:02 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:49:02 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:49:02 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:49:02 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:49:02 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:49:02 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:49:02 INFO : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2025/07/04 03:49:02 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:49:02 DEBUG : file1: newRWFileHandle: 2025/07/04 03:49:02 DEBUG : file1(0xc00053d580): openPending: 2025/07/04 03:49:02 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2025/07/04 03:49:02 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:49:02 DEBUG : file1(0xc00053d580): >openPending: err= 2025/07/04 03:49:02 DEBUG : file1: >newRWFileHandle: err= 2025/07/04 03:49:02 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:49:02 DEBUG : file1: >Open: fd=file1 (rw), err= 2025/07/04 03:49:02 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2025/07/04 03:49:02 DEBUG : file1(0xc00053d580): _writeAt: size=5, off=0 2025/07/04 03:49:02 DEBUG : file1(0xc00053d580): >_writeAt: n=5, err= 2025/07/04 03:49:02 DEBUG : file1(0xc00053d580): _writeAt: size=7, off=5 2025/07/04 03:49:02 DEBUG : file1(0xc00053d580): >_writeAt: n=7, err= 2025/07/04 03:49:02 DEBUG : file1: vfs cache: truncate to size=11 2025/07/04 03:49:02 DEBUG : file1(0xc00053d580): close: 2025/07/04 03:49:02 DEBUG : file1: vfs cache: setting modification time to 2025-07-04 03:49:02.483736369 +0000 UTC m=+47.341091218 2025/07/04 03:49:02 INFO : file1: vfs cache: queuing for upload in 100ms 2025/07/04 03:49:02 DEBUG : file1(0xc00053d580): >close: err= 2025/07/04 03:49:02 DEBUG : file1(0xc00053d580): close: 2025/07/04 03:49:02 DEBUG : file1(0xc00053d580): >close: err=file already closed 2025/07/04 03:49:02 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:49:02 DEBUG : Looking for writers 2025/07/04 03:49:02 DEBUG : file1: reading active writers 2025/07/04 03:49:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2025/07/04 03:49:02 DEBUG : Looking for writers 2025/07/04 03:49:02 DEBUG : file1: reading active writers 2025/07/04 03:49:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2025/07/04 03:49:02 DEBUG : Looking for writers 2025/07/04 03:49:02 DEBUG : file1: reading active writers 2025/07/04 03:49:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2025/07/04 03:49:02 DEBUG : Looking for writers 2025/07/04 03:49:02 DEBUG : file1: reading active writers 2025/07/04 03:49:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2025/07/04 03:49:02 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:49:02 DEBUG : Looking for writers 2025/07/04 03:49:02 DEBUG : file1: reading active writers 2025/07/04 03:49:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2025/07/04 03:49:02 DEBUG : Looking for writers 2025/07/04 03:49:02 DEBUG : file1: reading active writers 2025/07/04 03:49:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2025/07/04 03:49:03 DEBUG : Looking for writers 2025/07/04 03:49:03 DEBUG : file1: reading active writers 2025/07/04 03:49:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2025/07/04 03:49: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:49:03 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:49:03 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:49:03 DEBUG : Looking for writers 2025/07/04 03:49:03 DEBUG : file1: reading active writers 2025/07/04 03:49:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:04 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:49:04 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:49:04 DEBUG : Looking for writers 2025/07/04 03:49:04 DEBUG : file1: reading active writers 2025/07/04 03:49:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:05 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:49:05 DEBUG : Looking for writers 2025/07/04 03:49:05 DEBUG : file1: reading active writers 2025/07/04 03:49:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:06 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:49:06 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:49:06 DEBUG : Looking for writers 2025/07/04 03:49:06 DEBUG : file1: reading active writers 2025/07/04 03:49:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:06 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:49:07 DEBUG : Looking for writers 2025/07/04 03:49:07 DEBUG : file1: reading active writers 2025/07/04 03:49:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49: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:49: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:49:08 DEBUG : Looking for writers 2025/07/04 03:49:08 DEBUG : file1: reading active writers 2025/07/04 03:49:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:09 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:49:09 DEBUG : Looking for writers 2025/07/04 03:49:09 DEBUG : file1: reading active writers 2025/07/04 03:49:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49: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:49:10 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:49:10 DEBUG : Looking for writers 2025/07/04 03:49:10 DEBUG : file1: reading active writers 2025/07/04 03:49:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:11 DEBUG : Looking for writers 2025/07/04 03:49:11 DEBUG : file1: reading active writers 2025/07/04 03:49:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:12 DEBUG : Looking for writers 2025/07/04 03:49:12 DEBUG : file1: reading active writers 2025/07/04 03:49:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:13 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:49:13 DEBUG : Looking for writers 2025/07/04 03:49:13 DEBUG : file1: reading active writers 2025/07/04 03:49:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:14 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:49:14 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:49:14 DEBUG : Looking for writers 2025/07/04 03:49:14 DEBUG : file1: reading active writers 2025/07/04 03:49:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:15 DEBUG : Looking for writers 2025/07/04 03:49:15 DEBUG : file1: reading active writers 2025/07/04 03:49:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:16 DEBUG : Looking for writers 2025/07/04 03:49:16 DEBUG : file1: reading active writers 2025/07/04 03:49:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:17 DEBUG : Looking for writers 2025/07/04 03:49:17 DEBUG : file1: reading active writers 2025/07/04 03:49:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:18 DEBUG : Looking for writers 2025/07/04 03:49:18 DEBUG : file1: reading active writers 2025/07/04 03:49:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:19 DEBUG : Looking for writers 2025/07/04 03:49:19 DEBUG : file1: reading active writers 2025/07/04 03:49:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:20 DEBUG : Looking for writers 2025/07/04 03:49:20 DEBUG : file1: reading active writers 2025/07/04 03:49:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:21 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:49:21 DEBUG : Looking for writers 2025/07/04 03:49:21 DEBUG : file1: reading active writers 2025/07/04 03:49:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49: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:49: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:49:22 DEBUG : Looking for writers 2025/07/04 03:49:22 DEBUG : file1: reading active writers 2025/07/04 03:49:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:23 DEBUG : Looking for writers 2025/07/04 03:49:23 DEBUG : file1: reading active writers 2025/07/04 03:49:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:24 DEBUG : Looking for writers 2025/07/04 03:49:24 DEBUG : file1: reading active writers 2025/07/04 03:49:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:25 DEBUG : Looking for writers 2025/07/04 03:49:25 DEBUG : file1: reading active writers 2025/07/04 03:49:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:26 DEBUG : Looking for writers 2025/07/04 03:49:26 DEBUG : file1: reading active writers 2025/07/04 03:49:26 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:27 DEBUG : Looking for writers 2025/07/04 03:49:27 DEBUG : file1: reading active writers 2025/07/04 03:49:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:28 DEBUG : Looking for writers 2025/07/04 03:49:28 DEBUG : file1: reading active writers 2025/07/04 03:49:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:29 DEBUG : Looking for writers 2025/07/04 03:49:29 DEBUG : file1: reading active writers 2025/07/04 03:49:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:30 DEBUG : Looking for writers 2025/07/04 03:49:30 DEBUG : file1: reading active writers 2025/07/04 03:49:30 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:31 DEBUG : Looking for writers 2025/07/04 03:49:31 DEBUG : file1: reading active writers 2025/07/04 03:49:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:32 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc00074d860 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc000996008 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824643772480} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13984224037335022385 ext:47341091218 loc:0x3fe46e0} ATime:{wall:13984224037335055557 ext:47341124390 loc:0x3fe46e0} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2025/07/04 03:49:32 DEBUG : >WaitForWriters: 2025/07/04 03:49:32 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:49:34 ERROR : error listing: directory not found fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 2025/07/04 03:49:34 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:49:35 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:49:35 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:49:36 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:49:40 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:49:40 DEBUG : Looking for writers 2025/07/04 03:49:40 DEBUG : file1: reading active writers 2025/07/04 03:49:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2025/07/04 03:49:40 DEBUG : Looking for writers 2025/07/04 03:49:40 DEBUG : file1: reading active writers 2025/07/04 03:49:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2025/07/04 03:49:40 DEBUG : Looking for writers 2025/07/04 03:49:40 DEBUG : file1: reading active writers 2025/07/04 03:49:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2025/07/04 03:49:40 DEBUG : Looking for writers 2025/07/04 03:49:40 DEBUG : file1: reading active writers 2025/07/04 03:49:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2025/07/04 03:49:40 DEBUG : Looking for writers 2025/07/04 03:49:40 DEBUG : file1: reading active writers 2025/07/04 03:49:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2025/07/04 03:49:40 DEBUG : Looking for writers 2025/07/04 03:49:40 DEBUG : file1: reading active writers 2025/07/04 03:49:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2025/07/04 03:49:41 DEBUG : Looking for writers 2025/07/04 03:49:41 DEBUG : file1: reading active writers 2025/07/04 03:49:41 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2025/07/04 03:49:41 DEBUG : Looking for writers 2025/07/04 03:49:41 DEBUG : file1: reading active writers 2025/07/04 03:49:41 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:42 DEBUG : Looking for writers 2025/07/04 03:49:42 DEBUG : file1: reading active writers 2025/07/04 03:49:42 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:43 DEBUG : Looking for writers 2025/07/04 03:49:43 DEBUG : file1: reading active writers 2025/07/04 03:49:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:44 DEBUG : Looking for writers 2025/07/04 03:49:44 DEBUG : file1: reading active writers 2025/07/04 03:49:44 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:45 DEBUG : Looking for writers 2025/07/04 03:49:45 DEBUG : file1: reading active writers 2025/07/04 03:49:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:46 DEBUG : Looking for writers 2025/07/04 03:49:46 DEBUG : file1: reading active writers 2025/07/04 03:49:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:47 DEBUG : Looking for writers 2025/07/04 03:49:47 DEBUG : file1: reading active writers 2025/07/04 03:49:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:48 DEBUG : Looking for writers 2025/07/04 03:49:48 DEBUG : file1: reading active writers 2025/07/04 03:49:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:49 DEBUG : Looking for writers 2025/07/04 03:49:49 DEBUG : file1: reading active writers 2025/07/04 03:49:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:50 DEBUG : Looking for writers 2025/07/04 03:49:50 DEBUG : file1: reading active writers 2025/07/04 03:49:50 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:51 DEBUG : Looking for writers 2025/07/04 03:49:51 DEBUG : file1: reading active writers 2025/07/04 03:49:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:52 DEBUG : Looking for writers 2025/07/04 03:49:52 DEBUG : file1: reading active writers 2025/07/04 03:49:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:53 DEBUG : Looking for writers 2025/07/04 03:49:53 DEBUG : file1: reading active writers 2025/07/04 03:49:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:54 DEBUG : Looking for writers 2025/07/04 03:49:54 DEBUG : file1: reading active writers 2025/07/04 03:49:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:55 DEBUG : Looking for writers 2025/07/04 03:49:55 DEBUG : file1: reading active writers 2025/07/04 03:49:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:56 DEBUG : Looking for writers 2025/07/04 03:49:56 DEBUG : file1: reading active writers 2025/07/04 03:49:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:57 DEBUG : Looking for writers 2025/07/04 03:49:57 DEBUG : file1: reading active writers 2025/07/04 03:49:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:58 DEBUG : Looking for writers 2025/07/04 03:49:58 DEBUG : file1: reading active writers 2025/07/04 03:49:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:49:59 DEBUG : Looking for writers 2025/07/04 03:49:59 DEBUG : file1: reading active writers 2025/07/04 03:49:59 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:00 DEBUG : Looking for writers 2025/07/04 03:50:00 DEBUG : file1: reading active writers 2025/07/04 03:50:00 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:01 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:50:01 DEBUG : Looking for writers 2025/07/04 03:50:01 DEBUG : file1: reading active writers 2025/07/04 03:50:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:02 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2025/07/04 03:50:02 INFO : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 0, uploading 1, total size 11 (was 11) 2025/07/04 03:50: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:50:02 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:50:02 DEBUG : Looking for writers 2025/07/04 03:50:02 DEBUG : file1: reading active writers 2025/07/04 03:50:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:03 DEBUG : Looking for writers 2025/07/04 03:50:03 DEBUG : file1: reading active writers 2025/07/04 03:50:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:04 DEBUG : Looking for writers 2025/07/04 03:50:04 DEBUG : file1: reading active writers 2025/07/04 03:50:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:05 DEBUG : Looking for writers 2025/07/04 03:50:05 DEBUG : file1: reading active writers 2025/07/04 03:50:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:06 DEBUG : Looking for writers 2025/07/04 03:50:06 DEBUG : file1: reading active writers 2025/07/04 03:50:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:07 DEBUG : Looking for writers 2025/07/04 03:50:07 DEBUG : file1: reading active writers 2025/07/04 03:50:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:08 DEBUG : Looking for writers 2025/07/04 03:50:08 DEBUG : file1: reading active writers 2025/07/04 03:50:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:09 DEBUG : Looking for writers 2025/07/04 03:50:09 DEBUG : file1: reading active writers 2025/07/04 03:50:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:10 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc00074d860 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc000996008 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824643772480} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13984224037335022385 ext:47341091218 loc:0x3fe46e0} ATime:{wall:13984224037335055557 ext:47341124390 loc:0x3fe46e0} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2025/07/04 03:50:10 DEBUG : >WaitForWriters: 2025/07/04 03:50:10 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:50:10 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleMethodsWrite (68.59s) === RUN TestRWFileHandleWriteAt run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:50:10 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:50:10 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:50:10 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:50:10 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:50:10 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:50:10 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:50:10 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:50:10 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:50:10 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:50:10 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:50:10 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:50:10 INFO : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2025/07/04 03:50:11 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:50:11 DEBUG : file1: newRWFileHandle: 2025/07/04 03:50:11 DEBUG : file1(0xc0002d1c80): openPending: 2025/07/04 03:50:11 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2025/07/04 03:50:11 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:50:11 DEBUG : file1(0xc0002d1c80): >openPending: err= 2025/07/04 03:50:11 DEBUG : file1: >newRWFileHandle: err= 2025/07/04 03:50:11 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:50:11 DEBUG : file1: >Open: fd=file1 (rw), err= 2025/07/04 03:50:11 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2025/07/04 03:50:11 DEBUG : file1(0xc0002d1c80): _writeAt: size=7, off=0 2025/07/04 03:50:11 DEBUG : file1(0xc0002d1c80): >_writeAt: n=7, err= 2025/07/04 03:50:11 DEBUG : file1(0xc0002d1c80): _writeAt: size=6, off=5 2025/07/04 03:50:11 DEBUG : file1(0xc0002d1c80): >_writeAt: n=6, err= 2025/07/04 03:50:11 DEBUG : file1(0xc0002d1c80): close: 2025/07/04 03:50:11 DEBUG : file1: vfs cache: setting modification time to 2025-07-04 03:50:11.068103181 +0000 UTC m=+115.925458040 2025/07/04 03:50:11 INFO : file1: vfs cache: queuing for upload in 100ms 2025/07/04 03:50:11 DEBUG : file1(0xc0002d1c80): >close: err= 2025/07/04 03:50:11 DEBUG : file1(0xc0002d1c80): _writeAt: size=5, off=0 2025/07/04 03:50:11 DEBUG : file1(0xc0002d1c80): >_writeAt: n=0, err=file already closed 2025/07/04 03:50:11 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:50:11 DEBUG : Looking for writers 2025/07/04 03:50:11 DEBUG : file1: reading active writers 2025/07/04 03:50:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2025/07/04 03:50:11 DEBUG : Looking for writers 2025/07/04 03:50:11 DEBUG : file1: reading active writers 2025/07/04 03:50:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2025/07/04 03:50:11 DEBUG : Looking for writers 2025/07/04 03:50:11 DEBUG : file1: reading active writers 2025/07/04 03:50:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2025/07/04 03:50:11 DEBUG : Looking for writers 2025/07/04 03:50:11 DEBUG : file1: reading active writers 2025/07/04 03:50:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2025/07/04 03:50:11 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:50:11 DEBUG : Looking for writers 2025/07/04 03:50:11 DEBUG : file1: reading active writers 2025/07/04 03:50:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2025/07/04 03:50:11 DEBUG : Looking for writers 2025/07/04 03:50:11 DEBUG : file1: reading active writers 2025/07/04 03:50:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2025/07/04 03:50:11 DEBUG : Looking for writers 2025/07/04 03:50:11 DEBUG : file1: reading active writers 2025/07/04 03:50:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2025/07/04 03:50: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:50:12 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:50:12 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:50:12 DEBUG : Looking for writers 2025/07/04 03:50:12 DEBUG : file1: reading active writers 2025/07/04 03:50:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50: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:50:13 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:50:13 DEBUG : Looking for writers 2025/07/04 03:50:13 DEBUG : file1: reading active writers 2025/07/04 03:50:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:13 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:50:14 DEBUG : Looking for writers 2025/07/04 03:50:14 DEBUG : file1: reading active writers 2025/07/04 03:50:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:14 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:50:14 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:50:15 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:50:15 DEBUG : Looking for writers 2025/07/04 03:50:15 DEBUG : file1: reading active writers 2025/07/04 03:50:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:16 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:50:16 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:50:16 DEBUG : Looking for writers 2025/07/04 03:50:16 DEBUG : file1: reading active writers 2025/07/04 03:50:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:17 DEBUG : Looking for writers 2025/07/04 03:50:17 DEBUG : file1: reading active writers 2025/07/04 03:50:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:17 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:50:18 DEBUG : Looking for writers 2025/07/04 03:50:18 DEBUG : file1: reading active writers 2025/07/04 03:50:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50: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:50: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:50:19 DEBUG : Looking for writers 2025/07/04 03:50:19 DEBUG : file1: reading active writers 2025/07/04 03:50:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:20 DEBUG : Looking for writers 2025/07/04 03:50:20 DEBUG : file1: reading active writers 2025/07/04 03:50:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:21 DEBUG : Looking for writers 2025/07/04 03:50:21 DEBUG : file1: reading active writers 2025/07/04 03:50:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:22 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:50:22 DEBUG : Looking for writers 2025/07/04 03:50:22 DEBUG : file1: reading active writers 2025/07/04 03:50:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50: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:50: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:50:23 DEBUG : Looking for writers 2025/07/04 03:50:23 DEBUG : file1: reading active writers 2025/07/04 03:50:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:24 DEBUG : Looking for writers 2025/07/04 03:50:24 DEBUG : file1: reading active writers 2025/07/04 03:50:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:25 DEBUG : Looking for writers 2025/07/04 03:50:25 DEBUG : file1: reading active writers 2025/07/04 03:50:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:26 DEBUG : Looking for writers 2025/07/04 03:50:26 DEBUG : file1: reading active writers 2025/07/04 03:50:26 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:27 DEBUG : Looking for writers 2025/07/04 03:50:27 DEBUG : file1: reading active writers 2025/07/04 03:50:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:28 DEBUG : Looking for writers 2025/07/04 03:50:28 DEBUG : file1: reading active writers 2025/07/04 03:50:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:29 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:50:29 DEBUG : Looking for writers 2025/07/04 03:50:29 DEBUG : file1: reading active writers 2025/07/04 03:50:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:30 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:50:30 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:50:30 DEBUG : Looking for writers 2025/07/04 03:50:30 DEBUG : file1: reading active writers 2025/07/04 03:50:30 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:31 DEBUG : Looking for writers 2025/07/04 03:50:31 DEBUG : file1: reading active writers 2025/07/04 03:50:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:32 DEBUG : Looking for writers 2025/07/04 03:50:32 DEBUG : file1: reading active writers 2025/07/04 03:50:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:33 DEBUG : Looking for writers 2025/07/04 03:50:33 DEBUG : file1: reading active writers 2025/07/04 03:50:33 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:34 DEBUG : Looking for writers 2025/07/04 03:50:34 DEBUG : file1: reading active writers 2025/07/04 03:50:34 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:35 DEBUG : Looking for writers 2025/07/04 03:50:35 DEBUG : file1: reading active writers 2025/07/04 03:50:35 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:36 DEBUG : Looking for writers 2025/07/04 03:50:36 DEBUG : file1: reading active writers 2025/07/04 03:50:36 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:37 DEBUG : Looking for writers 2025/07/04 03:50:37 DEBUG : file1: reading active writers 2025/07/04 03:50:37 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:38 DEBUG : Looking for writers 2025/07/04 03:50:38 DEBUG : file1: reading active writers 2025/07/04 03:50:38 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:39 DEBUG : Looking for writers 2025/07/04 03:50:39 DEBUG : file1: reading active writers 2025/07/04 03:50:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:40 DEBUG : Looking for writers 2025/07/04 03:50:40 DEBUG : file1: reading active writers 2025/07/04 03:50:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:41 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc00079d2c0 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc00055c108 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824639340864} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13984224111007575053 ext:115925458040 loc:0x3fe46e0} ATime:{wall:13984224111007610068 ext:115925493055 loc:0x3fe46e0} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2025/07/04 03:50:41 DEBUG : >WaitForWriters: 2025/07/04 03:50:41 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:50:42 ERROR : error listing: directory not found fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 2025/07/04 03:50:43 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:50:44 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:50:44 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:50:45 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:50:49 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:50:49 DEBUG : Looking for writers 2025/07/04 03:50:49 DEBUG : file1: reading active writers 2025/07/04 03:50:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2025/07/04 03:50:49 DEBUG : Looking for writers 2025/07/04 03:50:49 DEBUG : file1: reading active writers 2025/07/04 03:50:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2025/07/04 03:50:49 DEBUG : Looking for writers 2025/07/04 03:50:49 DEBUG : file1: reading active writers 2025/07/04 03:50:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2025/07/04 03:50:49 DEBUG : Looking for writers 2025/07/04 03:50:49 DEBUG : file1: reading active writers 2025/07/04 03:50:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2025/07/04 03:50:49 DEBUG : Looking for writers 2025/07/04 03:50:49 DEBUG : file1: reading active writers 2025/07/04 03:50:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2025/07/04 03:50:49 DEBUG : Looking for writers 2025/07/04 03:50:49 DEBUG : file1: reading active writers 2025/07/04 03:50:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2025/07/04 03:50:49 DEBUG : Looking for writers 2025/07/04 03:50:49 DEBUG : file1: reading active writers 2025/07/04 03:50:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2025/07/04 03:50:50 DEBUG : Looking for writers 2025/07/04 03:50:50 DEBUG : file1: reading active writers 2025/07/04 03:50:50 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:51 DEBUG : Looking for writers 2025/07/04 03:50:51 DEBUG : file1: reading active writers 2025/07/04 03:50:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:52 DEBUG : Looking for writers 2025/07/04 03:50:52 DEBUG : file1: reading active writers 2025/07/04 03:50:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:53 DEBUG : Looking for writers 2025/07/04 03:50:53 DEBUG : file1: reading active writers 2025/07/04 03:50:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:54 DEBUG : Looking for writers 2025/07/04 03:50:54 DEBUG : file1: reading active writers 2025/07/04 03:50:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:55 DEBUG : Looking for writers 2025/07/04 03:50:55 DEBUG : file1: reading active writers 2025/07/04 03:50:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:56 DEBUG : Looking for writers 2025/07/04 03:50:56 DEBUG : file1: reading active writers 2025/07/04 03:50:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:57 DEBUG : Looking for writers 2025/07/04 03:50:57 DEBUG : file1: reading active writers 2025/07/04 03:50:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:58 DEBUG : Looking for writers 2025/07/04 03:50:58 DEBUG : file1: reading active writers 2025/07/04 03:50:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:50:59 DEBUG : Looking for writers 2025/07/04 03:50:59 DEBUG : file1: reading active writers 2025/07/04 03:50:59 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:00 DEBUG : Looking for writers 2025/07/04 03:51:00 DEBUG : file1: reading active writers 2025/07/04 03:51:00 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:01 DEBUG : Looking for writers 2025/07/04 03:51:01 DEBUG : file1: reading active writers 2025/07/04 03:51:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:02 DEBUG : Looking for writers 2025/07/04 03:51:02 DEBUG : file1: reading active writers 2025/07/04 03:51:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:03 DEBUG : Looking for writers 2025/07/04 03:51:03 DEBUG : file1: reading active writers 2025/07/04 03:51:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:04 DEBUG : Looking for writers 2025/07/04 03:51:04 DEBUG : file1: reading active writers 2025/07/04 03:51:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:05 DEBUG : Looking for writers 2025/07/04 03:51:05 DEBUG : file1: reading active writers 2025/07/04 03:51:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:06 DEBUG : Looking for writers 2025/07/04 03:51:06 DEBUG : file1: reading active writers 2025/07/04 03:51:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:07 DEBUG : Looking for writers 2025/07/04 03:51:07 DEBUG : file1: reading active writers 2025/07/04 03:51:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:08 DEBUG : Looking for writers 2025/07/04 03:51:08 DEBUG : file1: reading active writers 2025/07/04 03:51:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:09 DEBUG : Looking for writers 2025/07/04 03:51:09 DEBUG : file1: reading active writers 2025/07/04 03:51:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:09 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:51:10 DEBUG : Looking for writers 2025/07/04 03:51:10 DEBUG : file1: reading active writers 2025/07/04 03:51:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51: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:51: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:51:10 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2025/07/04 03:51:10 INFO : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 1, uploading 0, total size 11 (was 11) 2025/07/04 03:51:11 DEBUG : Looking for writers 2025/07/04 03:51:11 DEBUG : file1: reading active writers 2025/07/04 03:51:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:12 DEBUG : Looking for writers 2025/07/04 03:51:12 DEBUG : file1: reading active writers 2025/07/04 03:51:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:13 DEBUG : Looking for writers 2025/07/04 03:51:13 DEBUG : file1: reading active writers 2025/07/04 03:51:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:14 DEBUG : Looking for writers 2025/07/04 03:51:14 DEBUG : file1: reading active writers 2025/07/04 03:51:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:15 DEBUG : Looking for writers 2025/07/04 03:51:15 DEBUG : file1: reading active writers 2025/07/04 03:51:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:16 DEBUG : Looking for writers 2025/07/04 03:51:16 DEBUG : file1: reading active writers 2025/07/04 03:51:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:17 DEBUG : Looking for writers 2025/07/04 03:51:17 DEBUG : file1: reading active writers 2025/07/04 03:51:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:18 DEBUG : Looking for writers 2025/07/04 03:51:18 DEBUG : file1: reading active writers 2025/07/04 03:51:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:51:19 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc00079d2c0 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc00055c108 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824639340864} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13984224111007575053 ext:115925458040 loc:0x3fe46e0} ATime:{wall:13984224111007610068 ext:115925493055 loc:0x3fe46e0} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2025/07/04 03:51:19 DEBUG : >WaitForWriters: 2025/07/04 03:51:19 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:51:19 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleWriteAt (68.57s) === RUN TestRWFileHandleWriteNoWrite run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:51:19 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:51:19 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:51:19 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:51:19 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:51:19 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:51:19 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:51:19 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:51:19 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:51:19 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:51:19 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:51:19 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:51:19 INFO : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2025/07/04 03:51:19 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:51:19 DEBUG : file1: newRWFileHandle: 2025/07/04 03:51:19 DEBUG : file1(0xc0009b0100): openPending: 2025/07/04 03:51:19 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2025/07/04 03:51:19 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:51:19 DEBUG : file1(0xc0009b0100): >openPending: err= 2025/07/04 03:51:19 DEBUG : file1: >newRWFileHandle: err= 2025/07/04 03:51:19 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:51:19 DEBUG : file1: >Open: fd=file1 (rw), err= 2025/07/04 03:51:19 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2025/07/04 03:51:19 DEBUG : file1(0xc0009b0100): close: 2025/07/04 03:51:19 DEBUG : file1: vfs cache: setting modification time to 2025-07-04 03:51:19.639371022 +0000 UTC m=+184.496725881 2025/07/04 03:51:19 INFO : file1: vfs cache: queuing for upload in 100ms 2025/07/04 03:51:19 DEBUG : file1(0xc0009b0100): >close: err= 2025/07/04 03:51:19 DEBUG : file2: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx 2025/07/04 03:51:19 DEBUG : file2: Open: flags=O_WRONLY|O_CREATE|O_TRUNC 2025/07/04 03:51:19 DEBUG : file2: newRWFileHandle: 2025/07/04 03:51:19 DEBUG : file2(0xc0009b05c0): openPending: 2025/07/04 03:51:19 DEBUG : file2: vfs cache: truncate to size=0 (not needed as size correct) 2025/07/04 03:51:19 DEBUG : Added virtual directory entry vAddFile: "file2" 2025/07/04 03:51:19 DEBUG : file2(0xc0009b05c0): >openPending: err= 2025/07/04 03:51:19 DEBUG : file2: >newRWFileHandle: err= 2025/07/04 03:51:19 DEBUG : Added virtual directory entry vAddFile: "file2" 2025/07/04 03:51:19 DEBUG : file2: >Open: fd=file2 (rw), err= 2025/07/04 03:51:19 DEBUG : file2: >OpenFile: fd=file2 (rw), err= 2025/07/04 03:51:19 DEBUG : file2(0xc0009b05c0): RWFileHandle.Flush 2025/07/04 03:51:19 DEBUG : file2(0xc0009b05c0): RWFileHandle.Release 2025/07/04 03:51:19 DEBUG : file2(0xc0009b05c0): close: 2025/07/04 03:51:19 DEBUG : file2: vfs cache: setting modification time to 2025-07-04 03:51:19.641869199 +0000 UTC m=+184.499224059 2025/07/04 03:51:19 INFO : file2: vfs cache: queuing for upload in 100ms 2025/07/04 03:51:19 DEBUG : file2(0xc0009b05c0): >close: err= 2025/07/04 03:51:19 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:51:19 DEBUG : Looking for writers 2025/07/04 03:51:19 DEBUG : file1: reading active writers 2025/07/04 03:51:19 DEBUG : file2: reading active writers 2025/07/04 03:51:19 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms 2025/07/04 03:51:19 DEBUG : Looking for writers 2025/07/04 03:51:19 DEBUG : file1: reading active writers 2025/07/04 03:51:19 DEBUG : file2: reading active writers 2025/07/04 03:51:19 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms 2025/07/04 03:51:19 DEBUG : Looking for writers 2025/07/04 03:51:19 DEBUG : file1: reading active writers 2025/07/04 03:51:19 DEBUG : file2: reading active writers 2025/07/04 03:51:19 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms 2025/07/04 03:51:19 DEBUG : Looking for writers 2025/07/04 03:51:19 DEBUG : file1: reading active writers 2025/07/04 03:51:19 DEBUG : file2: reading active writers 2025/07/04 03:51:19 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms 2025/07/04 03:51:19 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:51:19 DEBUG : file2: vfs cache: starting upload 2025/07/04 03:51:19 DEBUG : Looking for writers 2025/07/04 03:51:19 DEBUG : file1: reading active writers 2025/07/04 03:51:19 DEBUG : file2: reading active writers 2025/07/04 03:51:19 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms 2025/07/04 03:51:19 DEBUG : Looking for writers 2025/07/04 03:51:19 DEBUG : file2: reading active writers 2025/07/04 03:51:19 DEBUG : file1: reading active writers 2025/07/04 03:51:19 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms 2025/07/04 03:51:20 DEBUG : Looking for writers 2025/07/04 03:51:20 DEBUG : file1: reading active writers 2025/07/04 03:51:20 DEBUG : file2: reading active writers 2025/07/04 03:51:20 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms 2025/07/04 03:51: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:51:20 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:51:20 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:51:20 DEBUG : Looking for writers 2025/07/04 03:51:20 DEBUG : file1: reading active writers 2025/07/04 03:51:20 DEBUG : file2: reading active writers 2025/07/04 03:51:20 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51: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:51:21 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:51:21 DEBUG : file2: vfs cache: starting upload 2025/07/04 03:51:21 DEBUG : Looking for writers 2025/07/04 03:51:21 DEBUG : file1: reading active writers 2025/07/04 03:51:21 DEBUG : file2: reading active writers 2025/07/04 03:51:21 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51: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:51:22 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:51:22 DEBUG : Looking for writers 2025/07/04 03:51:22 DEBUG : file1: reading active writers 2025/07/04 03:51:22 DEBUG : file2: reading active writers 2025/07/04 03:51:22 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:22 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:51:23 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:51:23 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:51:23 DEBUG : file2: vfs cache: starting upload 2025/07/04 03:51:23 DEBUG : Looking for writers 2025/07/04 03:51:23 DEBUG : file1: reading active writers 2025/07/04 03:51:23 DEBUG : file2: reading active writers 2025/07/04 03:51:23 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:24 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:51:24 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:51:24 DEBUG : Looking for writers 2025/07/04 03:51:24 DEBUG : file1: reading active writers 2025/07/04 03:51:24 DEBUG : file2: reading active writers 2025/07/04 03:51:24 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:25 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:51:25 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:51:25 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:51:25 DEBUG : Looking for writers 2025/07/04 03:51:25 DEBUG : file1: reading active writers 2025/07/04 03:51:25 DEBUG : file2: reading active writers 2025/07/04 03:51:25 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:26 DEBUG : file2: vfs cache: starting upload 2025/07/04 03:51:26 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:51:26 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:51:26 DEBUG : Looking for writers 2025/07/04 03:51:26 DEBUG : file1: reading active writers 2025/07/04 03:51:26 DEBUG : file2: reading active writers 2025/07/04 03:51:26 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:27 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:51:27 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:51:27 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:51:27 DEBUG : Looking for writers 2025/07/04 03:51:27 DEBUG : file1: reading active writers 2025/07/04 03:51:27 DEBUG : file2: reading active writers 2025/07/04 03:51:27 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:28 DEBUG : file2: vfs cache: starting upload 2025/07/04 03:51: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:51: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:51:28 DEBUG : Looking for writers 2025/07/04 03:51:28 DEBUG : file1: reading active writers 2025/07/04 03:51:28 DEBUG : file2: reading active writers 2025/07/04 03:51:28 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51: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:51: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:51:29 DEBUG : Looking for writers 2025/07/04 03:51:29 DEBUG : file1: reading active writers 2025/07/04 03:51:29 DEBUG : file2: reading active writers 2025/07/04 03:51:29 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:30 DEBUG : Looking for writers 2025/07/04 03:51:30 DEBUG : file2: reading active writers 2025/07/04 03:51:30 DEBUG : file1: reading active writers 2025/07/04 03:51:30 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:31 DEBUG : Looking for writers 2025/07/04 03:51:31 DEBUG : file1: reading active writers 2025/07/04 03:51:31 DEBUG : file2: reading active writers 2025/07/04 03:51:31 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:32 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:51:32 DEBUG : Looking for writers 2025/07/04 03:51:32 DEBUG : file2: reading active writers 2025/07/04 03:51:32 DEBUG : file1: reading active writers 2025/07/04 03:51:32 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51: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:51: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:51:32 DEBUG : file2: vfs cache: starting upload 2025/07/04 03:51:33 DEBUG : Looking for writers 2025/07/04 03:51:33 DEBUG : file1: reading active writers 2025/07/04 03:51:33 DEBUG : file2: reading active writers 2025/07/04 03:51:33 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51: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:51: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:51:34 DEBUG : Looking for writers 2025/07/04 03:51:34 DEBUG : file1: reading active writers 2025/07/04 03:51:34 DEBUG : file2: reading active writers 2025/07/04 03:51:34 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:35 DEBUG : Looking for writers 2025/07/04 03:51:35 DEBUG : file1: reading active writers 2025/07/04 03:51:35 DEBUG : file2: reading active writers 2025/07/04 03:51:35 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:36 DEBUG : Looking for writers 2025/07/04 03:51:36 DEBUG : file1: reading active writers 2025/07/04 03:51:36 DEBUG : file2: reading active writers 2025/07/04 03:51:36 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:37 DEBUG : Looking for writers 2025/07/04 03:51:37 DEBUG : file2: reading active writers 2025/07/04 03:51:37 DEBUG : file1: reading active writers 2025/07/04 03:51:37 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:38 DEBUG : Looking for writers 2025/07/04 03:51:38 DEBUG : file2: reading active writers 2025/07/04 03:51:38 DEBUG : file1: reading active writers 2025/07/04 03:51:38 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:39 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:51:39 DEBUG : Looking for writers 2025/07/04 03:51:39 DEBUG : file1: reading active writers 2025/07/04 03:51:39 DEBUG : file2: reading active writers 2025/07/04 03:51:39 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:40 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:51:40 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:51:40 DEBUG : file2: vfs cache: starting upload 2025/07/04 03:51:40 DEBUG : Looking for writers 2025/07/04 03:51:40 DEBUG : file1: reading active writers 2025/07/04 03:51:40 DEBUG : file2: reading active writers 2025/07/04 03:51:40 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:41 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:51:41 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:51:41 DEBUG : Looking for writers 2025/07/04 03:51:41 DEBUG : file2: reading active writers 2025/07/04 03:51:41 DEBUG : file1: reading active writers 2025/07/04 03:51:41 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:42 DEBUG : Looking for writers 2025/07/04 03:51:42 DEBUG : file1: reading active writers 2025/07/04 03:51:42 DEBUG : file2: reading active writers 2025/07/04 03:51:42 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:43 DEBUG : Looking for writers 2025/07/04 03:51:43 DEBUG : file1: reading active writers 2025/07/04 03:51:43 DEBUG : file2: reading active writers 2025/07/04 03:51:43 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:44 DEBUG : Looking for writers 2025/07/04 03:51:44 DEBUG : file1: reading active writers 2025/07/04 03:51:44 DEBUG : file2: reading active writers 2025/07/04 03:51:44 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:45 DEBUG : Looking for writers 2025/07/04 03:51:45 DEBUG : file1: reading active writers 2025/07/04 03:51:45 DEBUG : file2: reading active writers 2025/07/04 03:51:45 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:46 DEBUG : Looking for writers 2025/07/04 03:51:46 DEBUG : file1: reading active writers 2025/07/04 03:51:46 DEBUG : file2: reading active writers 2025/07/04 03:51:46 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:47 DEBUG : Looking for writers 2025/07/04 03:51:47 DEBUG : file1: reading active writers 2025/07/04 03:51:47 DEBUG : file2: reading active writers 2025/07/04 03:51:47 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:48 DEBUG : Looking for writers 2025/07/04 03:51:48 DEBUG : file2: reading active writers 2025/07/04 03:51:48 DEBUG : file1: reading active writers 2025/07/04 03:51:48 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:51:49 ERROR : Exiting even though 0 writers active and 2 cache items in use after 30s Cache{ "file2": &{c:0xc00079c960 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc000736c08 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824641285184} name:file2 opens:0 downloaders: o: fd: info:{ModTime:{wall:13984224184595785103 ext:184499224059 loc:0x3fe46e0} ATime:{wall:13984224184596118700 ext:184499557655 loc:0x3fe46e0} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2 pendingAccesses:0 modified:false beingReset:false}, "file1": &{c:0xc00079c960 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc000736b08 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824641284928} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13984224184593286926 ext:184496725881 loc:0x3fe46e0} ATime:{wall:13984224184593761707 ext:184497200652 loc:0x3fe46e0} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2025/07/04 03:51:49 DEBUG : >WaitForWriters: 2025/07/04 03:51: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:51:51 ERROR : error listing: directory not found fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 2025/07/04 03:51:53 DEBUG : file1: vfs cache: starting upload fstest.go:298: Flushing the directory cache 2025/07/04 03:51:54 DEBUG : file2: vfs cache: starting upload 2025/07/04 03:51:54 DEBUG : Saving config "captcha_token" in section "TestPikPak" of the config file 2025/07/04 03:51:55 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:51:55 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:51:56 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:51:56 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. 2025/07/04 03:51:56 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: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:52:00 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:52:00 DEBUG : Looking for writers 2025/07/04 03:52:00 DEBUG : file1: reading active writers 2025/07/04 03:52:00 DEBUG : file2: reading active writers 2025/07/04 03:52:00 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms 2025/07/04 03:52:00 DEBUG : Looking for writers 2025/07/04 03:52:00 DEBUG : file1: reading active writers 2025/07/04 03:52:00 DEBUG : file2: reading active writers 2025/07/04 03:52:00 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms 2025/07/04 03:52:00 DEBUG : Looking for writers 2025/07/04 03:52:00 DEBUG : file1: reading active writers 2025/07/04 03:52:00 DEBUG : file2: reading active writers 2025/07/04 03:52:00 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms 2025/07/04 03:52:00 DEBUG : Looking for writers 2025/07/04 03:52:00 DEBUG : file1: reading active writers 2025/07/04 03:52:00 DEBUG : file2: reading active writers 2025/07/04 03:52:00 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms 2025/07/04 03:52:00 DEBUG : Looking for writers 2025/07/04 03:52:00 DEBUG : file1: reading active writers 2025/07/04 03:52:00 DEBUG : file2: reading active writers 2025/07/04 03:52:00 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms 2025/07/04 03:52:00 DEBUG : Looking for writers 2025/07/04 03:52:00 DEBUG : file1: reading active writers 2025/07/04 03:52:00 DEBUG : file2: reading active writers 2025/07/04 03:52:00 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms 2025/07/04 03:52:01 DEBUG : Looking for writers 2025/07/04 03:52:01 DEBUG : file1: reading active writers 2025/07/04 03:52:01 DEBUG : file2: reading active writers 2025/07/04 03:52:01 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms 2025/07/04 03:52:01 DEBUG : Looking for writers 2025/07/04 03:52:01 DEBUG : file1: reading active writers 2025/07/04 03:52:01 DEBUG : file2: reading active writers 2025/07/04 03:52:01 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:02 DEBUG : Looking for writers 2025/07/04 03:52:02 DEBUG : file1: reading active writers 2025/07/04 03:52:02 DEBUG : file2: reading active writers 2025/07/04 03:52:02 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:03 DEBUG : Looking for writers 2025/07/04 03:52:03 DEBUG : file2: reading active writers 2025/07/04 03:52:03 DEBUG : file1: reading active writers 2025/07/04 03:52:03 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:04 DEBUG : Looking for writers 2025/07/04 03:52:04 DEBUG : file1: reading active writers 2025/07/04 03:52:04 DEBUG : file2: reading active writers 2025/07/04 03:52:04 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:05 DEBUG : Looking for writers 2025/07/04 03:52:05 DEBUG : file1: reading active writers 2025/07/04 03:52:05 DEBUG : file2: reading active writers 2025/07/04 03:52:05 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:06 DEBUG : Looking for writers 2025/07/04 03:52:06 DEBUG : file1: reading active writers 2025/07/04 03:52:06 DEBUG : file2: reading active writers 2025/07/04 03:52:06 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:07 DEBUG : Looking for writers 2025/07/04 03:52:07 DEBUG : file1: reading active writers 2025/07/04 03:52:07 DEBUG : file2: reading active writers 2025/07/04 03:52:07 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:08 DEBUG : Looking for writers 2025/07/04 03:52:08 DEBUG : file1: reading active writers 2025/07/04 03:52:08 DEBUG : file2: reading active writers 2025/07/04 03:52:08 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:09 DEBUG : Looking for writers 2025/07/04 03:52:09 DEBUG : file1: reading active writers 2025/07/04 03:52:09 DEBUG : file2: reading active writers 2025/07/04 03:52:09 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:10 DEBUG : Looking for writers 2025/07/04 03:52:10 DEBUG : file1: reading active writers 2025/07/04 03:52:10 DEBUG : file2: reading active writers 2025/07/04 03:52:10 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:11 DEBUG : Looking for writers 2025/07/04 03:52:11 DEBUG : file2: reading active writers 2025/07/04 03:52:11 DEBUG : file1: reading active writers 2025/07/04 03:52:11 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:12 DEBUG : Looking for writers 2025/07/04 03:52:12 DEBUG : file1: reading active writers 2025/07/04 03:52:12 DEBUG : file2: reading active writers 2025/07/04 03:52:12 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:13 DEBUG : Looking for writers 2025/07/04 03:52:13 DEBUG : file1: reading active writers 2025/07/04 03:52:13 DEBUG : file2: reading active writers 2025/07/04 03:52:13 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:14 DEBUG : Looking for writers 2025/07/04 03:52:14 DEBUG : file1: reading active writers 2025/07/04 03:52:14 DEBUG : file2: reading active writers 2025/07/04 03:52:14 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:15 DEBUG : Looking for writers 2025/07/04 03:52:15 DEBUG : file1: reading active writers 2025/07/04 03:52:15 DEBUG : file2: reading active writers 2025/07/04 03:52:15 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:16 DEBUG : Looking for writers 2025/07/04 03:52:16 DEBUG : file2: reading active writers 2025/07/04 03:52:16 DEBUG : file1: reading active writers 2025/07/04 03:52:16 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:17 DEBUG : Looking for writers 2025/07/04 03:52:17 DEBUG : file1: reading active writers 2025/07/04 03:52:17 DEBUG : file2: reading active writers 2025/07/04 03:52:17 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:18 DEBUG : Looking for writers 2025/07/04 03:52:18 DEBUG : file1: reading active writers 2025/07/04 03:52:18 DEBUG : file2: reading active writers 2025/07/04 03:52:18 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:19 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2025/07/04 03:52:19 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file2 not removed, freed 0 bytes 2025/07/04 03:52:19 INFO : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaned: objects 2 (was 2) in use 2, to upload 2, uploading 0, total size 0 (was 0) 2025/07/04 03:52:19 DEBUG : Looking for writers 2025/07/04 03:52:19 DEBUG : file1: reading active writers 2025/07/04 03:52:19 DEBUG : file2: reading active writers 2025/07/04 03:52:19 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:20 DEBUG : Looking for writers 2025/07/04 03:52:20 DEBUG : file2: reading active writers 2025/07/04 03:52:20 DEBUG : file1: reading active writers 2025/07/04 03:52:20 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:20 DEBUG : file1: vfs cache: starting upload 2025/07/04 03:52:21 DEBUG : Looking for writers 2025/07/04 03:52:21 DEBUG : file1: reading active writers 2025/07/04 03:52:21 DEBUG : file2: reading active writers 2025/07/04 03:52:21 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:21 DEBUG : file2: vfs cache: starting upload 2025/07/04 03:52: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:52:21 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:52:22 DEBUG : Looking for writers 2025/07/04 03:52:22 DEBUG : file1: reading active writers 2025/07/04 03:52:22 DEBUG : file2: reading active writers 2025/07/04 03:52:22 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52: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:52:22 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:52:23 DEBUG : Looking for writers 2025/07/04 03:52:23 DEBUG : file1: reading active writers 2025/07/04 03:52:23 DEBUG : file2: reading active writers 2025/07/04 03:52:23 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:24 DEBUG : Looking for writers 2025/07/04 03:52:24 DEBUG : file1: reading active writers 2025/07/04 03:52:24 DEBUG : file2: reading active writers 2025/07/04 03:52:24 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:25 DEBUG : Looking for writers 2025/07/04 03:52:25 DEBUG : file1: reading active writers 2025/07/04 03:52:25 DEBUG : file2: reading active writers 2025/07/04 03:52:25 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:26 DEBUG : Looking for writers 2025/07/04 03:52:26 DEBUG : file2: reading active writers 2025/07/04 03:52:26 DEBUG : file1: reading active writers 2025/07/04 03:52:26 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:27 DEBUG : Looking for writers 2025/07/04 03:52:27 DEBUG : file1: reading active writers 2025/07/04 03:52:27 DEBUG : file2: reading active writers 2025/07/04 03:52:27 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:28 DEBUG : Looking for writers 2025/07/04 03:52:28 DEBUG : file1: reading active writers 2025/07/04 03:52:28 DEBUG : file2: reading active writers 2025/07/04 03:52:28 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:29 DEBUG : Looking for writers 2025/07/04 03:52:29 DEBUG : file1: reading active writers 2025/07/04 03:52:29 DEBUG : file2: reading active writers 2025/07/04 03:52:29 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/07/04 03:52:30 ERROR : Exiting even though 0 writers active and 2 cache items in use after 30s Cache{ "file2": &{c:0xc00079c960 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc000736c08 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824641285184} name:file2 opens:0 downloaders: o: fd: info:{ModTime:{wall:13984224184595785103 ext:184499224059 loc:0x3fe46e0} ATime:{wall:13984224184596118700 ext:184499557655 loc:0x3fe46e0} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2 pendingAccesses:0 modified:false beingReset:false}, "file1": &{c:0xc00079c960 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc000736b08 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824641284928} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13984224184593286926 ext:184496725881 loc:0x3fe46e0} ATime:{wall:13984224184593761707 ext:184497200652 loc:0x3fe46e0} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2025/07/04 03:52:30 DEBUG : >WaitForWriters: 2025/07/04 03:52:30 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:52:30 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleWriteNoWrite (71.48s) === RUN TestRWFileHandleSizeTruncateExisting run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:52:30 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:52:30 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:52:30 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:52:30 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:52:30 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:52:30 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:52:30 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:52:30 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:52:30 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:52:30 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:52:30 INFO : PikPak root 'rclone-test-tunokup2wonu': 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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:52:31 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:52:31 DEBUG : Looking for writers 2025/07/04 03:52:31 DEBUG : >WaitForWriters: 2025/07/04 03:52:31 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:52:31 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleSizeTruncateExisting (0.93s) === RUN TestRWFileHandleSizeCreateExisting run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:52:31 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:52:31 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:52:31 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:52:31 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:52:31 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:52:31 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:52:31 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:52:31 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:52:31 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:52:31 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:52:31 INFO : PikPak root 'rclone-test-tunokup2wonu': 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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:52:32 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:52:32 DEBUG : Looking for writers 2025/07/04 03:52:32 DEBUG : >WaitForWriters: 2025/07/04 03:52:32 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:52:32 ERROR : error listing: directory not found --- FAIL: TestRWFileHandleSizeCreateExisting (0.96s) === RUN TestRWFileModTimeWithOpenWriters run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:52:32 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:52:32 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: root is "/home/rclone/.cache/rclone" 2025/07/04 03:52:32 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:52:32 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:52:32 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:52:32 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:52:32 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:52:32 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:52:32 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/07/04 03:52:32 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPikPak/rclone-test-tunokup2wonu" 2025/07/04 03:52:32 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:52:32 INFO : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2025/07/04 03:52:33 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:52:33 DEBUG : file1: newRWFileHandle: 2025/07/04 03:52:33 DEBUG : file1(0xc0002d05c0): openPending: 2025/07/04 03:52:33 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2025/07/04 03:52:33 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:52:33 DEBUG : file1(0xc0002d05c0): >openPending: err= 2025/07/04 03:52:33 DEBUG : file1: >newRWFileHandle: err= 2025/07/04 03:52:33 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:52:33 DEBUG : file1: >Open: fd=file1 (rw), err= 2025/07/04 03:52:33 DEBUG : file1: >OpenFile: fd=file1 (rw), err= run.go:237: Failed to mkdir "PikPak root 'rclone-test-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:52:33 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:52:33 DEBUG : Looking for writers 2025/07/04 03:52:33 DEBUG : file1: reading active writers 2025/07/04 03:52:33 DEBUG : file1: active writers 1 2025/07/04 03:52:33 DEBUG : Still 1 writers active and 1 cache items in use, waiting 10ms 2025/07/04 03:52:33 DEBUG : Looking for writers 2025/07/04 03:52:33 DEBUG : file1: reading active writers 2025/07/04 03:52:33 DEBUG : file1: active writers 1 2025/07/04 03:52:33 DEBUG : Still 1 writers active and 1 cache items in use, waiting 20ms 2025/07/04 03:52:33 DEBUG : Looking for writers 2025/07/04 03:52:33 DEBUG : file1: reading active writers 2025/07/04 03:52:33 DEBUG : file1: active writers 1 2025/07/04 03:52:33 DEBUG : Still 1 writers active and 1 cache items in use, waiting 40ms 2025/07/04 03:52:33 DEBUG : Looking for writers 2025/07/04 03:52:33 DEBUG : file1: reading active writers 2025/07/04 03:52:33 DEBUG : file1: active writers 1 2025/07/04 03:52:33 DEBUG : Still 1 writers active and 1 cache items in use, waiting 80ms 2025/07/04 03:52:33 DEBUG : Looking for writers 2025/07/04 03:52:33 DEBUG : file1: reading active writers 2025/07/04 03:52:33 DEBUG : file1: active writers 1 2025/07/04 03:52:33 DEBUG : Still 1 writers active and 1 cache items in use, waiting 160ms 2025/07/04 03:52:33 DEBUG : Looking for writers 2025/07/04 03:52:33 DEBUG : file1: reading active writers 2025/07/04 03:52:33 DEBUG : file1: active writers 1 2025/07/04 03:52:33 DEBUG : Still 1 writers active and 1 cache items in use, waiting 320ms 2025/07/04 03:52:34 DEBUG : Looking for writers 2025/07/04 03:52:34 DEBUG : file1: reading active writers 2025/07/04 03:52:34 DEBUG : file1: active writers 1 2025/07/04 03:52:34 DEBUG : Still 1 writers active and 1 cache items in use, waiting 640ms 2025/07/04 03:52:34 DEBUG : Looking for writers 2025/07/04 03:52:34 DEBUG : file1: reading active writers 2025/07/04 03:52:34 DEBUG : file1: active writers 1 2025/07/04 03:52:34 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:35 DEBUG : Looking for writers 2025/07/04 03:52:35 DEBUG : file1: reading active writers 2025/07/04 03:52:35 DEBUG : file1: active writers 1 2025/07/04 03:52:35 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:36 DEBUG : Looking for writers 2025/07/04 03:52:36 DEBUG : file1: reading active writers 2025/07/04 03:52:36 DEBUG : file1: active writers 1 2025/07/04 03:52:36 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:37 DEBUG : Looking for writers 2025/07/04 03:52:37 DEBUG : file1: reading active writers 2025/07/04 03:52:37 DEBUG : file1: active writers 1 2025/07/04 03:52:37 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:38 DEBUG : Looking for writers 2025/07/04 03:52:38 DEBUG : file1: reading active writers 2025/07/04 03:52:38 DEBUG : file1: active writers 1 2025/07/04 03:52:38 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:39 DEBUG : Looking for writers 2025/07/04 03:52:39 DEBUG : file1: reading active writers 2025/07/04 03:52:39 DEBUG : file1: active writers 1 2025/07/04 03:52:39 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:40 DEBUG : Looking for writers 2025/07/04 03:52:40 DEBUG : file1: reading active writers 2025/07/04 03:52:40 DEBUG : file1: active writers 1 2025/07/04 03:52:40 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:41 DEBUG : Looking for writers 2025/07/04 03:52:41 DEBUG : file1: reading active writers 2025/07/04 03:52:41 DEBUG : file1: active writers 1 2025/07/04 03:52:41 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:42 DEBUG : Looking for writers 2025/07/04 03:52:42 DEBUG : file1: reading active writers 2025/07/04 03:52:42 DEBUG : file1: active writers 1 2025/07/04 03:52:42 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:43 DEBUG : Looking for writers 2025/07/04 03:52:43 DEBUG : file1: reading active writers 2025/07/04 03:52:43 DEBUG : file1: active writers 1 2025/07/04 03:52:43 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:44 DEBUG : Looking for writers 2025/07/04 03:52:44 DEBUG : file1: reading active writers 2025/07/04 03:52:44 DEBUG : file1: active writers 1 2025/07/04 03:52:44 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:45 DEBUG : Looking for writers 2025/07/04 03:52:45 DEBUG : file1: reading active writers 2025/07/04 03:52:45 DEBUG : file1: active writers 1 2025/07/04 03:52:45 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:46 DEBUG : Looking for writers 2025/07/04 03:52:46 DEBUG : file1: reading active writers 2025/07/04 03:52:46 DEBUG : file1: active writers 1 2025/07/04 03:52:46 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:47 DEBUG : Looking for writers 2025/07/04 03:52:47 DEBUG : file1: reading active writers 2025/07/04 03:52:47 DEBUG : file1: active writers 1 2025/07/04 03:52:47 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:48 DEBUG : Looking for writers 2025/07/04 03:52:48 DEBUG : file1: reading active writers 2025/07/04 03:52:48 DEBUG : file1: active writers 1 2025/07/04 03:52:48 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:49 DEBUG : Looking for writers 2025/07/04 03:52:49 DEBUG : file1: reading active writers 2025/07/04 03:52:49 DEBUG : file1: active writers 1 2025/07/04 03:52:49 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:50 DEBUG : Looking for writers 2025/07/04 03:52:50 DEBUG : file1: reading active writers 2025/07/04 03:52:50 DEBUG : file1: active writers 1 2025/07/04 03:52:50 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:51 DEBUG : Looking for writers 2025/07/04 03:52:51 DEBUG : file1: reading active writers 2025/07/04 03:52:51 DEBUG : file1: active writers 1 2025/07/04 03:52:51 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:52 DEBUG : Looking for writers 2025/07/04 03:52:52 DEBUG : file1: reading active writers 2025/07/04 03:52:52 DEBUG : file1: active writers 1 2025/07/04 03:52:52 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:53 DEBUG : Looking for writers 2025/07/04 03:52:53 DEBUG : file1: reading active writers 2025/07/04 03:52:53 DEBUG : file1: active writers 1 2025/07/04 03:52:53 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:54 DEBUG : Looking for writers 2025/07/04 03:52:54 DEBUG : file1: reading active writers 2025/07/04 03:52:54 DEBUG : file1: active writers 1 2025/07/04 03:52:54 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:55 DEBUG : Looking for writers 2025/07/04 03:52:55 DEBUG : file1: reading active writers 2025/07/04 03:52:55 DEBUG : file1: active writers 1 2025/07/04 03:52:55 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:56 DEBUG : Looking for writers 2025/07/04 03:52:56 DEBUG : file1: reading active writers 2025/07/04 03:52:56 DEBUG : file1: active writers 1 2025/07/04 03:52:56 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:57 DEBUG : Looking for writers 2025/07/04 03:52:57 DEBUG : file1: reading active writers 2025/07/04 03:52:57 DEBUG : file1: active writers 1 2025/07/04 03:52:57 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:58 DEBUG : Looking for writers 2025/07/04 03:52:58 DEBUG : file1: reading active writers 2025/07/04 03:52:58 DEBUG : file1: active writers 1 2025/07/04 03:52:58 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:52:59 DEBUG : Looking for writers 2025/07/04 03:52:59 DEBUG : file1: reading active writers 2025/07/04 03:52:59 DEBUG : file1: active writers 1 2025/07/04 03:52:59 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:53:00 DEBUG : Looking for writers 2025/07/04 03:53:00 DEBUG : file1: reading active writers 2025/07/04 03:53:00 DEBUG : file1: active writers 1 2025/07/04 03:53:00 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:53:01 DEBUG : Looking for writers 2025/07/04 03:53:01 DEBUG : file1: reading active writers 2025/07/04 03:53:01 DEBUG : file1: active writers 1 2025/07/04 03:53:01 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:53:02 DEBUG : Looking for writers 2025/07/04 03:53:02 DEBUG : file1: reading active writers 2025/07/04 03:53:02 DEBUG : file1: active writers 1 2025/07/04 03:53:02 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/07/04 03:53:03 ERROR : Exiting even though 1 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc000255a40 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc00055cc08 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824639343680} name:file1 opens:1 downloaders: o: fd:0xc00008ab60 info:{ModTime:{wall:13984224263425003700 ext:257871547679 loc:0x3fe46e0} ATime:{wall:13984224263425003700 ext:257871547679 loc:0x3fe46e0} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:0 pendingAccesses:0 modified:true beingReset:false}, } 2025/07/04 03:53:03 DEBUG : >WaitForWriters: 2025/07/04 03:53:03 DEBUG : PikPak root 'rclone-test-tunokup2wonu': vfs cache: cleaner exiting 2025/07/04 03:53:03 ERROR : error listing: directory not found --- FAIL: TestRWFileModTimeWithOpenWriters (31.29s) === RUN TestCaseSensitivity run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" run.go:237: Failed to mkdir "PikPak root 'rclone-test-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:53:04 ERROR : error listing: directory not found --- FAIL: TestCaseSensitivity (0.92s) === RUN TestUnicodeNormalization run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" run.go:237: Failed to mkdir "PikPak root 'rclone-test-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:53:05 ERROR : error listing: directory not found --- FAIL: TestUnicodeNormalization (0.96s) === RUN TestVFSStat run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:53:05 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:53:05 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:53:06 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:53:06 DEBUG : Looking for writers 2025/07/04 03:53:06 DEBUG : >WaitForWriters: 2025/07/04 03:53:06 ERROR : error listing: directory not found --- FAIL: TestVFSStat (0.92s) === RUN TestVFSStatParent run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:53:06 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:53:06 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:53:07 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:53:07 DEBUG : Looking for writers 2025/07/04 03:53:07 DEBUG : >WaitForWriters: 2025/07/04 03:53:07 ERROR : error listing: directory not found --- FAIL: TestVFSStatParent (0.93s) === RUN TestVFSOpenFile run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:53:07 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:53:07 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:53:08 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:53:08 DEBUG : Looking for writers 2025/07/04 03:53:08 DEBUG : >WaitForWriters: 2025/07/04 03:53:08 ERROR : error listing: directory not found --- FAIL: TestVFSOpenFile (0.94s) === RUN TestVFSRename run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:53:08 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:53:08 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --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-tunokup2wonu'": failed to make directory: Error "file_invisible" (5): Operation failed, the target folder no longer exists. 2025/07/04 03:53:09 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:53:09 DEBUG : Looking for writers 2025/07/04 03:53:09 DEBUG : >WaitForWriters: 2025/07/04 03:53:09 ERROR : error listing: directory not found --- FAIL: TestVFSRename (0.94s) === RUN TestVFSMkdir run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:53:09 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:53:09 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:53:09 ERROR : error listing: directory not found 2025/07/04 03:53: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: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:53:10 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:53:10 DEBUG : Looking for writers 2025/07/04 03:53:10 DEBUG : >WaitForWriters: 2025/07/04 03:53:11 ERROR : error listing: directory not found --- FAIL: TestVFSMkdir (1.52s) === RUN TestVFSMkdirAll run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:53:11 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:53:11 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:53:11 ERROR : error listing: directory not found 2025/07/04 03:53:11 ERROR : error listing: directory not found 2025/07/04 03:53:12 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:53:12 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:53:12 DEBUG : Looking for writers 2025/07/04 03:53:12 DEBUG : >WaitForWriters: 2025/07/04 03:53:12 ERROR : error listing: directory not found --- FAIL: TestVFSMkdirAll (1.84s) === RUN TestWriteFileHandleMethods run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:53:12 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:53:12 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:53:12 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:53:13 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:53:13 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:53:13 DEBUG : file1: >Open: fd=file1 (w), err= 2025/07/04 03:53:13 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/07/04 03:53:13 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:53:13 ERROR : file1: WriteFileHandle: Read: Can't read and write to file without --vfs-cache-mode >= minimal 2025/07/04 03:53:13 ERROR : file1: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal 2025/07/04 03:53:13 ERROR : file1: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes 2025/07/04 03:53:13 DEBUG : PikPak root 'rclone-test-tunokup2wonu': File to upload is small (5 bytes), uploading instead of streaming 2025/07/04 03:53:14 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:53:14 DEBUG : file1: Remove: 2025/07/04 03:53:14 DEBUG : Added virtual directory entry vDel: "file1" 2025/07/04 03:53:14 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:53:14 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:53:15 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:53:18 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:53:22 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:53:22 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:53:22 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:53:22 DEBUG : file1: >Open: fd=file1 (w), err= 2025/07/04 03:53:22 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/07/04 03:53:22 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:53:22 DEBUG : PikPak root 'rclone-test-tunokup2wonu': File to upload is small (0 bytes), uploading instead of streaming 2025/07/04 03:53:23 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:53:23 DEBUG : file1: Remove: 2025/07/04 03:53:23 DEBUG : Added virtual directory entry vDel: "file1" 2025/07/04 03:53:23 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:53:23 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:53:23 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:53:23 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:53:23 DEBUG : file1: >Open: fd=file1 (w), err= 2025/07/04 03:53:23 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/07/04 03:53:23 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:53:23 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:53:23 DEBUG : Looking for writers 2025/07/04 03:53:23 DEBUG : file1: reading active writers 2025/07/04 03:53:23 DEBUG : file1: active writers 1 2025/07/04 03:53:23 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2025/07/04 03:53:23 DEBUG : Looking for writers 2025/07/04 03:53:23 DEBUG : file1: reading active writers 2025/07/04 03:53:23 DEBUG : file1: active writers 1 2025/07/04 03:53:23 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2025/07/04 03:53:23 DEBUG : Looking for writers 2025/07/04 03:53:23 DEBUG : file1: reading active writers 2025/07/04 03:53:23 DEBUG : file1: active writers 1 2025/07/04 03:53:23 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2025/07/04 03:53:23 DEBUG : Looking for writers 2025/07/04 03:53:23 DEBUG : file1: reading active writers 2025/07/04 03:53:23 DEBUG : file1: active writers 1 2025/07/04 03:53:23 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2025/07/04 03:53:23 DEBUG : Looking for writers 2025/07/04 03:53:23 DEBUG : file1: reading active writers 2025/07/04 03:53:23 DEBUG : file1: active writers 1 2025/07/04 03:53:23 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2025/07/04 03:53:23 DEBUG : Looking for writers 2025/07/04 03:53:23 DEBUG : file1: reading active writers 2025/07/04 03:53:23 DEBUG : file1: active writers 1 2025/07/04 03:53:23 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2025/07/04 03:53:23 DEBUG : Looking for writers 2025/07/04 03:53:23 DEBUG : file1: reading active writers 2025/07/04 03:53:23 DEBUG : file1: active writers 1 2025/07/04 03:53:23 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2025/07/04 03:53:24 DEBUG : Looking for writers 2025/07/04 03:53:24 DEBUG : file1: reading active writers 2025/07/04 03:53:24 DEBUG : file1: active writers 1 2025/07/04 03:53:24 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:25 DEBUG : Looking for writers 2025/07/04 03:53:25 DEBUG : file1: reading active writers 2025/07/04 03:53:25 DEBUG : file1: active writers 1 2025/07/04 03:53:25 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:26 DEBUG : Looking for writers 2025/07/04 03:53:26 DEBUG : file1: reading active writers 2025/07/04 03:53:26 DEBUG : file1: active writers 1 2025/07/04 03:53:26 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:27 DEBUG : Looking for writers 2025/07/04 03:53:27 DEBUG : file1: reading active writers 2025/07/04 03:53:27 DEBUG : file1: active writers 1 2025/07/04 03:53:27 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:28 DEBUG : Looking for writers 2025/07/04 03:53:28 DEBUG : file1: reading active writers 2025/07/04 03:53:28 DEBUG : file1: active writers 1 2025/07/04 03:53:28 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:29 DEBUG : Looking for writers 2025/07/04 03:53:29 DEBUG : file1: reading active writers 2025/07/04 03:53:29 DEBUG : file1: active writers 1 2025/07/04 03:53:29 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:30 DEBUG : Looking for writers 2025/07/04 03:53:30 DEBUG : file1: reading active writers 2025/07/04 03:53:30 DEBUG : file1: active writers 1 2025/07/04 03:53:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:31 DEBUG : Looking for writers 2025/07/04 03:53:31 DEBUG : file1: reading active writers 2025/07/04 03:53:31 DEBUG : file1: active writers 1 2025/07/04 03:53:31 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:32 DEBUG : Looking for writers 2025/07/04 03:53:32 DEBUG : file1: reading active writers 2025/07/04 03:53:32 DEBUG : file1: active writers 1 2025/07/04 03:53:32 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:33 DEBUG : Looking for writers 2025/07/04 03:53:33 DEBUG : file1: reading active writers 2025/07/04 03:53:33 DEBUG : file1: active writers 1 2025/07/04 03:53:33 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:34 DEBUG : Looking for writers 2025/07/04 03:53:34 DEBUG : file1: reading active writers 2025/07/04 03:53:34 DEBUG : file1: active writers 1 2025/07/04 03:53:34 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:35 DEBUG : Looking for writers 2025/07/04 03:53:35 DEBUG : file1: reading active writers 2025/07/04 03:53:35 DEBUG : file1: active writers 1 2025/07/04 03:53:35 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:36 DEBUG : Looking for writers 2025/07/04 03:53:36 DEBUG : file1: reading active writers 2025/07/04 03:53:36 DEBUG : file1: active writers 1 2025/07/04 03:53:36 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:37 DEBUG : Looking for writers 2025/07/04 03:53:37 DEBUG : file1: reading active writers 2025/07/04 03:53:37 DEBUG : file1: active writers 1 2025/07/04 03:53:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:38 DEBUG : Looking for writers 2025/07/04 03:53:38 DEBUG : file1: reading active writers 2025/07/04 03:53:38 DEBUG : file1: active writers 1 2025/07/04 03:53:38 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:39 DEBUG : Looking for writers 2025/07/04 03:53:39 DEBUG : file1: reading active writers 2025/07/04 03:53:39 DEBUG : file1: active writers 1 2025/07/04 03:53:39 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:40 DEBUG : Looking for writers 2025/07/04 03:53:40 DEBUG : file1: reading active writers 2025/07/04 03:53:40 DEBUG : file1: active writers 1 2025/07/04 03:53:40 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:41 DEBUG : Looking for writers 2025/07/04 03:53:41 DEBUG : file1: reading active writers 2025/07/04 03:53:41 DEBUG : file1: active writers 1 2025/07/04 03:53:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:42 DEBUG : Looking for writers 2025/07/04 03:53:42 DEBUG : file1: reading active writers 2025/07/04 03:53:42 DEBUG : file1: active writers 1 2025/07/04 03:53:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:43 DEBUG : Looking for writers 2025/07/04 03:53:43 DEBUG : file1: reading active writers 2025/07/04 03:53:43 DEBUG : file1: active writers 1 2025/07/04 03:53:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:44 DEBUG : Looking for writers 2025/07/04 03:53:44 DEBUG : file1: reading active writers 2025/07/04 03:53:44 DEBUG : file1: active writers 1 2025/07/04 03:53:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:45 DEBUG : Looking for writers 2025/07/04 03:53:45 DEBUG : file1: reading active writers 2025/07/04 03:53:45 DEBUG : file1: active writers 1 2025/07/04 03:53:45 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:46 DEBUG : Looking for writers 2025/07/04 03:53:46 DEBUG : file1: reading active writers 2025/07/04 03:53:46 DEBUG : file1: active writers 1 2025/07/04 03:53:46 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:47 DEBUG : Looking for writers 2025/07/04 03:53:47 DEBUG : file1: reading active writers 2025/07/04 03:53:47 DEBUG : file1: active writers 1 2025/07/04 03:53:47 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:48 DEBUG : Looking for writers 2025/07/04 03:53:48 DEBUG : file1: reading active writers 2025/07/04 03:53:48 DEBUG : file1: active writers 1 2025/07/04 03:53:48 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:49 DEBUG : Looking for writers 2025/07/04 03:53:49 DEBUG : file1: reading active writers 2025/07/04 03:53:49 DEBUG : file1: active writers 1 2025/07/04 03:53:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:50 DEBUG : Looking for writers 2025/07/04 03:53:50 DEBUG : file1: reading active writers 2025/07/04 03:53:50 DEBUG : file1: active writers 1 2025/07/04 03:53:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:51 DEBUG : Looking for writers 2025/07/04 03:53:51 DEBUG : file1: reading active writers 2025/07/04 03:53:51 DEBUG : file1: active writers 1 2025/07/04 03:53:51 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:52 DEBUG : Looking for writers 2025/07/04 03:53:52 DEBUG : file1: reading active writers 2025/07/04 03:53:52 DEBUG : file1: active writers 1 2025/07/04 03:53:52 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/07/04 03:53:53 ERROR : Exiting even though 1 writers active and 0 cache items in use after 30s Cache: 2025/07/04 03:53:53 DEBUG : >WaitForWriters: 2025/07/04 03:53:53 ERROR : error listing: directory not found --- FAIL: TestWriteFileHandleMethods (40.46s) === RUN TestWriteFileHandleWriteAt run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:53:53 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:53:53 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:53:53 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:53:53 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:53:53 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:53:53 DEBUG : file1: >Open: fd=file1 (w), err= 2025/07/04 03:53:53 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/07/04 03:53:53 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:53:53 DEBUG : file1: waiting for in-sequence write to 100 for 1s 2025/07/04 03:53:54 DEBUG : file1: aborting in-sequence write wait, off=100 2025/07/04 03:53:54 DEBUG : file1: failed to wait for in-sequence write to 100 2025/07/04 03:53:54 ERROR : file1: WriteFileHandle.Write: can't seek in file without --vfs-cache-mode >= writes 2025/07/04 03:53:54 DEBUG : PikPak root 'rclone-test-tunokup2wonu': File to upload is small (11 bytes), uploading instead of streaming 2025/07/04 03:53:55 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:53:55 DEBUG : file1: Remove: 2025/07/04 03:53:55 DEBUG : Added virtual directory entry vDel: "file1" 2025/07/04 03:53:55 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:53:55 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:53:56 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:53:57 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:53:59 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:54:03 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:54:03 DEBUG : Looking for writers 2025/07/04 03:54:03 DEBUG : >WaitForWriters: 2025/07/04 03:54:04 ERROR : error listing: directory not found --- FAIL: TestWriteFileHandleWriteAt (10.69s) === RUN TestWriteFileHandleFlush run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:54:04 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:54:04 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:54:04 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:54:04 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:54:04 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:54:04 DEBUG : file1: >Open: fd=file1 (w), err= 2025/07/04 03:54:04 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/07/04 03:54:04 DEBUG : file1: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions 2025/07/04 03:54:04 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:54:04 DEBUG : PikPak root 'rclone-test-tunokup2wonu': File to upload is small (5 bytes), uploading instead of streaming 2025/07/04 03:54:05 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:54:05 DEBUG : file1: Remove: 2025/07/04 03:54:05 DEBUG : Added virtual directory entry vDel: "file1" 2025/07/04 03:54:05 DEBUG : file1: >Remove: err= 2025/07/04 03:54:05 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:54:05 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:54:05 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:54:05 DEBUG : Looking for writers 2025/07/04 03:54:05 DEBUG : >WaitForWriters: 2025/07/04 03:54:05 ERROR : error listing: directory not found --- FAIL: TestWriteFileHandleFlush (1.55s) === RUN TestWriteFileHandleRelease run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:54:05 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:54:05 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:54:05 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:54:05 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:54:05 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:54:05 DEBUG : file1: >Open: fd=file1 (w), err= 2025/07/04 03:54:05 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/07/04 03:54:05 DEBUG : file1: WriteFileHandle.Release closing 2025/07/04 03:54:05 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:54:05 DEBUG : PikPak root 'rclone-test-tunokup2wonu': File to upload is small (0 bytes), uploading instead of streaming 2025/07/04 03:54: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:54:06 DEBUG : file1: Remove: 2025/07/04 03:54:06 DEBUG : Added virtual directory entry vDel: "file1" 2025/07/04 03:54:06 DEBUG : file1: >Remove: err= 2025/07/04 03:54:06 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:54:06 DEBUG : file1: WriteFileHandle.Release nothing to do 2025/07/04 03:54:06 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:54:06 DEBUG : Looking for writers 2025/07/04 03:54:06 DEBUG : >WaitForWriters: 2025/07/04 03:54:07 ERROR : error listing: directory not found --- FAIL: TestWriteFileHandleRelease (1.58s) === RUN TestWriteFileModTimeWithOpenWriters run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:54:07 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:54:07 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:54:07 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:54:07 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:54:07 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:54:07 DEBUG : file1: >Open: fd=file1 (w), err= 2025/07/04 03:54:07 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/07/04 03:54:07 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:54:07 DEBUG : PikPak root 'rclone-test-tunokup2wonu': File to upload is small (2 bytes), uploading instead of streaming 2025/07/04 03:54:08 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:54:08 DEBUG : file1: Remove: 2025/07/04 03:54:08 DEBUG : Added virtual directory entry vDel: "file1" 2025/07/04 03:54:08 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:54:08 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:54:08 DEBUG : Looking for writers 2025/07/04 03:54:08 DEBUG : >WaitForWriters: 2025/07/04 03:54:08 ERROR : error listing: directory not found --- FAIL: TestWriteFileModTimeWithOpenWriters (1.54s) === RUN TestFileReadAtZeroLength run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:54:08 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:54:08 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:54:08 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:54:09 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:54:09 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:54:09 DEBUG : file1: >Open: fd=file1 (w), err= 2025/07/04 03:54:09 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/07/04 03:54:09 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:54:09 DEBUG : PikPak root 'rclone-test-tunokup2wonu': File to upload is small (0 bytes), uploading instead of streaming 2025/07/04 03:54:10 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:54:10 DEBUG : file1: Remove: 2025/07/04 03:54:10 DEBUG : Added virtual directory entry vDel: "file1" 2025/07/04 03:54:10 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:54:10 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2025/07/04 03:54:10 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:54:10 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:54:10 DEBUG : Looking for writers 2025/07/04 03:54:10 DEBUG : >WaitForWriters: 2025/07/04 03:54:10 ERROR : error listing: directory not found --- FAIL: TestFileReadAtZeroLength (1.55s) === RUN TestFileReadAtNonZeroLength run.go:180: Remote "PikPak root 'rclone-test-tunokup2wonu'", Local "Local file system at /tmp/rclone3145784039", Modify Window "876000h0m0s" 2025/07/04 03:54:10 INFO : PikPak root 'rclone-test-tunokup2wonu': poll-interval is not supported by this remote 2025/07/04 03:54:10 NOTICE: PikPak root 'rclone-test-tunokup2wonu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/07/04 03:54:10 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/07/04 03:54:10 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/07/04 03:54:10 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:54:10 DEBUG : file1: >Open: fd=file1 (w), err= 2025/07/04 03:54:10 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/07/04 03:54:10 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/07/04 03:54:10 DEBUG : PikPak root 'rclone-test-tunokup2wonu': File to upload is small (100 bytes), uploading instead of streaming 2025/07/04 03:54:11 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:54:11 DEBUG : file1: Remove: 2025/07/04 03:54:11 DEBUG : Added virtual directory entry vDel: "file1" 2025/07/04 03:54:11 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:54:11 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2025/07/04 03:54:11 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:54:11 DEBUG : WaitForWriters: timeout=30s 2025/07/04 03:54:11 DEBUG : Looking for writers 2025/07/04 03:54:11 DEBUG : >WaitForWriters: 2025/07/04 03:54:11 ERROR : error listing: directory not found --- FAIL: TestFileReadAtNonZeroLength (1.55s) FAIL 2025/07/04 03:54:11 DEBUG : PikPak root 'rclone-test-tunokup2wonu': Purge remote 2025/07/04 03:54:12 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 5m57.063102679s (try 5/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]