"./vfs.test -test.v -test.timeout 1h0m0s -remote TestPcloud: -verbose" - Starting (try 1/5) 2026/01/01 03:59:37 DEBUG : Creating backend with remote "TestPcloud:rclone-test-vologop2dafa" 2026/01/01 03:59:37 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/01/01 03:59:44 DEBUG : Creating backend with remote "/tmp/rclone1249241989" === RUN TestDirHandleMethods run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 03:59:44 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 03:59:45 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 03:59:45 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 03:59:45 DEBUG : >changeNotify: 2026/01/01 03:59:45 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 03:59:45 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 03:59:45 DEBUG : >changeNotify: 2026/01/01 03:59:45 DEBUG : WaitForWriters: timeout=30s 2026/01/01 03:59:45 DEBUG : dir: Looking for writers 2026/01/01 03:59:45 DEBUG : Looking for writers 2026/01/01 03:59:45 DEBUG : dir: reading active writers 2026/01/01 03:59:45 DEBUG : >WaitForWriters: 2026/01/01 03:59:45 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 03:59:45 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 03:59:45 DEBUG : >changeNotify: --- PASS: TestDirHandleMethods (1.65s) === RUN TestDirHandleReaddir run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 03:59:46 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 03:59:46 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 03:59:46 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 03:59:46 DEBUG : >changeNotify: 2026/01/01 03:59:46 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 03:59:46 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 03:59:46 DEBUG : >changeNotify: 2026/01/01 03:59:46 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file2" (type: 1) 2026/01/01 03:59:46 DEBUG : changeNotify: relativePath="dir/file2", type=1 2026/01/01 03:59:46 DEBUG : >changeNotify: 2026/01/01 03:59:46 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/subdir" (type: 0) 2026/01/01 03:59:46 DEBUG : changeNotify: relativePath="dir/subdir", type=0 2026/01/01 03:59:46 DEBUG : >changeNotify: 2026/01/01 03:59:46 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/subdir/file3" (type: 1) 2026/01/01 03:59:46 DEBUG : changeNotify: relativePath="dir/subdir/file3", type=1 2026/01/01 03:59:46 DEBUG : >changeNotify: 2026/01/01 03:59:47 DEBUG : WaitForWriters: timeout=30s 2026/01/01 03:59:47 DEBUG : dir/subdir: Looking for writers 2026/01/01 03:59:47 DEBUG : dir: Looking for writers 2026/01/01 03:59:47 DEBUG : file1: reading active writers 2026/01/01 03:59:47 DEBUG : file2: reading active writers 2026/01/01 03:59:47 DEBUG : subdir: reading active writers 2026/01/01 03:59:47 DEBUG : Looking for writers 2026/01/01 03:59:47 DEBUG : dir: reading active writers 2026/01/01 03:59:47 DEBUG : >WaitForWriters: 2026/01/01 03:59:47 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/subdir/file3" (type: 1) 2026/01/01 03:59:47 DEBUG : changeNotify: relativePath="dir/subdir/file3", type=1 2026/01/01 03:59:47 DEBUG : >changeNotify: --- PASS: TestDirHandleReaddir (2.09s) === RUN TestDirHandleReaddirnames run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 03:59:48 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 03:59:48 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 03:59:48 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 03:59:48 DEBUG : >changeNotify: 2026/01/01 03:59:48 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 03:59:48 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 03:59:48 DEBUG : >changeNotify: 2026/01/01 03:59:48 DEBUG : WaitForWriters: timeout=30s 2026/01/01 03:59:48 DEBUG : dir: Looking for writers 2026/01/01 03:59:48 DEBUG : file1: reading active writers 2026/01/01 03:59:48 DEBUG : Looking for writers 2026/01/01 03:59:48 DEBUG : dir: reading active writers 2026/01/01 03:59:48 DEBUG : >WaitForWriters: 2026/01/01 03:59:49 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 03:59:49 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 03:59:49 DEBUG : dir: invalidating directory cache 2026/01/01 03:59:49 DEBUG : >changeNotify: --- PASS: TestDirHandleReaddirnames (1.10s) === RUN TestDirMethods run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 03:59:49 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 03:59:49 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 03:59:49 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 03:59:49 DEBUG : >changeNotify: 2026/01/01 03:59:49 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 03:59:49 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 03:59:49 DEBUG : >changeNotify: 2026/01/01 03:59:49 DEBUG : WaitForWriters: timeout=30s 2026/01/01 03:59:49 DEBUG : dir: Looking for writers 2026/01/01 03:59:49 DEBUG : Looking for writers 2026/01/01 03:59:49 DEBUG : dir: reading active writers 2026/01/01 03:59:49 DEBUG : >WaitForWriters: 2026/01/01 03:59:50 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 03:59:50 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 03:59:50 DEBUG : >changeNotify: --- PASS: TestDirMethods (1.00s) === RUN TestDirForgetAll run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 03:59:50 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 03:59:50 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 03:59:50 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 03:59:50 DEBUG : >changeNotify: 2026/01/01 03:59:50 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 03:59:50 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 03:59:50 DEBUG : >changeNotify: 2026/01/01 03:59:50 DEBUG : dir: forgetting directory cache 2026/01/01 03:59:50 DEBUG : forgetting directory cache 2026/01/01 03:59:50 DEBUG : dir: forgetting directory cache 2026/01/01 03:59:50 DEBUG : WaitForWriters: timeout=30s 2026/01/01 03:59:50 DEBUG : Looking for writers 2026/01/01 03:59:50 DEBUG : >WaitForWriters: 2026/01/01 03:59:51 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 03:59:51 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 03:59:51 DEBUG : >changeNotify: --- PASS: TestDirForgetAll (1.12s) === RUN TestDirForgetPath run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 03:59:51 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 03:59:51 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 03:59:51 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 03:59:51 DEBUG : >changeNotify: 2026/01/01 03:59:51 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 03:59:51 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 03:59:51 DEBUG : >changeNotify: 2026/01/01 03:59:52 DEBUG : ForgetPath: relativePath="dir/notfound", type=1 2026/01/01 03:59:52 DEBUG : dir: invalidating directory cache 2026/01/01 03:59:52 DEBUG : >ForgetPath: 2026/01/01 03:59:52 DEBUG : ForgetPath: relativePath="dir", type=0 2026/01/01 03:59:52 DEBUG : invalidating directory cache 2026/01/01 03:59:52 DEBUG : dir: forgetting directory cache 2026/01/01 03:59:52 DEBUG : >ForgetPath: 2026/01/01 03:59:52 DEBUG : ForgetPath: relativePath="not/in/cache", type=0 2026/01/01 03:59:52 DEBUG : >ForgetPath: 2026/01/01 03:59:52 DEBUG : WaitForWriters: timeout=30s 2026/01/01 03:59:52 DEBUG : dir: Looking for writers 2026/01/01 03:59:52 DEBUG : Looking for writers 2026/01/01 03:59:52 DEBUG : dir: reading active writers 2026/01/01 03:59:52 DEBUG : >WaitForWriters: 2026/01/01 03:59:52 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 03:59:52 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 03:59:52 DEBUG : >changeNotify: --- PASS: TestDirForgetPath (1.09s) === RUN TestDirWalk run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 03:59:52 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 03:59:52 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 03:59:52 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 03:59:52 DEBUG : >changeNotify: 2026/01/01 03:59:52 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 03:59:52 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 03:59:52 DEBUG : >changeNotify: 2026/01/01 03:59:53 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "fil" (type: 0) 2026/01/01 03:59:53 DEBUG : changeNotify: relativePath="fil", type=0 2026/01/01 03:59:53 DEBUG : invalidating directory cache 2026/01/01 03:59:53 DEBUG : >changeNotify: 2026/01/01 03:59:53 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "fil/a" (type: 0) 2026/01/01 03:59:53 DEBUG : changeNotify: relativePath="fil/a", type=0 2026/01/01 03:59:53 DEBUG : >changeNotify: 2026/01/01 03:59:53 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "fil/a/b" (type: 0) 2026/01/01 03:59:53 DEBUG : changeNotify: relativePath="fil/a/b", type=0 2026/01/01 03:59:53 DEBUG : >changeNotify: 2026/01/01 03:59:53 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "fil/a/b/c" (type: 1) 2026/01/01 03:59:53 DEBUG : changeNotify: relativePath="fil/a/b/c", type=1 2026/01/01 03:59:53 DEBUG : >changeNotify: 2026/01/01 03:59:54 DEBUG : forgetting directory cache 2026/01/01 03:59:54 DEBUG : dir: forgetting directory cache 2026/01/01 03:59:54 DEBUG : WaitForWriters: timeout=30s 2026/01/01 03:59:54 DEBUG : dir: Looking for writers 2026/01/01 03:59:54 DEBUG : fil/a/b: Looking for writers 2026/01/01 03:59:54 DEBUG : fil/a: Looking for writers 2026/01/01 03:59:54 DEBUG : b: reading active writers 2026/01/01 03:59:54 DEBUG : fil: Looking for writers 2026/01/01 03:59:54 DEBUG : a: reading active writers 2026/01/01 03:59:54 DEBUG : Looking for writers 2026/01/01 03:59:54 DEBUG : dir: reading active writers 2026/01/01 03:59:54 DEBUG : fil: reading active writers 2026/01/01 03:59:54 DEBUG : >WaitForWriters: 2026/01/01 03:59:54 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 03:59:54 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 03:59:54 DEBUG : >changeNotify: --- PASS: TestDirWalk (2.70s) === RUN TestDirSetModTime run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 03:59:55 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 03:59:55 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 03:59:55 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 03:59:55 DEBUG : >changeNotify: 2026/01/01 03:59:55 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 03:59:55 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 03:59:55 DEBUG : >changeNotify: 2026/01/01 03:59:55 DEBUG : WaitForWriters: timeout=30s 2026/01/01 03:59:55 DEBUG : dir: Looking for writers 2026/01/01 03:59:55 DEBUG : Looking for writers 2026/01/01 03:59:55 DEBUG : dir: reading active writers 2026/01/01 03:59:55 DEBUG : >WaitForWriters: 2026/01/01 03:59:55 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 03:59:55 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 03:59:55 DEBUG : >changeNotify: --- PASS: TestDirSetModTime (1.00s) === RUN TestDirStat run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 03:59:56 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 03:59:56 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 03:59:56 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 03:59:56 DEBUG : >changeNotify: 2026/01/01 03:59:56 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 03:59:56 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 03:59:56 DEBUG : >changeNotify: 2026/01/01 03:59:56 DEBUG : WaitForWriters: timeout=30s 2026/01/01 03:59:56 DEBUG : dir: Looking for writers 2026/01/01 03:59:56 DEBUG : file1: reading active writers 2026/01/01 03:59:56 DEBUG : Looking for writers 2026/01/01 03:59:56 DEBUG : dir: reading active writers 2026/01/01 03:59:56 DEBUG : >WaitForWriters: 2026/01/01 03:59:57 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 03:59:57 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 03:59:57 DEBUG : dir: invalidating directory cache 2026/01/01 03:59:57 DEBUG : >changeNotify: --- PASS: TestDirStat (1.10s) === RUN TestDirReadDirAll run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 03:59:57 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 03:59:57 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 03:59:57 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 03:59:57 DEBUG : >changeNotify: 2026/01/01 03:59:57 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 03:59:57 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 03:59:57 DEBUG : >changeNotify: 2026/01/01 03:59:57 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file2" (type: 1) 2026/01/01 03:59:57 DEBUG : changeNotify: relativePath="dir/file2", type=1 2026/01/01 03:59:57 DEBUG : >changeNotify: 2026/01/01 03:59:57 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/subdir" (type: 0) 2026/01/01 03:59:57 DEBUG : changeNotify: relativePath="dir/subdir", type=0 2026/01/01 03:59:57 DEBUG : >changeNotify: 2026/01/01 03:59:58 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/subdir/file3" (type: 1) 2026/01/01 03:59:58 DEBUG : changeNotify: relativePath="dir/subdir/file3", type=1 2026/01/01 03:59:58 DEBUG : >changeNotify: === RUN TestDirReadDirAll/Virtual 2026/01/01 03:59:58 DEBUG : dir: Added virtual directory entry vAddFile: "virtualFile" 2026/01/01 03:59:58 DEBUG : dir: Added virtual directory entry vAddDir: "virtualDir" 2026/01/01 03:59:58 DEBUG : dir: Added virtual directory entry vDel: "file2" 2026/01/01 03:59:58 DEBUG : dir: Added virtual directory entry vDel: "subdir" 2026/01/01 03:59:58 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/virtualFile" (type: 1) 2026/01/01 03:59:58 DEBUG : changeNotify: relativePath="dir/virtualFile", type=1 2026/01/01 03:59:58 DEBUG : dir: invalidating directory cache 2026/01/01 03:59:58 DEBUG : >changeNotify: 2026/01/01 03:59:59 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/virtualDir" (type: 0) 2026/01/01 03:59:59 DEBUG : changeNotify: relativePath="dir/virtualDir", type=0 2026/01/01 03:59:59 DEBUG : >changeNotify: 2026/01/01 03:59:59 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/virtualDir/testFile" (type: 1) 2026/01/01 03:59:59 DEBUG : changeNotify: relativePath="dir/virtualDir/testFile", type=1 2026/01/01 03:59:59 DEBUG : >changeNotify: 2026/01/01 03:59:59 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file2" (type: 1) 2026/01/01 03:59:59 DEBUG : changeNotify: relativePath="dir/file2", type=1 2026/01/01 03:59:59 DEBUG : >changeNotify: 2026/01/01 03:59:59 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/subdir" (type: 0) 2026/01/01 03:59:59 DEBUG : changeNotify: relativePath="dir/subdir", type=0 2026/01/01 03:59:59 DEBUG : dir: Removed virtual directory entry vDel: "file2" 2026/01/01 03:59:59 DEBUG : dir: Removed virtual directory entry vDel: "subdir" 2026/01/01 03:59:59 DEBUG : dir: Removed virtual directory entry vAddDir: "virtualDir" 2026/01/01 03:59:59 DEBUG : dir/file1: Reset virtual modtime 2026/01/01 03:59:59 DEBUG : dir: Removed virtual directory entry vAddFile: "virtualFile" 2026/01/01 03:59:59 DEBUG : dir/virtualFile: Reset virtual modtime 2026/01/01 03:59:59 DEBUG : dir: Added virtual directory entry vAddFile: "virtualFile2" 2026/01/01 03:59:59 DEBUG : dir: Added virtual directory entry vAddDir: "virtualDir2" 2026/01/01 03:59:59 DEBUG : dir: Added virtual directory entry vDel: "file1" 2026/01/01 03:59:59 DEBUG : dir: invalidating directory cache 2026/01/01 03:59:59 DEBUG : dir: Removed virtual directory entry vAddDir: "virtualDir2" 2026/01/01 03:59:59 DEBUG : dir: Removed virtual directory entry vDel: "file1" 2026/01/01 03:59:59 DEBUG : dir/virtualFile: Reset virtual modtime 2026/01/01 03:59:59 DEBUG : dir: invalidating directory cache 2026/01/01 03:59:59 DEBUG : >changeNotify: 2026/01/01 03:59:59 DEBUG : forgetting directory cache 2026/01/01 03:59:59 DEBUG : dir: forgetting directory cache 2026/01/01 03:59:59 DEBUG : dir/virtualDir: forgetting directory cache 2026/01/01 03:59:59 DEBUG : dir/file1: Reset virtual modtime 2026/01/01 03:59:59 DEBUG : dir/virtualFile: Reset virtual modtime 2026/01/01 03:59:59 DEBUG : WaitForWriters: timeout=30s 2026/01/01 03:59:59 DEBUG : dir/virtualDir: Looking for writers 2026/01/01 03:59:59 DEBUG : dir: Looking for writers 2026/01/01 03:59:59 DEBUG : file1: reading active writers 2026/01/01 03:59:59 DEBUG : virtualFile2: reading active writers 2026/01/01 03:59:59 DEBUG : virtualFile: reading active writers 2026/01/01 03:59:59 DEBUG : virtualDir: reading active writers 2026/01/01 03:59:59 DEBUG : Looking for writers 2026/01/01 03:59:59 DEBUG : dir: reading active writers 2026/01/01 03:59:59 DEBUG : >WaitForWriters: 2026/01/01 04:00:00 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/virtualDir/testFile" (type: 1) 2026/01/01 04:00:00 DEBUG : changeNotify: relativePath="dir/virtualDir/testFile", type=1 2026/01/01 04:00:00 DEBUG : >changeNotify: --- PASS: TestDirReadDirAll (3.27s) --- PASS: TestDirReadDirAll/Virtual (1.07s) === RUN TestDirOpen run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:00 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 04:00:00 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:00 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:00 DEBUG : >changeNotify: 2026/01/01 04:00:00 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:00 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:00 DEBUG : >changeNotify: 2026/01/01 04:00:01 ERROR : dir/: Can only open directories read only 2026/01/01 04:00:01 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:01 DEBUG : dir: Looking for writers 2026/01/01 04:00:01 DEBUG : Looking for writers 2026/01/01 04:00:01 DEBUG : dir: reading active writers 2026/01/01 04:00:01 DEBUG : >WaitForWriters: 2026/01/01 04:00:01 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:01 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:01 DEBUG : >changeNotify: --- PASS: TestDirOpen (1.01s) === RUN TestDirCreate run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:01 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 04:00:01 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:01 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:01 DEBUG : >changeNotify: 2026/01/01 04:00:01 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:01 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:01 DEBUG : >changeNotify: fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache fstest.go:292: Sleeping for 6s just to make sure 2026/01/01 04:00:09 DEBUG : dir/potato: Open: flags=O_WRONLY|O_CREATE 2026/01/01 04:00:09 DEBUG : dir: Added virtual directory entry vAddFile: "potato" 2026/01/01 04:00:09 DEBUG : dir/potato: >Open: fd=dir/potato (w), err= 2026/01/01 04:00:09 DEBUG : dir: Added virtual directory entry vAddFile: "potato" 2026/01/01 04:00:09 DEBUG : pcloud root 'rclone-test-vologop2dafa': File to upload is small (5 bytes), uploading instead of streaming 2026/01/01 04:00:10 DEBUG : dir/potato: size = 5 OK 2026/01/01 04:00:10 DEBUG : dir/potato: sha1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2026/01/01 04:00:10 DEBUG : dir/potato: Size and sha1 of src and dst objects identical 2026/01/01 04:00:10 DEBUG : dir: Added virtual directory entry vAddFile: "potato" 2026/01/01 04:00:10 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:10 DEBUG : dir: Looking for writers 2026/01/01 04:00:10 DEBUG : file1: reading active writers 2026/01/01 04:00:10 DEBUG : potato: reading active writers 2026/01/01 04:00:10 DEBUG : Looking for writers 2026/01/01 04:00:10 DEBUG : dir: reading active writers 2026/01/01 04:00:10 DEBUG : >WaitForWriters: 2026/01/01 04:00:10 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/potato" (type: 1) 2026/01/01 04:00:10 DEBUG : changeNotify: relativePath="dir/potato", type=1 2026/01/01 04:00:10 DEBUG : dir: invalidating directory cache 2026/01/01 04:00:10 DEBUG : >changeNotify: --- PASS: TestDirCreate (9.00s) === RUN TestDirMkdir run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:10 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 04:00:10 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:10 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:10 DEBUG : >changeNotify: 2026/01/01 04:00:10 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:10 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:10 DEBUG : >changeNotify: 2026/01/01 04:00:11 DEBUG : dir: Added virtual directory entry vAddDir: "sub" 2026/01/01 04:00:11 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/sub" (type: 0) 2026/01/01 04:00:11 DEBUG : changeNotify: relativePath="dir/sub", type=0 2026/01/01 04:00:11 DEBUG : dir: invalidating directory cache 2026/01/01 04:00:11 DEBUG : dir/sub: invalidating directory cache 2026/01/01 04:00:11 DEBUG : >changeNotify: 2026/01/01 04:00:11 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:11 DEBUG : dir/sub: Looking for writers 2026/01/01 04:00:11 DEBUG : dir: Looking for writers 2026/01/01 04:00:11 DEBUG : file1: reading active writers 2026/01/01 04:00:11 DEBUG : sub: reading active writers 2026/01/01 04:00:11 DEBUG : Looking for writers 2026/01/01 04:00:11 DEBUG : dir: reading active writers 2026/01/01 04:00:11 DEBUG : >WaitForWriters: 2026/01/01 04:00:12 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:12 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:12 DEBUG : >changeNotify: --- PASS: TestDirMkdir (1.82s) === RUN TestDirMkdirSub run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:12 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 04:00:12 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:12 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:12 DEBUG : >changeNotify: 2026/01/01 04:00:12 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:12 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:12 DEBUG : >changeNotify: 2026/01/01 04:00:13 DEBUG : dir: Added virtual directory entry vAddDir: "sub" 2026/01/01 04:00:13 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/sub" (type: 0) 2026/01/01 04:00:13 DEBUG : changeNotify: relativePath="dir/sub", type=0 2026/01/01 04:00:13 DEBUG : dir: invalidating directory cache 2026/01/01 04:00:13 DEBUG : dir/sub: invalidating directory cache 2026/01/01 04:00:13 DEBUG : >changeNotify: 2026/01/01 04:00:13 DEBUG : dir/sub: Added virtual directory entry vAddDir: "subsub" 2026/01/01 04:00:13 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/sub/subsub" (type: 0) 2026/01/01 04:00:13 DEBUG : changeNotify: relativePath="dir/sub/subsub", type=0 2026/01/01 04:00:13 DEBUG : dir: Removed virtual directory entry vAddDir: "sub" 2026/01/01 04:00:13 DEBUG : dir/file1: Reset virtual modtime 2026/01/01 04:00:13 DEBUG : dir/sub: Removed virtual directory entry vAddDir: "subsub" 2026/01/01 04:00:13 DEBUG : dir/sub: invalidating directory cache 2026/01/01 04:00:13 DEBUG : dir/sub/subsub: invalidating directory cache 2026/01/01 04:00:13 DEBUG : >changeNotify: 2026/01/01 04:00:14 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:14 DEBUG : dir/sub/subsub: Looking for writers 2026/01/01 04:00:14 DEBUG : dir/sub: Looking for writers 2026/01/01 04:00:14 DEBUG : subsub: reading active writers 2026/01/01 04:00:14 DEBUG : dir: Looking for writers 2026/01/01 04:00:14 DEBUG : file1: reading active writers 2026/01/01 04:00:14 DEBUG : sub: reading active writers 2026/01/01 04:00:14 DEBUG : Looking for writers 2026/01/01 04:00:14 DEBUG : dir: reading active writers 2026/01/01 04:00:14 DEBUG : >WaitForWriters: 2026/01/01 04:00:14 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:14 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:14 DEBUG : dir: invalidating directory cache 2026/01/01 04:00:14 DEBUG : >changeNotify: --- PASS: TestDirMkdirSub (2.34s) === RUN TestDirRemove run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:14 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 04:00:14 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:14 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:14 DEBUG : >changeNotify: 2026/01/01 04:00:15 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:15 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:15 DEBUG : >changeNotify: 2026/01/01 04:00:15 ERROR : dir/: Dir.Remove not empty 2026/01/01 04:00:15 DEBUG : dir/file1: Remove: 2026/01/01 04:00:15 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:15 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:15 DEBUG : dir: invalidating directory cache 2026/01/01 04:00:15 DEBUG : >changeNotify: 2026/01/01 04:00:15 DEBUG : dir: Added virtual directory entry vDel: "file1" 2026/01/01 04:00:15 DEBUG : dir/file1: >Remove: err= 2026/01/01 04:00:15 DEBUG : dir: Removed virtual directory entry vDel: "file1" 2026/01/01 04:00:15 DEBUG : Added virtual directory entry vDel: "dir" 2026/01/01 04:00:15 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:15 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:15 DEBUG : invalidating directory cache 2026/01/01 04:00:15 DEBUG : >changeNotify: 2026/01/01 04:00:15 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:15 DEBUG : Looking for writers 2026/01/01 04:00:15 DEBUG : >WaitForWriters: --- PASS: TestDirRemove (1.36s) === RUN TestDirRemoveAll run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:16 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 04:00:16 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:16 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:16 DEBUG : >changeNotify: 2026/01/01 04:00:16 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:16 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:16 DEBUG : >changeNotify: 2026/01/01 04:00:16 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:16 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:16 DEBUG : >changeNotify: 2026/01/01 04:00:16 DEBUG : dir/file1: Remove: 2026/01/01 04:00:16 DEBUG : dir: Added virtual directory entry vDel: "file1" 2026/01/01 04:00:16 DEBUG : dir/file1: >Remove: err= 2026/01/01 04:00:16 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:16 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:16 DEBUG : dir: invalidating directory cache 2026/01/01 04:00:16 DEBUG : >changeNotify: 2026/01/01 04:00:17 DEBUG : Added virtual directory entry vDel: "dir" 2026/01/01 04:00:17 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:17 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:17 DEBUG : invalidating directory cache 2026/01/01 04:00:17 DEBUG : >changeNotify: 2026/01/01 04:00:17 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:17 DEBUG : Looking for writers 2026/01/01 04:00:17 DEBUG : >WaitForWriters: --- PASS: TestDirRemoveAll (1.25s) === RUN TestDirRemoveName run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:17 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 04:00:17 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:17 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:17 DEBUG : >changeNotify: 2026/01/01 04:00:17 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:17 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:17 DEBUG : >changeNotify: 2026/01/01 04:00:17 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:17 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:17 DEBUG : >changeNotify: 2026/01/01 04:00:18 DEBUG : dir/file1: Remove: 2026/01/01 04:00:18 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:18 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:18 DEBUG : dir: invalidating directory cache 2026/01/01 04:00:18 DEBUG : >changeNotify: 2026/01/01 04:00:18 DEBUG : dir: Added virtual directory entry vDel: "file1" 2026/01/01 04:00:18 DEBUG : dir/file1: >Remove: err= 2026/01/01 04:00:18 DEBUG : dir: Removed virtual directory entry vDel: "file1" 2026/01/01 04:00:18 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:18 DEBUG : dir: Looking for writers 2026/01/01 04:00:18 DEBUG : Looking for writers 2026/01/01 04:00:18 DEBUG : dir: reading active writers 2026/01/01 04:00:18 DEBUG : >WaitForWriters: 2026/01/01 04:00:18 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:18 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:18 DEBUG : invalidating directory cache 2026/01/01 04:00:18 DEBUG : dir: invalidating directory cache 2026/01/01 04:00:18 DEBUG : >changeNotify: --- PASS: TestDirRemoveName (1.40s) === RUN TestDirRename run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:18 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 04:00:18 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:18 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:18 DEBUG : >changeNotify: 2026/01/01 04:00:19 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:19 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:19 DEBUG : >changeNotify: 2026/01/01 04:00:19 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file3" (type: 1) 2026/01/01 04:00:19 DEBUG : changeNotify: relativePath="dir/file3", type=1 2026/01/01 04:00:19 DEBUG : >changeNotify: 2026/01/01 04:00:19 ERROR : dir/not found: Dir.Rename error: file does not exist 2026/01/01 04:00:20 DEBUG : dir: Updating dir with dir2 0xc0006685b0 2026/01/01 04:00:20 DEBUG : dir: forgetting directory cache 2026/01/01 04:00:20 DEBUG : Added virtual directory entry vDel: "dir" 2026/01/01 04:00:20 DEBUG : Added virtual directory entry vAddDir: "dir2" 2026/01/01 04:00:20 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir2" (type: 0) 2026/01/01 04:00:20 DEBUG : changeNotify: relativePath="dir2", type=0 2026/01/01 04:00:20 DEBUG : invalidating directory cache 2026/01/01 04:00:20 DEBUG : dir2: invalidating directory cache 2026/01/01 04:00:20 DEBUG : >changeNotify: 2026/01/01 04:00:20 DEBUG : Removed virtual directory entry vAddDir: "dir2" 2026/01/01 04:00:20 DEBUG : Removed virtual directory entry vDel: "dir" 2026/01/01 04:00:20 DEBUG : dir2/file1: Reset virtual modtime 2026/01/01 04:00:20 DEBUG : dir2/file3: Reset virtual modtime 2026/01/01 04:00:21 INFO : dir2/file1: Moved (server-side) to: file2 2026/01/01 04:00:21 DEBUG : file2: Updating file with file2 0xc0001a3200 2026/01/01 04:00:21 DEBUG : dir2: Added virtual directory entry vDel: "file1" 2026/01/01 04:00:21 DEBUG : Added virtual directory entry vAddFile: "file2" 2026/01/01 04:00:21 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "file2" (type: 1) 2026/01/01 04:00:21 DEBUG : changeNotify: relativePath="file2", type=1 2026/01/01 04:00:21 DEBUG : invalidating directory cache 2026/01/01 04:00:21 DEBUG : >changeNotify: 2026/01/01 04:00:21 DEBUG : Removed virtual directory entry vAddFile: "file2" 2026/01/01 04:00:21 DEBUG : file2: Reset virtual modtime 2026/01/01 04:00:21 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir2/file3" (type: 1) 2026/01/01 04:00:21 DEBUG : changeNotify: relativePath="dir2/file3", type=1 2026/01/01 04:00:21 DEBUG : dir2: invalidating directory cache 2026/01/01 04:00:21 DEBUG : >changeNotify: 2026/01/01 04:00:21 INFO : dir2/file3: Deleted 2026/01/01 04:00:21 INFO : file2: Moved (server-side) to: dir2/file3 2026/01/01 04:00:21 DEBUG : dir2/file3: Updating file with dir2/file3 0xc0001a3200 2026/01/01 04:00:21 DEBUG : Added virtual directory entry vDel: "file2" 2026/01/01 04:00:21 DEBUG : dir2: Added virtual directory entry vAddFile: "file3" 2026/01/01 04:00:21 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir2/file3" (type: 1) 2026/01/01 04:00:21 DEBUG : changeNotify: relativePath="dir2/file3", type=1 2026/01/01 04:00:21 DEBUG : dir2: Removed virtual directory entry vDel: "file1" 2026/01/01 04:00:21 DEBUG : dir2: Removed virtual directory entry vAddFile: "file3" 2026/01/01 04:00:21 DEBUG : dir2/file3: Reset virtual modtime 2026/01/01 04:00:21 DEBUG : dir2: invalidating directory cache 2026/01/01 04:00:21 DEBUG : >changeNotify: 2026/01/01 04:00:22 DEBUG : Added virtual directory entry vAddDir: "empty directory" 2026/01/01 04:00:22 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "empty directory" (type: 0) 2026/01/01 04:00:22 DEBUG : changeNotify: relativePath="empty directory", type=0 2026/01/01 04:00:22 DEBUG : invalidating directory cache 2026/01/01 04:00:22 DEBUG : >changeNotify: 2026/01/01 04:00:22 DEBUG : empty directory: Updating dir with renamed empty directory 0xc0005668f0 2026/01/01 04:00:22 DEBUG : empty directory: forgetting directory cache 2026/01/01 04:00:22 DEBUG : Added virtual directory entry vDel: "empty directory" 2026/01/01 04:00:22 DEBUG : Added virtual directory entry vAddDir: "renamed empty directory" 2026/01/01 04:00:22 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "renamed empty directory" (type: 0) 2026/01/01 04:00:22 DEBUG : changeNotify: relativePath="renamed empty directory", type=0 2026/01/01 04:00:22 DEBUG : Removed virtual directory entry vDel: "file2" 2026/01/01 04:00:22 DEBUG : Removed virtual directory entry vDel: "empty directory" 2026/01/01 04:00:22 DEBUG : Removed virtual directory entry vAddDir: "renamed empty directory" 2026/01/01 04:00:22 DEBUG : dir2: Renaming to "dir3" 2026/01/01 04:00:22 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:22 DEBUG : dir3: Looking for writers 2026/01/01 04:00:22 DEBUG : file3: reading active writers 2026/01/01 04:00:22 DEBUG : renamed empty directory: Looking for writers 2026/01/01 04:00:22 DEBUG : Looking for writers 2026/01/01 04:00:22 DEBUG : dir3: reading active writers 2026/01/01 04:00:22 DEBUG : renamed empty directory: reading active writers 2026/01/01 04:00:22 DEBUG : >WaitForWriters: 2026/01/01 04:00:22 DEBUG : invalidating directory cache 2026/01/01 04:00:22 DEBUG : >changeNotify: --- PASS: TestDirRename (4.36s) === RUN TestDirStructSize dir_test.go:611: Dir struct has size 200 bytes --- PASS: TestDirStructSize (0.00s) === RUN TestDirFileOpen run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:23 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 04:00:23 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:23 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:23 DEBUG : >changeNotify: 2026/01/01 04:00:23 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:23 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:23 DEBUG : >changeNotify: 2026/01/01 04:00:24 DEBUG : dir: Added virtual directory entry vAddDir: "sub" 2026/01/01 04:00:24 DEBUG : dir/sub/file0: OpenFile: flags=O_RDWR|O_CREATE|O_TRUNC, perm=-rw-rw-rw- 2026/01/01 04:00:24 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/sub" (type: 0) 2026/01/01 04:00:24 DEBUG : changeNotify: relativePath="dir/sub", type=0 2026/01/01 04:00:24 DEBUG : dir: invalidating directory cache 2026/01/01 04:00:24 DEBUG : dir/sub: invalidating directory cache 2026/01/01 04:00:24 DEBUG : >changeNotify: 2026/01/01 04:00:24 DEBUG : dir: Removed virtual directory entry vAddDir: "sub" 2026/01/01 04:00:24 DEBUG : dir/file1: Reset virtual modtime 2026/01/01 04:00:24 DEBUG : dir/sub/file0: Open: flags=O_RDWR|O_CREATE|O_TRUNC 2026/01/01 04:00:24 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file0" 2026/01/01 04:00:24 DEBUG : dir/sub/file0: >Open: fd=dir/sub/file0 (w), err= 2026/01/01 04:00:24 DEBUG : dir/sub/file0: >OpenFile: fd=dir/sub/file0 (w), err= 2026/01/01 04:00:24 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file0" 2026/01/01 04:00:24 DEBUG : dir/sub/file2: OpenFile: flags=O_RDWR|O_CREATE|O_TRUNC, perm=-rw-rw-rw- 2026/01/01 04:00:24 DEBUG : dir/sub/file2: Open: flags=O_RDWR|O_CREATE|O_TRUNC 2026/01/01 04:00:24 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file2" 2026/01/01 04:00:24 DEBUG : dir/sub/file2: >Open: fd=dir/sub/file2 (w), err= 2026/01/01 04:00:24 DEBUG : dir/sub/file2: >OpenFile: fd=dir/sub/file2 (w), err= 2026/01/01 04:00:24 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file2" 2026/01/01 04:00:24 DEBUG : pcloud root 'rclone-test-vologop2dafa': File to upload is small (12 bytes), uploading instead of streaming 2026/01/01 04:00:24 DEBUG : dir/sub/file2: size = 12 OK 2026/01/01 04:00:24 DEBUG : dir/sub/file2: sha1 = 430ce34d020724ed75a196dfc2ad67c77772d169 OK 2026/01/01 04:00:24 DEBUG : dir/sub/file2: Size and sha1 of src and dst objects identical 2026/01/01 04:00:24 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file2" 2026/01/01 04:00:24 DEBUG : forgetting directory cache 2026/01/01 04:00:24 DEBUG : dir: forgetting directory cache 2026/01/01 04:00:24 DEBUG : dir/sub: forgetting directory cache 2026/01/01 04:00:24 DEBUG : dir/sub: Removed virtual directory entry vAddFile: "file2" 2026/01/01 04:00:24 DEBUG : pcloud root 'rclone-test-vologop2dafa': File to upload is small (5 bytes), uploading instead of streaming 2026/01/01 04:00:24 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/sub/file2" (type: 1) 2026/01/01 04:00:24 DEBUG : changeNotify: relativePath="dir/sub/file2", type=1 2026/01/01 04:00:24 DEBUG : dir/sub: invalidating directory cache 2026/01/01 04:00:24 DEBUG : >changeNotify: 2026/01/01 04:00:24 DEBUG : dir/sub/file0: size = 5 OK 2026/01/01 04:00:24 DEBUG : dir/sub/file0: sha1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2026/01/01 04:00:24 DEBUG : dir/sub/file0: Size and sha1 of src and dst objects identical 2026/01/01 04:00:24 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file0" 2026/01/01 04:00:24 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:24 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/sub/file0" (type: 1) 2026/01/01 04:00:24 DEBUG : changeNotify: relativePath="dir/sub/file0", type=1 2026/01/01 04:00:24 DEBUG : dir/sub: Looking for writers 2026/01/01 04:00:24 DEBUG : file0: reading active writers 2026/01/01 04:00:24 DEBUG : file2: reading active writers 2026/01/01 04:00:24 DEBUG : dir: Looking for writers 2026/01/01 04:00:24 DEBUG : file1: reading active writers 2026/01/01 04:00:24 DEBUG : sub: reading active writers 2026/01/01 04:00:24 DEBUG : Looking for writers 2026/01/01 04:00:24 DEBUG : dir: reading active writers 2026/01/01 04:00:24 DEBUG : >WaitForWriters: 2026/01/01 04:00:24 DEBUG : >changeNotify: --- PASS: TestDirFileOpen (2.11s) === RUN TestDirEntryModTimeInvalidation run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:25 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream dir_test.go:666: Need DirModTimeUpdatesOnWrite 2026/01/01 04:00:25 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:25 DEBUG : Looking for writers 2026/01/01 04:00:25 DEBUG : >WaitForWriters: --- SKIP: TestDirEntryModTimeInvalidation (0.20s) === RUN TestDirMetadataExtension run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:25 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 04:00:25 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:25 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:25 DEBUG : >changeNotify: 2026/01/01 04:00:25 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:25 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:25 DEBUG : >changeNotify: 2026/01/01 04:00:26 DEBUG : dir: Added virtual directory entry vAddFile: "file1.metadata" 2026/01/01 04:00:26 DEBUG : dir/file1.metadata: OpenFile: flags=O_RDONLY, perm=---------- 2026/01/01 04:00:26 DEBUG : dir/file1.metadata: Open: flags=O_RDONLY 2026/01/01 04:00:26 DEBUG : dir/file1.metadata: >Open: fd=dir/file1.metadata (r), err= 2026/01/01 04:00:26 DEBUG : dir/file1.metadata: >OpenFile: fd=dir/file1.metadata (r), err= 2026/01/01 04:00:26 DEBUG : dir/file1.metadata: ChunkedReader.openRange at 0 length 134217728 2026/01/01 04:00:26 DEBUG : dir/file1.metadata: ChunkedReader.Read at 0 length 512 chunkOffset 0 chunkSize 134217728 2026/01/01 04:00:26 DEBUG : Added virtual directory entry vAddFile: "dir.metadata" 2026/01/01 04:00:26 DEBUG : dir.metadata: OpenFile: flags=O_RDONLY, perm=---------- 2026/01/01 04:00:26 DEBUG : dir.metadata: Open: flags=O_RDONLY 2026/01/01 04:00:26 DEBUG : dir.metadata: >Open: fd=dir.metadata (r), err= 2026/01/01 04:00:26 DEBUG : dir.metadata: >OpenFile: fd=dir.metadata (r), err= 2026/01/01 04:00:26 DEBUG : dir.metadata: ChunkedReader.openRange at 0 length 134217728 2026/01/01 04:00:26 DEBUG : dir.metadata: ChunkedReader.Read at 0 length 512 chunkOffset 0 chunkSize 134217728 2026/01/01 04:00:26 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:26 DEBUG : dir: Looking for writers 2026/01/01 04:00:26 DEBUG : file1: reading active writers 2026/01/01 04:00:26 DEBUG : file1.metadata: reading active writers 2026/01/01 04:00:26 DEBUG : Looking for writers 2026/01/01 04:00:26 DEBUG : dir: reading active writers 2026/01/01 04:00:26 DEBUG : dir.metadata: reading active writers 2026/01/01 04:00:26 DEBUG : >WaitForWriters: 2026/01/01 04:00:26 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:26 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:26 DEBUG : dir: invalidating directory cache 2026/01/01 04:00:26 DEBUG : >changeNotify: --- PASS: TestDirMetadataExtension (1.10s) === RUN TestErrorError --- PASS: TestErrorError (0.00s) === RUN TestFileMethods run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:26 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 04:00:26 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:26 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:26 DEBUG : >changeNotify: 2026/01/01 04:00:26 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:26 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:26 DEBUG : >changeNotify: 2026/01/01 04:00:27 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:27 DEBUG : dir: Looking for writers 2026/01/01 04:00:27 DEBUG : file1: reading active writers 2026/01/01 04:00:27 DEBUG : Looking for writers 2026/01/01 04:00:27 DEBUG : dir: reading active writers 2026/01/01 04:00:27 DEBUG : >WaitForWriters: 2026/01/01 04:00:27 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:27 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:27 DEBUG : dir: invalidating directory cache 2026/01/01 04:00:27 DEBUG : >changeNotify: --- PASS: TestFileMethods (1.11s) === RUN TestFileSetModTime === RUN TestFileSetModTime/cache=off,open=false,write=false run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:27 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 04:00:27 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:27 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:27 DEBUG : >changeNotify: 2026/01/01 04:00:27 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:27 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:27 DEBUG : >changeNotify: 2026/01/01 04:00:28 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "time_test" (type: 1) 2026/01/01 04:00:28 DEBUG : changeNotify: relativePath="time_test", type=1 2026/01/01 04:00:28 DEBUG : invalidating directory cache 2026/01/01 04:00:28 DEBUG : >changeNotify: 2026/01/01 04:00:28 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "time_test" (type: 1) 2026/01/01 04:00:28 DEBUG : changeNotify: relativePath="time_test", type=1 2026/01/01 04:00:28 DEBUG : >changeNotify: 2026/01/01 04:00:28 DEBUG : Can set mod time: true 2026/01/01 04:00:28 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "time_test" (type: 1) 2026/01/01 04:00:28 DEBUG : changeNotify: relativePath="time_test", type=1 2026/01/01 04:00:28 DEBUG : >changeNotify: 2026/01/01 04:00:28 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK 2026/01/01 04:00:28 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:28 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:28 DEBUG : dir: invalidating directory cache 2026/01/01 04:00:28 DEBUG : >changeNotify: 2026/01/01 04:00:28 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:28 DEBUG : dir: Looking for writers 2026/01/01 04:00:28 DEBUG : file1: reading active writers 2026/01/01 04:00:28 DEBUG : Looking for writers 2026/01/01 04:00:28 DEBUG : dir: reading active writers 2026/01/01 04:00:28 DEBUG : >WaitForWriters: 2026/01/01 04:00:29 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:29 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:29 DEBUG : >changeNotify: === RUN TestFileSetModTime/cache=off,open=true,write=false run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:29 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 04:00:29 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:29 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:29 DEBUG : >changeNotify: 2026/01/01 04:00:29 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:29 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:29 DEBUG : >changeNotify: 2026/01/01 04:00:29 DEBUG : dir/file1: Open: flags=O_WRONLY|O_TRUNC 2026/01/01 04:00:29 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err= 2026/01/01 04:00:29 DEBUG : dir: Added virtual directory entry vAddFile: "file1" 2026/01/01 04:00:29 DEBUG : pcloud root 'rclone-test-vologop2dafa': File to upload is small (0 bytes), uploading instead of streaming 2026/01/01 04:00:30 DEBUG : dir/file1: size = 0 OK 2026/01/01 04:00:30 DEBUG : dir/file1: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2026/01/01 04:00:30 DEBUG : dir/file1: Size and sha1 of src and dst objects identical 2026/01/01 04:00:30 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:30 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:30 DEBUG : dir: invalidating directory cache 2026/01/01 04:00:30 DEBUG : >changeNotify: 2026/01/01 04:00:30 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK 2026/01/01 04:00:30 DEBUG : dir: Added virtual directory entry vAddFile: "file1" 2026/01/01 04:00:30 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:30 DEBUG : dir: Looking for writers 2026/01/01 04:00:30 DEBUG : file1: reading active writers 2026/01/01 04:00:30 DEBUG : Looking for writers 2026/01/01 04:00:30 DEBUG : dir: reading active writers 2026/01/01 04:00:30 DEBUG : >WaitForWriters: 2026/01/01 04:00:30 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:30 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:30 DEBUG : >changeNotify: 2026/01/01 04:00:30 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:30 DEBUG : dir: Looking for writers 2026/01/01 04:00:30 DEBUG : file1: reading active writers 2026/01/01 04:00:30 DEBUG : Looking for writers 2026/01/01 04:00:30 DEBUG : dir: reading active writers 2026/01/01 04:00:30 DEBUG : >WaitForWriters: 2026/01/01 04:00:30 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:30 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:30 DEBUG : >changeNotify: === RUN TestFileSetModTime/cache=off,open=true,write=true run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:30 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 04:00:30 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:30 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:30 DEBUG : >changeNotify: 2026/01/01 04:00:31 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:31 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:31 DEBUG : >changeNotify: 2026/01/01 04:00:31 DEBUG : dir/file1: Open: flags=O_WRONLY|O_TRUNC 2026/01/01 04:00:31 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err= 2026/01/01 04:00:31 DEBUG : dir: Added virtual directory entry vAddFile: "file1" 2026/01/01 04:00:31 DEBUG : pcloud root 'rclone-test-vologop2dafa': File to upload is small (5 bytes), uploading instead of streaming 2026/01/01 04:00:31 DEBUG : dir/file1: size = 5 OK 2026/01/01 04:00:31 DEBUG : dir/file1: sha1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2026/01/01 04:00:31 DEBUG : dir/file1: Size and sha1 of src and dst objects identical 2026/01/01 04:00:31 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:31 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:31 DEBUG : dir: invalidating directory cache 2026/01/01 04:00:31 DEBUG : >changeNotify: 2026/01/01 04:00:31 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK 2026/01/01 04:00:31 DEBUG : dir: Added virtual directory entry vAddFile: "file1" 2026/01/01 04:00:31 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:31 DEBUG : dir: Looking for writers 2026/01/01 04:00:31 DEBUG : file1: reading active writers 2026/01/01 04:00:31 DEBUG : Looking for writers 2026/01/01 04:00:31 DEBUG : dir: reading active writers 2026/01/01 04:00:31 DEBUG : >WaitForWriters: 2026/01/01 04:00:31 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:31 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:31 DEBUG : >changeNotify: 2026/01/01 04:00:31 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:31 DEBUG : dir: Looking for writers 2026/01/01 04:00:31 DEBUG : file1: reading active writers 2026/01/01 04:00:31 DEBUG : Looking for writers 2026/01/01 04:00:31 DEBUG : dir: reading active writers 2026/01/01 04:00:31 DEBUG : >WaitForWriters: 2026/01/01 04:00:31 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:31 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:31 DEBUG : >changeNotify: === RUN TestFileSetModTime/cache=full,open=false,write=false run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:32 DEBUG : pcloud root 'rclone-test-vologop2dafa': vfs cache: root is "/home/rclone/.cache/rclone" 2026/01/01 04:00:32 DEBUG : pcloud root 'rclone-test-vologop2dafa': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPcloud/rclone-test-vologop2dafa" 2026/01/01 04:00:32 DEBUG : pcloud root 'rclone-test-vologop2dafa': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPcloud/rclone-test-vologop2dafa" 2026/01/01 04:00:32 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPcloud/rclone-test-vologop2dafa" 2026/01/01 04:00:32 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/01/01 04:00:32 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPcloud/rclone-test-vologop2dafa" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPcloud/rclone-test-vologop2dafa" 2026/01/01 04:00:32 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPcloud/rclone-test-vologop2dafa" 2026/01/01 04:00:32 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/01/01 04:00:32 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPcloud/rclone-test-vologop2dafa" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPcloud/rclone-test-vologop2dafa" 2026/01/01 04:00:32 INFO : pcloud root 'rclone-test-vologop2dafa': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2026/01/01 04:00:32 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:32 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:32 DEBUG : >changeNotify: 2026/01/01 04:00:32 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:32 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:32 DEBUG : >changeNotify: 2026/01/01 04:00:32 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK 2026/01/01 04:00:32 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:32 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:32 DEBUG : dir: invalidating directory cache 2026/01/01 04:00:32 DEBUG : >changeNotify: 2026/01/01 04:00:33 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:33 DEBUG : dir: Looking for writers 2026/01/01 04:00:33 DEBUG : file1: reading active writers 2026/01/01 04:00:33 DEBUG : Looking for writers 2026/01/01 04:00:33 DEBUG : dir: reading active writers 2026/01/01 04:00:33 DEBUG : >WaitForWriters: 2026/01/01 04:00:33 DEBUG : pcloud root 'rclone-test-vologop2dafa': vfs cache: cleaner exiting 2026/01/01 04:00:33 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:33 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:33 DEBUG : >changeNotify: === RUN TestFileSetModTime/cache=full,open=true,write=false run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:33 DEBUG : pcloud root 'rclone-test-vologop2dafa': vfs cache: root is "/home/rclone/.cache/rclone" 2026/01/01 04:00:33 DEBUG : pcloud root 'rclone-test-vologop2dafa': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPcloud/rclone-test-vologop2dafa" 2026/01/01 04:00:33 DEBUG : pcloud root 'rclone-test-vologop2dafa': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPcloud/rclone-test-vologop2dafa" 2026/01/01 04:00:33 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPcloud/rclone-test-vologop2dafa" 2026/01/01 04:00:33 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/01/01 04:00:33 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPcloud/rclone-test-vologop2dafa" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPcloud/rclone-test-vologop2dafa" 2026/01/01 04:00:33 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPcloud/rclone-test-vologop2dafa" 2026/01/01 04:00:33 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/01/01 04:00:33 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPcloud/rclone-test-vologop2dafa" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPcloud/rclone-test-vologop2dafa" 2026/01/01 04:00:33 INFO : pcloud root 'rclone-test-vologop2dafa': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2026/01/01 04:00:33 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:33 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:33 DEBUG : >changeNotify: 2026/01/01 04:00:33 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:33 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:33 DEBUG : >changeNotify: 2026/01/01 04:00:34 DEBUG : dir/file1: Open: flags=O_WRONLY 2026/01/01 04:00:34 DEBUG : dir/file1: newRWFileHandle: 2026/01/01 04:00:34 DEBUG : dir/file1: >newRWFileHandle: err= 2026/01/01 04:00:34 DEBUG : dir/file1: >Open: fd=dir/file1 (rw), err= 2026/01/01 04:00:34 DEBUG : dir/file1(0xc000c15500): close: 2026/01/01 04:00:34 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK 2026/01/01 04:00:34 DEBUG : dir/file1(0xc000c15500): >close: err= 2026/01/01 04:00:34 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:34 DEBUG : dir: Looking for writers 2026/01/01 04:00:34 DEBUG : file1: reading active writers 2026/01/01 04:00:34 DEBUG : Looking for writers 2026/01/01 04:00:34 DEBUG : dir: reading active writers 2026/01/01 04:00:34 DEBUG : >WaitForWriters: 2026/01/01 04:00:34 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:34 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:34 DEBUG : dir: invalidating directory cache 2026/01/01 04:00:34 DEBUG : >changeNotify: 2026/01/01 04:00:34 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:34 DEBUG : dir: Looking for writers 2026/01/01 04:00:34 DEBUG : file1: reading active writers 2026/01/01 04:00:34 DEBUG : Looking for writers 2026/01/01 04:00:34 DEBUG : dir: reading active writers 2026/01/01 04:00:34 DEBUG : >WaitForWriters: 2026/01/01 04:00:34 DEBUG : pcloud root 'rclone-test-vologop2dafa': vfs cache: cleaner exiting 2026/01/01 04:00:34 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:34 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:34 DEBUG : >changeNotify: === RUN TestFileSetModTime/cache=full,open=true,write=true run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:34 DEBUG : pcloud root 'rclone-test-vologop2dafa': vfs cache: root is "/home/rclone/.cache/rclone" 2026/01/01 04:00:34 DEBUG : pcloud root 'rclone-test-vologop2dafa': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestPcloud/rclone-test-vologop2dafa" 2026/01/01 04:00:34 DEBUG : pcloud root 'rclone-test-vologop2dafa': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestPcloud/rclone-test-vologop2dafa" 2026/01/01 04:00:34 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPcloud/rclone-test-vologop2dafa" 2026/01/01 04:00:34 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/01/01 04:00:34 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestPcloud/rclone-test-vologop2dafa" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestPcloud/rclone-test-vologop2dafa" 2026/01/01 04:00:34 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPcloud/rclone-test-vologop2dafa" 2026/01/01 04:00:34 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/01/01 04:00:34 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestPcloud/rclone-test-vologop2dafa" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestPcloud/rclone-test-vologop2dafa" 2026/01/01 04:00:34 INFO : pcloud root 'rclone-test-vologop2dafa': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2026/01/01 04:00:35 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir" (type: 0) 2026/01/01 04:00:35 DEBUG : changeNotify: relativePath="dir", type=0 2026/01/01 04:00:35 DEBUG : >changeNotify: 2026/01/01 04:00:35 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:35 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:35 DEBUG : >changeNotify: fstest.go:142: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:142 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:149 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:195 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:308 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:345 /home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:28 /home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:95 /home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:159 Error: Received unexpected error: failed to get hash: pcloud error: File not found. (2009) Test: TestFileSetModTime/cache=full,open=true,write=true 2026/01/01 04:00:35 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:35 DEBUG : Looking for writers 2026/01/01 04:00:35 DEBUG : >WaitForWriters: 2026/01/01 04:00:35 DEBUG : pcloud root 'rclone-test-vologop2dafa': vfs cache: cleaner exiting 2026/01/01 04:00:35 DEBUG : pcloud root 'rclone-test-vologop2dafa': ChangeNotify: detected change in "dir/file1" (type: 1) 2026/01/01 04:00:35 DEBUG : changeNotify: relativePath="dir/file1", type=1 2026/01/01 04:00:35 DEBUG : >changeNotify: --- FAIL: TestFileSetModTime (8.13s) --- PASS: TestFileSetModTime/cache=off,open=false,write=false (1.63s) --- PASS: TestFileSetModTime/cache=off,open=true,write=false (1.47s) --- PASS: TestFileSetModTime/cache=off,open=true,write=true (1.47s) --- PASS: TestFileSetModTime/cache=full,open=false,write=false (1.34s) --- PASS: TestFileSetModTime/cache=full,open=true,write=false (1.32s) --- FAIL: TestFileSetModTime/cache=full,open=true,write=true (0.91s) === RUN TestFileOpenRead run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:35 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:290: Failed to put "dir/file1" to "pcloud root 'rclone-test-vologop2dafa'": pcloud error: Directory does not exist. (2005) 2026/01/01 04:00:41 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:41 DEBUG : Looking for writers 2026/01/01 04:00:41 DEBUG : >WaitForWriters: --- FAIL: TestFileOpenRead (5.92s) === RUN TestFileOpenReadUnknownSize 2026/01/01 04:00:41 INFO : Mock file system at root: poll-interval is not supported by this remote 2026/01/01 04:00:41 NOTICE: Mock file system at root: --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 04:00:41 DEBUG : file.txt: ChunkedReader.openRange at 0 length 134217728 2026/01/01 04:00:41 DEBUG : file.txt: ChunkedReader.Read at 0 length 4096 chunkOffset 0 chunkSize 134217728 file_test.go:223: gotContents = "file contents" 2026/01/01 04:00:41 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:00:41 DEBUG : Looking for writers 2026/01/01 04:00:41 DEBUG : file.txt: reading active writers 2026/01/01 04:00:41 DEBUG : >WaitForWriters: --- PASS: TestFileOpenReadUnknownSize (0.00s) === RUN TestFileOpenWrite run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:00:41 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 04:02:58 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:02:58 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:03:00 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:03:01 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:03:02 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 1/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:05:07 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:05:07 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:05:07 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:05:08 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:05:09 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 2/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:07:15 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:07:15 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:07:15 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:07:16 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:07:17 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 3/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:09:22 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:09:22 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:09:22 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:09:24 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:09:25 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 4/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:09:45 DEBUG : forgetting directory cache 2026/01/01 04:09:45 DEBUG : dir: forgetting directory cache 2026/01/01 04:09:45 DEBUG : dir: forgetting directory cache 2026/01/01 04:09:47 DEBUG : forgetting directory cache 2026/01/01 04:09:47 DEBUG : dir: forgetting directory cache 2026/01/01 04:09:47 DEBUG : dir/subdir: forgetting directory cache 2026/01/01 04:09:48 DEBUG : forgetting directory cache 2026/01/01 04:09:48 DEBUG : dir: forgetting directory cache 2026/01/01 04:09:49 DEBUG : forgetting directory cache 2026/01/01 04:09:49 DEBUG : dir: forgetting directory cache 2026/01/01 04:09:49 DEBUG : dir: forgetting directory cache 2026/01/01 04:09:51 DEBUG : forgetting directory cache 2026/01/01 04:09:51 DEBUG : dir: forgetting directory cache 2026/01/01 04:09:54 DEBUG : forgetting directory cache 2026/01/01 04:09:54 DEBUG : dir: forgetting directory cache 2026/01/01 04:09:54 DEBUG : fil: forgetting directory cache 2026/01/01 04:09:54 DEBUG : fil/a: forgetting directory cache 2026/01/01 04:09:54 DEBUG : fil/a/b: forgetting directory cache 2026/01/01 04:09:54 DEBUG : dir: forgetting directory cache 2026/01/01 04:09:55 DEBUG : forgetting directory cache 2026/01/01 04:09:55 DEBUG : dir: forgetting directory cache 2026/01/01 04:09:55 DEBUG : dir: forgetting directory cache 2026/01/01 04:09:56 DEBUG : forgetting directory cache 2026/01/01 04:09:56 DEBUG : dir: forgetting directory cache 2026/01/01 04:09:58 DEBUG : dir/subdir: forgetting directory cache 2026/01/01 04:09:59 DEBUG : dir/virtualDir2: forgetting directory cache 2026/01/01 04:09:59 DEBUG : forgetting directory cache 2026/01/01 04:09:59 DEBUG : dir: forgetting directory cache 2026/01/01 04:09:59 DEBUG : dir/virtualDir: forgetting directory cache 2026/01/01 04:10:01 DEBUG : forgetting directory cache 2026/01/01 04:10:01 DEBUG : dir: forgetting directory cache 2026/01/01 04:10:09 DEBUG : forgetting directory cache 2026/01/01 04:10:09 DEBUG : dir: forgetting directory cache 2026/01/01 04:10:09 DEBUG : dir: Removed virtual directory entry vAddFile: "potato" 2026/01/01 04:10:11 DEBUG : forgetting directory cache 2026/01/01 04:10:11 DEBUG : dir: forgetting directory cache 2026/01/01 04:10:11 DEBUG : dir/sub: forgetting directory cache 2026/01/01 04:10:11 DEBUG : dir: Removed virtual directory entry vAddDir: "sub" 2026/01/01 04:10:12 DEBUG : forgetting directory cache 2026/01/01 04:10:12 DEBUG : dir: forgetting directory cache 2026/01/01 04:10:12 DEBUG : dir/sub: forgetting directory cache 2026/01/01 04:10:12 DEBUG : dir/sub/subsub: forgetting directory cache 2026/01/01 04:10:15 DEBUG : forgetting directory cache 2026/01/01 04:10:15 DEBUG : Removed virtual directory entry vDel: "dir" 2026/01/01 04:10:15 DEBUG : dir: forgetting directory cache 2026/01/01 04:10:16 DEBUG : forgetting directory cache 2026/01/01 04:10:16 DEBUG : Removed virtual directory entry vDel: "dir" 2026/01/01 04:10:16 DEBUG : dir: forgetting directory cache 2026/01/01 04:10:16 DEBUG : dir: Removed virtual directory entry vDel: "file1" 2026/01/01 04:10:17 DEBUG : forgetting directory cache 2026/01/01 04:10:17 DEBUG : dir: forgetting directory cache 2026/01/01 04:10:21 DEBUG : dir3: forgetting directory cache 2026/01/01 04:10:22 DEBUG : forgetting directory cache 2026/01/01 04:10:22 DEBUG : dir3: forgetting directory cache 2026/01/01 04:10:22 DEBUG : renamed empty directory: forgetting directory cache 2026/01/01 04:10:24 DEBUG : forgetting directory cache 2026/01/01 04:10:24 DEBUG : dir: forgetting directory cache 2026/01/01 04:10:24 DEBUG : dir/sub: forgetting directory cache 2026/01/01 04:10:24 DEBUG : dir/sub: Removed virtual directory entry vAddFile: "file0" 2026/01/01 04:10:24 DEBUG : dir: forgetting directory cache 2026/01/01 04:10:24 DEBUG : dir/sub: forgetting directory cache 2026/01/01 04:10:24 DEBUG : dir/sub: forgetting directory cache 2026/01/01 04:10:25 DEBUG : forgetting directory cache 2026/01/01 04:10:26 DEBUG : forgetting directory cache 2026/01/01 04:10:26 DEBUG : dir: forgetting directory cache 2026/01/01 04:10:26 DEBUG : dir: Removed virtual directory entry vAddFile: "file1.metadata" 2026/01/01 04:10:26 DEBUG : Removed virtual directory entry vAddFile: "dir.metadata" 2026/01/01 04:10:27 DEBUG : forgetting directory cache 2026/01/01 04:10:27 DEBUG : dir: forgetting directory cache 2026/01/01 04:10:28 DEBUG : forgetting directory cache 2026/01/01 04:10:28 DEBUG : dir: forgetting directory cache 2026/01/01 04:10:29 DEBUG : forgetting directory cache 2026/01/01 04:10:29 DEBUG : dir: forgetting directory cache 2026/01/01 04:10:29 DEBUG : dir: Removed virtual directory entry vAddFile: "file1" 2026/01/01 04:10:31 DEBUG : forgetting directory cache 2026/01/01 04:10:31 DEBUG : dir: forgetting directory cache 2026/01/01 04:10:31 DEBUG : dir: Removed virtual directory entry vAddFile: "file1" 2026/01/01 04:10:32 DEBUG : forgetting directory cache 2026/01/01 04:10:32 DEBUG : dir: forgetting directory cache 2026/01/01 04:10:34 DEBUG : forgetting directory cache 2026/01/01 04:10:34 DEBUG : dir: forgetting directory cache 2026/01/01 04:10:34 DEBUG : forgetting directory cache 2026/01/01 04:10:35 DEBUG : forgetting directory cache 2026/01/01 04:10:41 DEBUG : forgetting directory cache 2026/01/01 04:10:41 DEBUG : forgetting directory cache 2026/01/01 04:11:30 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:11:30 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:11:30 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:11:31 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:11:32 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 5/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:13:38 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:13:38 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:13:38 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:13:39 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:13:40 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 6/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:15:45 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:15:45 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:15:45 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:15:46 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:15:47 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 7/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:17:53 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:17:53 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:17:53 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:17:54 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:17:55 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 8/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:19:59 DEBUG : forgetting directory cache 2026/01/01 04:19:59 DEBUG : dir: forgetting directory cache 2026/01/01 04:19:59 DEBUG : dir: forgetting directory cache 2026/01/01 04:19:59 DEBUG : dir/virtualDir: forgetting directory cache 2026/01/01 04:19:59 DEBUG : dir/virtualDir: forgetting directory cache 2026/01/01 04:20:00 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:20:00 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:20:00 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:20:01 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:20:03 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 9/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:20:16 DEBUG : forgetting directory cache 2026/01/01 04:22:08 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:22:08 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:22:08 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:22:09 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:22:10 DEBUG : pacer: Reducing sleep to 10ms run.go:290: Failed to put "dir/file1" to "pcloud root 'rclone-test-vologop2dafa'": Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF 2026/01/01 04:22:13 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:22:13 DEBUG : Looking for writers 2026/01/01 04:22:13 DEBUG : >WaitForWriters: --- FAIL: TestFileOpenWrite (1292.41s) === RUN TestFileRemove run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:22:14 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 04:24:14 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:24:14 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:24:14 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:24:15 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:24:16 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 1/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:26:21 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:26:21 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:26:21 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:26:22 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:26:24 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 2/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:28:29 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:28:29 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:28:29 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:28:30 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:28:31 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 3/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:29:59 DEBUG : dir: forgetting directory cache 2026/01/01 04:29:59 DEBUG : dir/virtualDir: forgetting directory cache 2026/01/01 04:29:59 DEBUG : forgetting directory cache 2026/01/01 04:29:59 DEBUG : dir: forgetting directory cache 2026/01/01 04:29:59 DEBUG : dir/virtualDir: forgetting directory cache 2026/01/01 04:30:37 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:30:37 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:30:37 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:30:38 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:30:39 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 4/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:32:14 DEBUG : forgetting directory cache 2026/01/01 04:32:44 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:32:44 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:32:44 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:32:45 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:32:46 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 5/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:34:52 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:34:52 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:34:52 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:34:53 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:34:54 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 6/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:36:59 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:36:59 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:36:59 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:37:00 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:37:02 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 7/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:39:07 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:39:07 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:39:07 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:39:08 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:39:09 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 8/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:39:59 DEBUG : forgetting directory cache 2026/01/01 04:39:59 DEBUG : dir: forgetting directory cache 2026/01/01 04:39:59 DEBUG : dir: forgetting directory cache 2026/01/01 04:39:59 DEBUG : dir/virtualDir: forgetting directory cache 2026/01/01 04:39:59 DEBUG : dir/virtualDir: forgetting directory cache 2026/01/01 04:41:14 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:41:14 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:41:15 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:41:16 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:41:17 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 9/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:43:22 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:43:22 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:43:22 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:43:23 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:43:24 DEBUG : pacer: Reducing sleep to 10ms run.go:290: Failed to put "dir/file1" to "pcloud root 'rclone-test-vologop2dafa'": Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF 2026/01/01 04:43:28 DEBUG : WaitForWriters: timeout=30s 2026/01/01 04:43:28 DEBUG : Looking for writers 2026/01/01 04:43:28 DEBUG : >WaitForWriters: --- FAIL: TestFileRemove (1274.18s) === RUN TestFileRemoveAll run.go:185: Remote "pcloud root 'rclone-test-vologop2dafa'", Local "Local file system at /tmp/rclone1249241989", Modify Window "1s" 2026/01/01 04:43:28 NOTICE: pcloud root 'rclone-test-vologop2dafa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/01/01 04:45:28 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:45:28 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:45:28 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:45:29 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:45:30 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 1/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:47:36 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:47:36 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:47:36 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:47:37 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:47:38 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 2/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:49:43 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:49:43 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:49:44 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:49:45 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:49:46 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 3/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:49:59 DEBUG : dir: forgetting directory cache 2026/01/01 04:49:59 DEBUG : dir/virtualDir: forgetting directory cache 2026/01/01 04:49:59 DEBUG : forgetting directory cache 2026/01/01 04:49:59 DEBUG : dir: forgetting directory cache 2026/01/01 04:49:59 DEBUG : dir/virtualDir: forgetting directory cache 2026/01/01 04:51:51 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:51:51 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:51:51 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:51:52 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:51:53 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 4/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:53:28 DEBUG : forgetting directory cache 2026/01/01 04:53:59 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) 2026/01/01 04:53:59 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/01/01 04:53:59 DEBUG : pacer: Reducing sleep to 15ms 2026/01/01 04:54:01 DEBUG : pacer: Reducing sleep to 11.25ms 2026/01/01 04:54:02 DEBUG : pacer: Reducing sleep to 10ms run.go:286: Retry Put of "dir/file1" to pcloud root 'rclone-test-vologop2dafa': 5/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=21199894211&mtime=981173106&nopartial=1": EOF) panic: test timed out after 1h0m0s running tests: TestFileRemoveAll (16m16s) goroutine 27507 [running]: testing.(*M).startAlarm.func1() /usr/local/go/src/testing/testing.go:2484 +0x394 created by time.goFunc /usr/local/go/src/time/sleep.go:215 +0x2d goroutine 1 [chan receive, 16 minutes]: testing.(*T).Run(0xc0008bae00, {0x28dfdf7?, 0xc00059fad8?}, 0x2a26928) /usr/local/go/src/testing/testing.go:1859 +0x431 testing.runTests.func1(0xc0008bae00) /usr/local/go/src/testing/testing.go:2279 +0x37 testing.tRunner(0xc0008bae00, 0xc00059fc18) /usr/local/go/src/testing/testing.go:1792 +0xf4 testing.runTests(0xc000719b48, {0x429a040, 0x59, 0x59}, {0xee0e7e830?, 0x42b6f20?, 0x42b6f20?}) /usr/local/go/src/testing/testing.go:2277 +0x4b4 testing.(*M).Run(0xc000812460) /usr/local/go/src/testing/testing.go:2142 +0x64a github.com/rclone/rclone/fstest.TestMain(0xc000812460) /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:74 +0xa6 github.com/rclone/rclone/vfs.TestMain(...) /home/rclone/go/src/github.com/rclone/rclone/vfs/vfs_test.go:36 main.main() _testmain.go:225 +0xa9 goroutine 51 [syscall, 60 minutes]: os/signal.signal_recv() /usr/local/go/src/runtime/sigqueue.go:152 +0x29 os/signal.loop() /usr/local/go/src/os/signal/signal_unix.go:23 +0x13 created by os/signal.Notify.func1.1 in goroutine 1 /usr/local/go/src/os/signal/signal.go:152 +0x1f goroutine 52 [chan receive, 60 minutes]: github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler.func1() /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting_unix.go:24 +0x27 created by github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler in goroutine 1 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting_unix.go:21 +0xa7 goroutine 53 [select, 60 minutes]: github.com/rclone/rclone/lib/oauthutil.(*Renew).renewOnExpiry(0xc0004d0400) /home/rclone/go/src/github.com/rclone/rclone/lib/oauthutil/renew.go:43 +0x86 created by github.com/rclone/rclone/lib/oauthutil.NewRenew in goroutine 1 /home/rclone/go/src/github.com/rclone/rclone/lib/oauthutil/renew.go:32 +0xe5 goroutine 27035 [select]: net/http.(*persistConn).roundTrip(0xc000b0e000, 0xc0008320f0) /usr/local/go/src/net/http/transport.go:2826 +0x785 net/http.(*Transport).roundTrip(0xc0001884e0, 0xc000bf43c0) /usr/local/go/src/net/http/transport.go:696 +0xb9a net/http.(*Transport).RoundTrip(...) /usr/local/go/src/net/http/roundtrip.go:30 github.com/rclone/rclone/fs/fshttp.(*Transport).RoundTrip(0xc00016e4e0, 0xc000bf43c0) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:496 +0x345 golang.org/x/oauth2.(*Transport).RoundTrip(0xc0003cdb80, 0xc000bf4280) /home/rclone/go/pkg/mod/golang.org/x/oauth2@v0.33.0/transport.go:55 +0x15e net/http.send(0xc000bf4280, {0x2d98720, 0xc0003cdb80}, {0x6fdc01?, 0xc000abe4d8?, 0x0?}) /usr/local/go/src/net/http/client.go:259 +0x5e2 net/http.(*Client).send(0xc000881bf0, 0xc000bf4280, {0xb?, 0x1?, 0x0?}) /usr/local/go/src/net/http/client.go:180 +0x91 net/http.(*Client).do(0xc000881bf0, 0xc000bf4280) /usr/local/go/src/net/http/client.go:728 +0x989 net/http.(*Client).Do(...) /usr/local/go/src/net/http/client.go:587 github.com/rclone/rclone/lib/rest.(*Client).Call(0xc0000be050, {0x2dbe148, 0x42da7e0}, 0xc000bf4140) /home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:353 +0xd67 github.com/rclone/rclone/lib/rest.(*Client).callCodec(0xc0000be050, {0x2dbe148, 0x42da7e0}, 0xc0009856c8?, {0x0?, 0x0?}, {0x23a7220, 0xc0007a8000}, 0xc000985740?, 0x2a28250, ...) /home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:550 +0x3f2 github.com/rclone/rclone/lib/rest.(*Client).CallJSON(...) /home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:493 github.com/rclone/rclone/backend/pcloud.(*Object).Update.func1() /home/rclone/go/src/github.com/rclone/rclone/backend/pcloud/pcloud.go:1477 +0x93 github.com/rclone/rclone/fs.pacerInvoker(0x1, 0x1, 0x9?) /home/rclone/go/src/github.com/rclone/rclone/fs/pacer.go:86 +0x32 github.com/rclone/rclone/lib/pacer.(*Pacer).call(0xc00016e5a0, 0xc0004d0140, 0x1) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:216 +0xd2 github.com/rclone/rclone/lib/pacer.(*Pacer).CallNoRetry(...) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:244 github.com/rclone/rclone/backend/pcloud.(*Object).Update(0xc000886000, {0x2dbe148, 0x42da7e0}, {0x2d94a40, 0xc000452900}, {0x2dcabd0, 0xc00039e150}, {0x0, 0x0, 0x0}) /home/rclone/go/src/github.com/rclone/rclone/backend/pcloud/pcloud.go:1476 +0xb1e github.com/rclone/rclone/backend/pcloud.(*Fs).Put(0xc000384840, {0x2dbe148, 0x42da7e0}, {0x2d94a40, 0xc000452900}, {0x2dcabd0, 0xc00039e150}, {0x0, 0x0, 0x0}) /home/rclone/go/src/github.com/rclone/rclone/backend/pcloud/pcloud.go:707 +0x14c github.com/rclone/rclone/fstest.(*Run).WriteObjectTo(0xc000572a10, {0x2dbe148, 0x42da7e0}, {0x2dd7180, 0xc000384840}, {0x28c8d19, 0x9}, {0x28d6eeb, 0xe}, {0x1dcd64ff, ...}, ...) /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:280 +0x3f2 github.com/rclone/rclone/fstest.(*Run).WriteObject(...) /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:297 github.com/rclone/rclone/vfs.fileCreate(0xc000c21a40, 0x60?) /home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:27 +0xfa github.com/rclone/rclone/vfs.TestFileRemoveAll(0xc000c21a40) /home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:264 +0x25 testing.tRunner(0xc000c21a40, 0x2a26928) /usr/local/go/src/testing/testing.go:1792 +0xf4 created by testing.(*T).Run in goroutine 1 /usr/local/go/src/testing/testing.go:1851 +0x413 goroutine 27468 [IO wait]: internal/poll.runtime_pollWait(0x73adde8cb4e8, 0x72) /usr/local/go/src/runtime/netpoll.go:351 +0x85 internal/poll.(*pollDesc).wait(0xc0003eee80?, 0xc0009b5980?, 0x0) /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 internal/poll.(*pollDesc).waitRead(...) /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Read(0xc0003eee80, {0xc0009b5980, 0x1980, 0x1980}) /usr/local/go/src/internal/poll/fd_unix.go:165 +0x27a net.(*netFD).Read(0xc0003eee80, {0xc0009b5980?, 0x192c?, 0xc0000723c0?}) /usr/local/go/src/net/fd_posix.go:55 +0x25 net.(*conn).Read(0xc000872068, {0xc0009b5980?, 0xc0009b59cf?, 0x5?}) /usr/local/go/src/net/net.go:194 +0x45 github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc000010300, {0xc0009b5980?, 0x73addcedde20?, 0x73ae26daea78?}) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29 crypto/tls.(*atLeastReader).Read(0xc0007183d8, {0xc0009b5980?, 0x192c?, 0xc0008321e0?}) /usr/local/go/src/crypto/tls/conn.go:809 +0x3b bytes.(*Buffer).ReadFrom(0xc000666638, {0x2d97840, 0xc0007183d8}) /usr/local/go/src/bytes/buffer.go:211 +0x98 crypto/tls.(*Conn).readFromUntil(0xc000666388, {0x73addc597558, 0xc000010300}, 0x1931?) /usr/local/go/src/crypto/tls/conn.go:831 +0xde crypto/tls.(*Conn).readRecordOrCCS(0xc000666388, 0x0) /usr/local/go/src/crypto/tls/conn.go:629 +0x3cf crypto/tls.(*Conn).readRecord(...) /usr/local/go/src/crypto/tls/conn.go:591 crypto/tls.(*Conn).Read(0xc000666388, {0xc000952000, 0x1000, 0x73ae26dae108?}) /usr/local/go/src/crypto/tls/conn.go:1385 +0x145 net/http.(*persistConn).Read(0xc000b0e000, {0xc000952000?, 0x412565?, 0x68?}) /usr/local/go/src/net/http/transport.go:2122 +0x47 bufio.(*Reader).fill(0xc0009f6c00) /usr/local/go/src/bufio/bufio.go:113 +0x103 bufio.(*Reader).Peek(0xc0009f6c00, 0x1) /usr/local/go/src/bufio/bufio.go:152 +0x53 net/http.(*persistConn).readLoop(0xc000b0e000) /usr/local/go/src/net/http/transport.go:2275 +0x172 created by net/http.(*Transport).dialConn in goroutine 27446 /usr/local/go/src/net/http/transport.go:1944 +0x174f goroutine 27469 [select]: net/http.(*persistConn).writeLoop(0xc000b0e000) /usr/local/go/src/net/http/transport.go:2590 +0xe7 created by net/http.(*Transport).dialConn in goroutine 27446 /usr/local/go/src/net/http/transport.go:1945 +0x17a5 goroutine 27499 [select]: net/http.(*persistConn).writeLoop(0xc000308fc0) /usr/local/go/src/net/http/transport.go:2590 +0xe7 created by net/http.(*Transport).dialConn in goroutine 27470 /usr/local/go/src/net/http/transport.go:1945 +0x17a5 goroutine 27498 [IO wait]: internal/poll.runtime_pollWait(0x73adde8cb830, 0x72) /usr/local/go/src/runtime/netpoll.go:351 +0x85 internal/poll.(*pollDesc).wait(0xc0003ef900?, 0xc0001d4600?, 0x0) /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 internal/poll.(*pollDesc).waitRead(...) /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Read(0xc0003ef900, {0xc0001d4600, 0x1980, 0x1980}) /usr/local/go/src/internal/poll/fd_unix.go:165 +0x27a net.(*netFD).Read(0xc0003ef900, {0xc0001d4600?, 0x197b?, 0xc000750500?}) /usr/local/go/src/net/fd_posix.go:55 +0x25 net.(*conn).Read(0xc000624080, {0xc0001d4600?, 0xc0001d4600?, 0x5?}) /usr/local/go/src/net/net.go:194 +0x45 github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc0007183f0, {0xc0001d4600?, 0x73ae26db7170?, 0x73ae26dae108?}) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29 crypto/tls.(*atLeastReader).Read(0xc0000112d8, {0xc0001d4600?, 0x197b?, 0xc000800808?}) /usr/local/go/src/crypto/tls/conn.go:809 +0x3b bytes.(*Buffer).ReadFrom(0xc00018a2b8, {0x2d97840, 0xc0000112d8}) /usr/local/go/src/bytes/buffer.go:211 +0x98 crypto/tls.(*Conn).readFromUntil(0xc00018a008, {0x73addc597558, 0xc0007183f0}, 0x1980?) /usr/local/go/src/crypto/tls/conn.go:831 +0xde crypto/tls.(*Conn).readRecordOrCCS(0xc00018a008, 0x0) /usr/local/go/src/crypto/tls/conn.go:629 +0x3cf crypto/tls.(*Conn).readRecord(...) /usr/local/go/src/crypto/tls/conn.go:591 crypto/tls.(*Conn).Read(0xc00018a008, {0xc00041d000, 0x1000, 0x73ae26dae5c0?}) /usr/local/go/src/crypto/tls/conn.go:1385 +0x145 net/http.(*persistConn).Read(0xc000308fc0, {0xc00041d000?, 0x412565?, 0x68?}) /usr/local/go/src/net/http/transport.go:2122 +0x47 bufio.(*Reader).fill(0xc0008960c0) /usr/local/go/src/bufio/bufio.go:113 +0x103 bufio.(*Reader).Peek(0xc0008960c0, 0x1) /usr/local/go/src/bufio/bufio.go:152 +0x53 net/http.(*persistConn).readLoop(0xc000308fc0) /usr/local/go/src/net/http/transport.go:2275 +0x172 created by net/http.(*Transport).dialConn in goroutine 27470 /usr/local/go/src/net/http/transport.go:1944 +0x174f goroutine 27020 [select, 16 minutes]: github.com/rclone/rclone/vfs.(*VFS).signalHandler(0xc00028b2c0, {0x2dbe260, 0xc00078a5f0}) /home/rclone/go/src/github.com/rclone/rclone/vfs/vfs.go:290 +0xc5 created by github.com/rclone/rclone/vfs.New in goroutine 27035 /home/rclone/go/src/github.com/rclone/rclone/vfs/vfs.go:266 +0x7fe goroutine 27036 [select]: net/http.(*persistConn).roundTrip(0xc000308fc0, 0xc0000be500) /usr/local/go/src/net/http/transport.go:2826 +0x785 net/http.(*Transport).roundTrip(0xc0001884e0, 0xc000c60280) /usr/local/go/src/net/http/transport.go:696 +0xb9a net/http.(*Transport).RoundTrip(...) /usr/local/go/src/net/http/roundtrip.go:30 github.com/rclone/rclone/fs/fshttp.(*Transport).RoundTrip(0xc00016e4e0, 0xc000c60280) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:496 +0x345 golang.org/x/oauth2.(*Transport).RoundTrip(0xc0003cdb80, 0xc000c60140) /home/rclone/go/pkg/mod/golang.org/x/oauth2@v0.33.0/transport.go:55 +0x15e net/http.send(0xc000c60140, {0x2d98720, 0xc0003cdb80}, {0x6fdc01?, 0xc000865348?, 0x0?}) /usr/local/go/src/net/http/client.go:259 +0x5e2 net/http.(*Client).send(0xc000881bf0, 0xc000c60140, {0x5?, 0x1?, 0x0?}) /usr/local/go/src/net/http/client.go:180 +0x91 net/http.(*Client).do(0xc000881bf0, 0xc000c60140) /usr/local/go/src/net/http/client.go:728 +0x989 net/http.(*Client).Do(...) /usr/local/go/src/net/http/client.go:587 github.com/rclone/rclone/lib/rest.(*Client).Call(0xc0000be050, {0x2dbe2d0, 0xc00076e7e0}, 0xc000311b68) /home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:353 +0xd67 github.com/rclone/rclone/lib/rest.(*Client).callCodec(0xc0000be050, {0x2dbe2d0, 0xc00076e7e0}, 0x252b120?, {0x0?, 0x0?}, {0x2245140, 0xc000a92900}, 0x4c7189?, 0x2a28250, ...) /home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:550 +0x3f2 github.com/rclone/rclone/lib/rest.(*Client).CallJSON(...) /home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:493 github.com/rclone/rclone/backend/pcloud.(*Fs).changeNotifyLoop(0xc000384840, {0x2dbe1b8, 0x42da7e0}, 0xc000067140, 0xc000abe8c0) /home/rclone/go/src/github.com/rclone/rclone/backend/pcloud/pcloud.go:1135 +0x465 created by github.com/rclone/rclone/backend/pcloud.(*Fs).ChangeNotify in goroutine 27035 /home/rclone/go/src/github.com/rclone/rclone/backend/pcloud/pcloud.go:1040 +0xa8 "./vfs.test -test.v -test.timeout 1h0m0s -remote TestPcloud: -verbose" - Finished ERROR in 1h0m7.222016016s (try 1/5): exit status 2: Failed [TestFileSetModTime/cache=full,open=true,write=true TestFileOpenRead TestFileOpenWrite TestFileRemove]