"./vfs.test -test.v -test.timeout 1h0m0s -remote TestPcloud: -verbose" - Starting (try 1/5)
2026/10/17 01:20:15 DEBUG : Creating backend with remote "TestPcloud:rclone-test-hisifad5jopa"
2026/10/17 01:20:15 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/10/17 01:20:16 DEBUG : Creating backend with remote "/tmp/rclone2950321852"
=== RUN   TestDirHandleMethods
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:20:16 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:20:17 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/17 01:20:17 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/17 01:20:17 DEBUG : >changeNotify: 
2026/10/17 01:20:17 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/17 01:20:17 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/17 01:20:17 DEBUG : >changeNotify: 
    fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:302: Flushing the directory cache
    fstest.go:293: Sleeping for 6s just to make sure
2026/10/17 01:20:26 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:20:26 DEBUG : dir: Looking for writers
2026/10/17 01:20:26 DEBUG : Looking for writers
2026/10/17 01:20:26 DEBUG : dir: reading active writers
2026/10/17 01:20:26 DEBUG : >WaitForWriters: 
    fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:302: Flushing the directory cache
    fstest.go:293: Sleeping for 6s just to make sure
--- PASS: TestDirHandleMethods (17.35s)
=== RUN   TestDirHandleReaddir
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:20:34 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:20:34 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/17 01:20:34 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/17 01:20:34 DEBUG : >changeNotify: 
2026/10/17 01:20:34 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/17 01:20:34 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/17 01:20:34 DEBUG : >changeNotify: 
2026/10/17 01:20:34 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file2" (type: 1)
2026/10/17 01:20:34 DEBUG : changeNotify: relativePath="dir/file2", type=1
2026/10/17 01:20:34 DEBUG : >changeNotify: 
2026/10/17 01:20:34 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/subdir" (type: 0)
2026/10/17 01:20:34 DEBUG : changeNotify: relativePath="dir/subdir", type=0
2026/10/17 01:20:34 DEBUG : >changeNotify: 
2026/10/17 01:20:34 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/subdir/file3" (type: 1)
2026/10/17 01:20:34 DEBUG : changeNotify: relativePath="dir/subdir/file3", type=1
2026/10/17 01:20:34 DEBUG : >changeNotify: 
2026/10/17 01:20:35 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:20:35 DEBUG : dir/subdir: Looking for writers
2026/10/17 01:20:35 DEBUG : dir: Looking for writers
2026/10/17 01:20:35 DEBUG : file1: reading active writers
2026/10/17 01:20:35 DEBUG : file2: reading active writers
2026/10/17 01:20:35 DEBUG : subdir: reading active writers
2026/10/17 01:20:35 DEBUG : Looking for writers
2026/10/17 01:20:35 DEBUG : dir: reading active writers
2026/10/17 01:20:35 DEBUG : >WaitForWriters: 
--- PASS: TestDirHandleReaddir (2.07s)
=== RUN   TestDirHandleReaddirnames
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:20:36 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:20:36 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/17 01:20:36 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/17 01:20:36 DEBUG : >changeNotify: 
2026/10/17 01:20:36 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/17 01:20:36 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/17 01:20:36 DEBUG : >changeNotify: 
2026/10/17 01:20:36 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:20:36 DEBUG : dir: Looking for writers
2026/10/17 01:20:36 DEBUG : file1: reading active writers
2026/10/17 01:20:36 DEBUG : Looking for writers
2026/10/17 01:20:36 DEBUG : dir: reading active writers
2026/10/17 01:20:36 DEBUG : >WaitForWriters: 
--- PASS: TestDirHandleReaddirnames (28.21s)
=== RUN   TestDirLinksInvalidName
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:21:04 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:21:04 NOTICE: pcloud root 'rclone-test-hisifad5jopa': Symlinks support enabled
2026/10/17 01:21:09 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/17 01:21:09 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/17 01:21:09 DEBUG : >changeNotify: 
2026/10/17 01:21:09 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/...rclonelink" (type: 1)
2026/10/17 01:21:09 DEBUG : changeNotify: relativePath="dir/...rclonelink", type=1
2026/10/17 01:21:09 DEBUG : >changeNotify: 
2026/10/17 01:21:09 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/17 01:21:09 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/17 01:21:09 DEBUG : >changeNotify: 
2026/10/17 01:21:10 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:21:10 DEBUG : dir: Looking for writers
2026/10/17 01:21:10 DEBUG : file1: reading active writers
2026/10/17 01:21:10 DEBUG : Looking for writers
2026/10/17 01:21:10 DEBUG : dir: reading active writers
2026/10/17 01:21:10 DEBUG : >WaitForWriters: 
--- PASS: TestDirLinksInvalidName (6.48s)
=== RUN   TestDirMethods
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:21:10 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:21:11 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/17 01:21:11 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/17 01:21:11 DEBUG : >changeNotify: 
2026/10/17 01:21:11 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/17 01:21:11 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/17 01:21:11 DEBUG : >changeNotify: 
2026/10/17 01:21:11 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:21:11 DEBUG : dir: Looking for writers
2026/10/17 01:21:11 DEBUG : Looking for writers
2026/10/17 01:21:11 DEBUG : dir: reading active writers
2026/10/17 01:21:11 DEBUG : >WaitForWriters: 
--- PASS: TestDirMethods (0.98s)
=== RUN   TestDirForgetAll
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:21:11 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:21:17 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/17 01:21:17 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/17 01:21:17 DEBUG : >changeNotify: 
2026/10/17 01:21:17 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/17 01:21:17 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/17 01:21:17 DEBUG : >changeNotify: 
2026/10/17 01:21:29 DEBUG : dir: forgetting directory cache
2026/10/17 01:21:29 DEBUG : forgetting directory cache
2026/10/17 01:21:29 DEBUG : dir: forgetting directory cache
2026/10/17 01:21:29 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:21:29 DEBUG : Looking for writers
2026/10/17 01:21:29 DEBUG : >WaitForWriters: 
--- PASS: TestDirForgetAll (18.17s)
=== RUN   TestDirForgetPath
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:21:30 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:21:30 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/17 01:21:30 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/17 01:21:30 DEBUG : >changeNotify: 
2026/10/17 01:21:30 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/17 01:21:30 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/17 01:21:30 DEBUG : >changeNotify: 
2026/10/17 01:21:30 DEBUG : ForgetPath: relativePath="dir/notfound", type=1
2026/10/17 01:21:30 DEBUG : dir: invalidating directory cache
2026/10/17 01:21:30 DEBUG : >ForgetPath: 
2026/10/17 01:21:30 DEBUG : ForgetPath: relativePath="dir", type=0
2026/10/17 01:21:30 DEBUG : invalidating directory cache
2026/10/17 01:21:30 DEBUG : dir: forgetting directory cache
2026/10/17 01:21:30 DEBUG : >ForgetPath: 
2026/10/17 01:21:30 DEBUG : ForgetPath: relativePath="not/in/cache", type=0
2026/10/17 01:21:30 DEBUG : >ForgetPath: 
2026/10/17 01:21:30 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:21:30 DEBUG : dir: Looking for writers
2026/10/17 01:21:30 DEBUG : Looking for writers
2026/10/17 01:21:30 DEBUG : dir: reading active writers
2026/10/17 01:21:30 DEBUG : >WaitForWriters: 
--- PASS: TestDirForgetPath (1.10s)
=== RUN   TestDirWalk
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:21:31 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:21:31 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/17 01:21:31 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/17 01:21:31 DEBUG : >changeNotify: 
2026/10/17 01:21:31 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/17 01:21:31 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/17 01:21:31 DEBUG : >changeNotify: 
    fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:302: Flushing the directory cache
    fstest.go:293: Sleeping for 6s just to make sure
2026/10/17 01:21:40 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "fil" (type: 0)
2026/10/17 01:21:40 DEBUG : changeNotify: relativePath="fil", type=0
2026/10/17 01:21:40 DEBUG : invalidating directory cache
2026/10/17 01:21:40 DEBUG : >changeNotify: 
2026/10/17 01:21:40 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "fil/a" (type: 0)
2026/10/17 01:21:40 DEBUG : changeNotify: relativePath="fil/a", type=0
2026/10/17 01:21:40 DEBUG : >changeNotify: 
2026/10/17 01:21:40 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "fil/a/b" (type: 0)
2026/10/17 01:21:40 DEBUG : changeNotify: relativePath="fil/a/b", type=0
2026/10/17 01:21:40 DEBUG : >changeNotify: 
2026/10/17 01:21:47 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "fil/a/b/c" (type: 1)
2026/10/17 01:21:47 DEBUG : changeNotify: relativePath="fil/a/b/c", type=1
2026/10/17 01:21:47 DEBUG : >changeNotify: 
2026/10/17 01:21:47 DEBUG : forgetting directory cache
2026/10/17 01:21:47 DEBUG : dir: forgetting directory cache
2026/10/17 01:21:47 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:21:47 DEBUG : dir: Looking for writers
2026/10/17 01:21:47 DEBUG : fil/a/b: Looking for writers
2026/10/17 01:21:47 DEBUG : fil/a: Looking for writers
2026/10/17 01:21:47 DEBUG : b: reading active writers
2026/10/17 01:21:47 DEBUG : fil: Looking for writers
2026/10/17 01:21:47 DEBUG : a: reading active writers
2026/10/17 01:21:47 DEBUG : Looking for writers
2026/10/17 01:21:47 DEBUG : dir: reading active writers
2026/10/17 01:21:47 DEBUG : fil: reading active writers
2026/10/17 01:21:47 DEBUG : >WaitForWriters: 
--- PASS: TestDirWalk (17.30s)
=== RUN   TestDirSetModTime
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:21:48 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:21:48 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/17 01:21:48 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/17 01:21:48 DEBUG : >changeNotify: 
2026/10/17 01:21:48 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/17 01:21:48 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/17 01:21:48 DEBUG : >changeNotify: 
2026/10/17 01:21:49 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:21:49 DEBUG : dir: Looking for writers
2026/10/17 01:21:49 DEBUG : Looking for writers
2026/10/17 01:21:49 DEBUG : dir: reading active writers
2026/10/17 01:21:49 DEBUG : >WaitForWriters: 
--- PASS: TestDirSetModTime (10.83s)
=== RUN   TestDirStat
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:21:59 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:22:00 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:22:00 DEBUG : dir: Looking for writers
2026/10/17 01:22:00 DEBUG : file1: reading active writers
2026/10/17 01:22:00 DEBUG : Looking for writers
2026/10/17 01:22:00 DEBUG : dir: reading active writers
2026/10/17 01:22:00 DEBUG : >WaitForWriters: 
--- PASS: TestDirStat (1.12s)
=== RUN   TestDirReadDirAll
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:22:00 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:22:00 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/17 01:22:00 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/17 01:22:00 DEBUG : >changeNotify: 
2026/10/17 01:22:00 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/17 01:22:00 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/17 01:22:00 DEBUG : >changeNotify: 
2026/10/17 01:22:00 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file2" (type: 1)
2026/10/17 01:22:00 DEBUG : changeNotify: relativePath="dir/file2", type=1
2026/10/17 01:22:00 DEBUG : >changeNotify: 
2026/10/17 01:22:02 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/subdir" (type: 0)
2026/10/17 01:22:02 DEBUG : changeNotify: relativePath="dir/subdir", type=0
2026/10/17 01:22:02 DEBUG : >changeNotify: 
2026/10/17 01:22:02 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/subdir/file3" (type: 1)
2026/10/17 01:22:02 DEBUG : changeNotify: relativePath="dir/subdir/file3", type=1
2026/10/17 01:22:02 DEBUG : >changeNotify: 
=== RUN   TestDirReadDirAll/Virtual
2026/10/17 01:22:03 DEBUG : dir: Added virtual directory entry vAddFile: "virtualFile"
2026/10/17 01:22:03 DEBUG : dir: Added virtual directory entry vAddDir: "virtualDir"
2026/10/17 01:22:03 DEBUG : dir: Added virtual directory entry vDel: "file2"
2026/10/17 01:22:03 DEBUG : dir: Added virtual directory entry vDel: "subdir"
2026/10/17 01:22:03 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/virtualFile" (type: 1)
2026/10/17 01:22:03 DEBUG : changeNotify: relativePath="dir/virtualFile", type=1
2026/10/17 01:22:03 DEBUG : dir: invalidating directory cache
2026/10/17 01:22:03 DEBUG : >changeNotify: 
2026/10/17 01:22:04 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/virtualDir" (type: 0)
2026/10/17 01:22:04 DEBUG : changeNotify: relativePath="dir/virtualDir", type=0
2026/10/17 01:22:04 DEBUG : >changeNotify: 
2026/10/17 01:22:04 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/virtualDir/testFile" (type: 1)
2026/10/17 01:22:04 DEBUG : changeNotify: relativePath="dir/virtualDir/testFile", type=1
2026/10/17 01:22:04 DEBUG : >changeNotify: 
2026/10/17 01:22:04 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file2" (type: 1)
2026/10/17 01:22:04 DEBUG : changeNotify: relativePath="dir/file2", type=1
2026/10/17 01:22:04 DEBUG : >changeNotify: 
2026/10/17 01:22:04 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/subdir" (type: 0)
2026/10/17 01:22:04 DEBUG : changeNotify: relativePath="dir/subdir", type=0
2026/10/17 01:22:04 DEBUG : dir: Removed virtual directory entry vAddDir: "virtualDir"
2026/10/17 01:22:04 DEBUG : dir: Removed virtual directory entry vDel: "file2"
2026/10/17 01:22:04 DEBUG : dir: Removed virtual directory entry vDel: "subdir"
2026/10/17 01:22:04 DEBUG : dir/file1: Reset virtual modtime
2026/10/17 01:22:04 DEBUG : dir: Removed virtual directory entry vAddFile: "virtualFile"
2026/10/17 01:22:04 DEBUG : dir/virtualFile: Reset virtual modtime
2026/10/17 01:22:04 DEBUG : dir: Added virtual directory entry vAddFile: "virtualFile2"
2026/10/17 01:22:04 DEBUG : dir: Added virtual directory entry vAddDir: "virtualDir2"
2026/10/17 01:22:04 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/10/17 01:22:04 DEBUG : dir: invalidating directory cache
2026/10/17 01:22:04 DEBUG : dir: Removed virtual directory entry vAddDir: "virtualDir2"
2026/10/17 01:22:04 DEBUG : dir: Removed virtual directory entry vDel: "file1"
2026/10/17 01:22:04 DEBUG : dir/virtualFile: Reset virtual modtime
2026/10/17 01:22:04 DEBUG : dir: invalidating directory cache
2026/10/17 01:22:04 DEBUG : >changeNotify: 
2026/10/17 01:22:04 DEBUG : forgetting directory cache
2026/10/17 01:22:04 DEBUG : dir: forgetting directory cache
2026/10/17 01:22:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/17 01:22:05 DEBUG : dir/file1: Reset virtual modtime
2026/10/17 01:22:05 DEBUG : dir/virtualFile: Reset virtual modtime
2026/10/17 01:22:05 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:22:05 DEBUG : dir/virtualDir: Looking for writers
2026/10/17 01:22:05 DEBUG : dir: Looking for writers
2026/10/17 01:22:05 DEBUG : virtualFile2: reading active writers
2026/10/17 01:22:05 DEBUG : virtualFile: reading active writers
2026/10/17 01:22:05 DEBUG : virtualDir: reading active writers
2026/10/17 01:22:05 DEBUG : file1: reading active writers
2026/10/17 01:22:05 DEBUG : Looking for writers
2026/10/17 01:22:05 DEBUG : dir: reading active writers
2026/10/17 01:22:05 DEBUG : >WaitForWriters: 
--- PASS: TestDirReadDirAll (6.48s)
    --- PASS: TestDirReadDirAll/Virtual (1.26s)
=== RUN   TestDirOpen
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:22:06 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:22:07 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/17 01:22:07 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/17 01:22:07 DEBUG : >changeNotify: 
2026/10/17 01:22:07 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/17 01:22:07 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/17 01:22:07 DEBUG : >changeNotify: 
2026/10/17 01:22:07 ERROR : dir/: Can only open directories read only
2026/10/17 01:22:07 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:22:07 DEBUG : dir: Looking for writers
2026/10/17 01:22:07 DEBUG : Looking for writers
2026/10/17 01:22:07 DEBUG : dir: reading active writers
2026/10/17 01:22:07 DEBUG : >WaitForWriters: 
--- PASS: TestDirOpen (1.04s)
=== RUN   TestDirCreate
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:22:07 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:22:08 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/17 01:22:08 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/17 01:22:08 DEBUG : >changeNotify: 
2026/10/17 01:22:08 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/17 01:22:08 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/17 01:22:08 DEBUG : >changeNotify: 
2026/10/17 01:22:08 DEBUG : dir/potato: Open: flags=O_WRONLY|O_CREATE
2026/10/17 01:22:08 DEBUG : dir: Added virtual directory entry vAddFile: "potato"
2026/10/17 01:22:08 DEBUG : dir/potato: >Open: fd=dir/potato (w), err=<nil>
2026/10/17 01:22:08 DEBUG : dir: Added virtual directory entry vAddFile: "potato"
2026/10/17 01:22:08 DEBUG : pcloud root 'rclone-test-hisifad5jopa': File to upload is small (5 bytes), uploading instead of streaming
2026/10/17 01:22:08 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/potato" (type: 1)
2026/10/17 01:22:08 DEBUG : changeNotify: relativePath="dir/potato", type=1
2026/10/17 01:22:08 DEBUG : dir: invalidating directory cache
2026/10/17 01:22:08 DEBUG : >changeNotify: 
2026/10/17 01:22:08 DEBUG : dir/potato: size = 5 OK
2026/10/17 01:22:08 DEBUG : dir/potato: sha1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK
2026/10/17 01:22:08 DEBUG : dir/potato: Size and sha1 of src and dst objects identical
2026/10/17 01:22:08 DEBUG : dir: Added virtual directory entry vAddFile: "potato"
2026/10/17 01:22:08 DEBUG : dir: Removed virtual directory entry vAddFile: "potato"
2026/10/17 01:22:08 DEBUG : dir/file1: Reset virtual modtime
2026/10/17 01:22:08 DEBUG : dir/potato: Reset virtual modtime
2026/10/17 01:22:08 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:22:08 DEBUG : dir: Looking for writers
2026/10/17 01:22:08 DEBUG : file1: reading active writers
2026/10/17 01:22:08 DEBUG : potato: reading active writers
2026/10/17 01:22:08 DEBUG : Looking for writers
2026/10/17 01:22:08 DEBUG : dir: reading active writers
2026/10/17 01:22:08 DEBUG : >WaitForWriters: 
--- PASS: TestDirCreate (1.53s)
=== RUN   TestDirMkdir
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:22:09 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:22:20 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/17 01:22:20 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/17 01:22:20 DEBUG : >changeNotify: 
2026/10/17 01:22:20 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/17 01:22:20 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/17 01:22:20 DEBUG : >changeNotify: 
2026/10/17 01:22:21 DEBUG : dir: Added virtual directory entry vAddDir: "sub"
2026/10/17 01:22:21 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/sub" (type: 0)
2026/10/17 01:22:21 DEBUG : changeNotify: relativePath="dir/sub", type=0
2026/10/17 01:22:21 DEBUG : dir: invalidating directory cache
2026/10/17 01:22:21 DEBUG : dir/sub: invalidating directory cache
2026/10/17 01:22:21 DEBUG : >changeNotify: 
2026/10/17 01:22:21 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:22:21 DEBUG : dir/sub: Looking for writers
2026/10/17 01:22:21 DEBUG : dir: Looking for writers
2026/10/17 01:22:21 DEBUG : file1: reading active writers
2026/10/17 01:22:21 DEBUG : sub: reading active writers
2026/10/17 01:22:21 DEBUG : Looking for writers
2026/10/17 01:22:21 DEBUG : dir: reading active writers
2026/10/17 01:22:21 DEBUG : >WaitForWriters: 
    fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:302: Flushing the directory cache
    fstest.go:293: Sleeping for 6s just to make sure
--- PASS: TestDirMkdir (20.65s)
=== RUN   TestDirMkdirSub
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:22:30 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:22:31 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/17 01:22:31 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/17 01:22:31 DEBUG : >changeNotify: 
2026/10/17 01:22:31 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/17 01:22:31 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/17 01:22:31 DEBUG : >changeNotify: 
    fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:302: Flushing the directory cache
    fstest.go:293: Sleeping for 6s just to make sure
2026/10/17 01:22:39 DEBUG : dir: Added virtual directory entry vAddDir: "sub"
2026/10/17 01:22:39 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/sub" (type: 0)
2026/10/17 01:22:39 DEBUG : changeNotify: relativePath="dir/sub", type=0
2026/10/17 01:22:39 DEBUG : dir: invalidating directory cache
2026/10/17 01:22:39 DEBUG : dir/sub: invalidating directory cache
2026/10/17 01:22:39 DEBUG : >changeNotify: 
2026/10/17 01:22:40 DEBUG : dir/sub: Added virtual directory entry vAddDir: "subsub"
2026/10/17 01:22:40 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/sub/subsub" (type: 0)
2026/10/17 01:22:40 DEBUG : changeNotify: relativePath="dir/sub/subsub", type=0
2026/10/17 01:22:40 DEBUG : dir: Removed virtual directory entry vAddDir: "sub"
2026/10/17 01:22:40 DEBUG : dir/file1: Reset virtual modtime
2026/10/17 01:22:40 DEBUG : dir/sub: Removed virtual directory entry vAddDir: "subsub"
2026/10/17 01:22:40 DEBUG : dir/sub: invalidating directory cache
2026/10/17 01:22:40 DEBUG : dir/sub/subsub: invalidating directory cache
2026/10/17 01:22:40 DEBUG : >changeNotify: 
2026/10/17 01:22:40 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:22:40 DEBUG : dir/sub/subsub: Looking for writers
2026/10/17 01:22:40 DEBUG : dir/sub: Looking for writers
2026/10/17 01:22:40 DEBUG : subsub: reading active writers
2026/10/17 01:22:40 DEBUG : dir: Looking for writers
2026/10/17 01:22:40 DEBUG : file1: reading active writers
2026/10/17 01:22:40 DEBUG : sub: reading active writers
2026/10/17 01:22:40 DEBUG : Looking for writers
2026/10/17 01:22:40 DEBUG : dir: reading active writers
2026/10/17 01:22:40 DEBUG : >WaitForWriters: 
--- PASS: TestDirMkdirSub (10.99s)
=== RUN   TestDirUnsafeName
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:22:41 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:22:41 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/17 01:22:41 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/17 01:22:41 DEBUG : >changeNotify: 
2026/10/17 01:22:41 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/17 01:22:41 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/17 01:22:41 DEBUG : >changeNotify: 
=== RUN   TestDirUnsafeName/""_in_""
2026/10/17 01:22:41 ERROR : /: Refusing unsafe name: unsafe path component ""
2026/10/17 01:22:41 ERROR : /: Refusing unsafe name: unsafe path component ""
2026/10/17 01:22:41 ERROR : /: Refusing unsafe name: unsafe path component ""
2026/10/17 01:22:41 ERROR : Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/"."_in_""
2026/10/17 01:22:41 ERROR : /: Refusing unsafe name: unsafe path component "."
2026/10/17 01:22:41 ERROR : /: Refusing unsafe name: unsafe path component "."
2026/10/17 01:22:41 ERROR : /: Refusing unsafe name: unsafe path component "."
2026/10/17 01:22:41 ERROR : .: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/".."_in_""
2026/10/17 01:22:41 ERROR : /: Refusing unsafe name: unsafe path component ".."
2026/10/17 01:22:41 ERROR : /: Refusing unsafe name: unsafe path component ".."
2026/10/17 01:22:41 ERROR : /: Refusing unsafe name: unsafe path component ".."
2026/10/17 01:22:41 ERROR : ..: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/"sub/dir"_in_""
2026/10/17 01:22:41 ERROR : /: Refusing unsafe name: path component "sub/dir" contains a "/"
2026/10/17 01:22:41 ERROR : /: Refusing unsafe name: path component "sub/dir" contains a "/"
2026/10/17 01:22:41 ERROR : /: Refusing unsafe name: path component "sub/dir" contains a "/"
2026/10/17 01:22:41 ERROR : sub/dir: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/"../escape"_in_""
2026/10/17 01:22:41 ERROR : /: Refusing unsafe name: path component "../escape" contains a "/"
2026/10/17 01:22:41 ERROR : /: Refusing unsafe name: path component "../escape" contains a "/"
2026/10/17 01:22:41 ERROR : /: Refusing unsafe name: path component "../escape" contains a "/"
2026/10/17 01:22:41 ERROR : ../escape: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/"escape/.."_in_""
2026/10/17 01:22:41 ERROR : /: Refusing unsafe name: path component "escape/.." contains a "/"
2026/10/17 01:22:41 ERROR : /: Refusing unsafe name: path component "escape/.." contains a "/"
2026/10/17 01:22:41 ERROR : /: Refusing unsafe name: path component "escape/.." contains a "/"
2026/10/17 01:22:41 ERROR : .: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/""_in_"dir"
2026/10/17 01:22:41 ERROR : dir/: Refusing unsafe name: unsafe path component ""
2026/10/17 01:22:41 ERROR : dir/: Refusing unsafe name: unsafe path component ""
2026/10/17 01:22:41 ERROR : dir/: Refusing unsafe name: unsafe path component ""
2026/10/17 01:22:41 ERROR : dir: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/"."_in_"dir"
2026/10/17 01:22:41 ERROR : dir/: Refusing unsafe name: unsafe path component "."
2026/10/17 01:22:41 ERROR : dir/: Refusing unsafe name: unsafe path component "."
2026/10/17 01:22:41 ERROR : dir/: Refusing unsafe name: unsafe path component "."
2026/10/17 01:22:41 ERROR : dir: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/".."_in_"dir"
2026/10/17 01:22:41 ERROR : dir/: Refusing unsafe name: unsafe path component ".."
2026/10/17 01:22:41 ERROR : dir/: Refusing unsafe name: unsafe path component ".."
2026/10/17 01:22:41 ERROR : dir/: Refusing unsafe name: unsafe path component ".."
2026/10/17 01:22:41 ERROR : .: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/"sub/dir"_in_"dir"
2026/10/17 01:22:41 ERROR : dir/: Refusing unsafe name: path component "sub/dir" contains a "/"
2026/10/17 01:22:41 ERROR : dir/: Refusing unsafe name: path component "sub/dir" contains a "/"
2026/10/17 01:22:41 ERROR : dir/: Refusing unsafe name: path component "sub/dir" contains a "/"
2026/10/17 01:22:41 ERROR : dir/sub/dir: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/"../escape"_in_"dir"
2026/10/17 01:22:41 ERROR : dir/: Refusing unsafe name: path component "../escape" contains a "/"
2026/10/17 01:22:41 ERROR : dir/: Refusing unsafe name: path component "../escape" contains a "/"
2026/10/17 01:22:41 ERROR : dir/: Refusing unsafe name: path component "../escape" contains a "/"
2026/10/17 01:22:41 ERROR : escape: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/"escape/.."_in_"dir"
2026/10/17 01:22:41 ERROR : dir/: Refusing unsafe name: path component "escape/.." contains a "/"
2026/10/17 01:22:41 ERROR : dir/: Refusing unsafe name: path component "escape/.." contains a "/"
2026/10/17 01:22:41 ERROR : dir/: Refusing unsafe name: path component "escape/.." contains a "/"
2026/10/17 01:22:41 ERROR : dir: Dir.Rename error: file does not exist
2026/10/17 01:22:41 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:22:41 DEBUG : dir: Looking for writers
2026/10/17 01:22:41 DEBUG : file1: reading active writers
2026/10/17 01:22:41 DEBUG : Looking for writers
2026/10/17 01:22:41 DEBUG : dir: reading active writers
2026/10/17 01:22:41 DEBUG : >WaitForWriters: 
--- PASS: TestDirUnsafeName (1.29s)
    --- PASS: TestDirUnsafeName/""_in_"" (0.00s)
    --- PASS: TestDirUnsafeName/"."_in_"" (0.00s)
    --- PASS: TestDirUnsafeName/".."_in_"" (0.00s)
    --- PASS: TestDirUnsafeName/"sub/dir"_in_"" (0.00s)
    --- PASS: TestDirUnsafeName/"../escape"_in_"" (0.00s)
    --- PASS: TestDirUnsafeName/"escape/.."_in_"" (0.00s)
    --- PASS: TestDirUnsafeName/""_in_"dir" (0.09s)
    --- PASS: TestDirUnsafeName/"."_in_"dir" (0.00s)
    --- PASS: TestDirUnsafeName/".."_in_"dir" (0.00s)
    --- PASS: TestDirUnsafeName/"sub/dir"_in_"dir" (0.00s)
    --- PASS: TestDirUnsafeName/"../escape"_in_"dir" (0.00s)
    --- PASS: TestDirUnsafeName/"escape/.."_in_"dir" (0.00s)
=== RUN   TestDirRemove
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:22:42 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:22:42 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/17 01:22:42 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/17 01:22:42 DEBUG : >changeNotify: 
2026/10/17 01:22:42 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/17 01:22:42 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/17 01:22:42 DEBUG : >changeNotify: 
2026/10/17 01:22:43 ERROR : dir/: Dir.Remove not empty
2026/10/17 01:22:43 DEBUG : dir/file1: Remove: 
2026/10/17 01:22:43 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/17 01:22:43 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/17 01:22:43 DEBUG : dir: invalidating directory cache
2026/10/17 01:22:43 DEBUG : >changeNotify: 
2026/10/17 01:22:43 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/10/17 01:22:43 DEBUG : dir/file1: >Remove: err=<nil>
2026/10/17 01:22:43 DEBUG : dir: Removed virtual directory entry vDel: "file1"
2026/10/17 01:22:43 DEBUG : pcloud root 'rclone-test-hisifad5jopa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/17 01:22:43 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/17 01:22:43 DEBUG : invalidating directory cache
2026/10/17 01:22:43 DEBUG : dir: invalidating directory cache
2026/10/17 01:22:43 DEBUG : >changeNotify: 
2026/10/17 01:22:43 DEBUG : Added virtual directory entry vDel: "dir"
2026/10/17 01:22:43 DEBUG : Removed virtual directory entry vDel: "dir"
2026/10/17 01:22:43 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:22:43 DEBUG : Looking for writers
2026/10/17 01:22:43 DEBUG : >WaitForWriters: 
--- PASS: TestDirRemove (1.44s)
=== RUN   TestDirRemoveVirtuals
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:22:43 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:22:45 DEBUG : dir/file1: Remove: 
2026/10/17 01:22:45 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/10/17 01:22:45 DEBUG : dir/file1: >Remove: err=<nil>
2026/10/17 01:22:45 DEBUG : dir: Removed virtual directory entry vDel: "file1"
2026/10/17 01:22:45 DEBUG : Added virtual directory entry vDel: "dir"
2026/10/17 01:22:45 DEBUG : forgetting directory cache
2026/10/17 01:22:45 DEBUG : Removed virtual directory entry vDel: "dir"
2026/10/17 01:22:45 DEBUG : dir: forgetting directory cache
2026/10/17 01:22:45 DEBUG : forgetting directory cache
2026/10/17 01:22:45 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:22:45 DEBUG : Looking for writers
2026/10/17 01:22:45 DEBUG : >WaitForWriters: 
    run.go:186: removing dir "dir" failed - try 1/3: sleeping 1s: rmdir failed: pcloud error: Directory does not exist. (2005)
    run.go:186: removing dir "dir" failed - try 2/3: sleeping 1.5s: rmdir failed: pcloud error: Directory does not exist. (2005)
    run.go:186: removing dir "dir" failed: rmdir failed: pcloud error: Directory does not exist. (2005)
--- PASS: TestDirRemoveVirtuals (5.03s)
=== RUN   TestDirRemoveAll
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:22:48 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:24:48 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:24:48 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 01:24:49 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 01:24:50 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 01:24:51 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 1/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:26:56 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:26:56 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 01:26:56 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 01:26:57 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 01:26:58 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 2/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:29:04 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:29:04 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 01:29:04 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 01:29:05 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 01:29:06 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 3/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:30:26 DEBUG : forgetting directory cache
2026/10/17 01:30:26 DEBUG : dir: forgetting directory cache
2026/10/17 01:30:26 DEBUG : dir: forgetting directory cache
2026/10/17 01:30:35 DEBUG : forgetting directory cache
2026/10/17 01:30:35 DEBUG : dir: forgetting directory cache
2026/10/17 01:30:35 DEBUG : dir/subdir: forgetting directory cache
2026/10/17 01:30:36 DEBUG : forgetting directory cache
2026/10/17 01:30:36 DEBUG : dir: forgetting directory cache
2026/10/17 01:31:10 DEBUG : forgetting directory cache
2026/10/17 01:31:10 DEBUG : dir: forgetting directory cache
2026/10/17 01:31:11 DEBUG : dir: forgetting directory cache
2026/10/17 01:31:11 DEBUG : forgetting directory cache
2026/10/17 01:31:11 DEBUG : dir: forgetting directory cache
2026/10/17 01:31:25 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:31:25 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 01:31:25 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 01:31:26 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 01:31:27 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 4/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:31:30 DEBUG : forgetting directory cache
2026/10/17 01:31:30 DEBUG : dir: forgetting directory cache
2026/10/17 01:31:47 DEBUG : dir: forgetting directory cache
2026/10/17 01:31:47 DEBUG : forgetting directory cache
2026/10/17 01:31:47 DEBUG : dir: forgetting directory cache
2026/10/17 01:31:47 DEBUG : fil: forgetting directory cache
2026/10/17 01:31:47 DEBUG : fil/a: forgetting directory cache
2026/10/17 01:31:47 DEBUG : fil/a/b: forgetting directory cache
2026/10/17 01:31:49 DEBUG : dir: forgetting directory cache
2026/10/17 01:31:49 DEBUG : forgetting directory cache
2026/10/17 01:31:49 DEBUG : dir: forgetting directory cache
2026/10/17 01:31:59 DEBUG : forgetting directory cache
2026/10/17 01:31:59 DEBUG : dir: forgetting directory cache
2026/10/17 01:32:03 DEBUG : dir/subdir: forgetting directory cache
2026/10/17 01:32:04 DEBUG : dir/virtualDir2: forgetting directory cache
2026/10/17 01:32:04 DEBUG : forgetting directory cache
2026/10/17 01:32:04 DEBUG : dir: forgetting directory cache
2026/10/17 01:32:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/17 01:32:07 DEBUG : forgetting directory cache
2026/10/17 01:32:07 DEBUG : dir: forgetting directory cache
2026/10/17 01:32:07 DEBUG : dir: forgetting directory cache
2026/10/17 01:32:08 DEBUG : forgetting directory cache
2026/10/17 01:32:08 DEBUG : dir: forgetting directory cache
2026/10/17 01:32:21 DEBUG : forgetting directory cache
2026/10/17 01:32:21 DEBUG : dir: forgetting directory cache
2026/10/17 01:32:21 DEBUG : dir/sub: forgetting directory cache
2026/10/17 01:32:21 DEBUG : dir: Removed virtual directory entry vAddDir: "sub"
2026/10/17 01:32:39 DEBUG : forgetting directory cache
2026/10/17 01:32:39 DEBUG : dir: forgetting directory cache
2026/10/17 01:32:39 DEBUG : dir/sub: forgetting directory cache
2026/10/17 01:32:39 DEBUG : dir/sub/subsub: forgetting directory cache
2026/10/17 01:32:41 DEBUG : forgetting directory cache
2026/10/17 01:32:41 DEBUG : dir: forgetting directory cache
2026/10/17 01:32:43 DEBUG : dir: forgetting directory cache
2026/10/17 01:32:43 DEBUG : forgetting directory cache
2026/10/17 01:32:48 DEBUG : forgetting directory cache
2026/10/17 01:33:32 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:33:32 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 01:33:32 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 01:33:33 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 01:33:35 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 5/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:35:40 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:35:40 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 01:35:40 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 01:35:41 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 01:35:42 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 6/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:37:47 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:37:47 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 01:37:48 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 01:37:49 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 01:37:50 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 7/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:39:55 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:39:55 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 01:39:55 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 01:39:56 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 01:39:57 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 8/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:42:03 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:42:03 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 01:42:03 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 01:42:04 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 01:42:04 DEBUG : forgetting directory cache
2026/10/17 01:42:04 DEBUG : dir: forgetting directory cache
2026/10/17 01:42:04 DEBUG : dir: forgetting directory cache
2026/10/17 01:42:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/17 01:42:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/17 01:42:05 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 9/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:44:10 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:44:10 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 01:44:10 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 01:44:11 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 01:44:12 DEBUG : pacer: Reducing sleep to 10ms
    run.go:303: Failed to put "dir/file1" to "pcloud root 'rclone-test-hisifad5jopa'": Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF
2026/10/17 01:44:16 DEBUG : WaitForWriters: timeout=30s
2026/10/17 01:44:16 DEBUG : Looking for writers
2026/10/17 01:44:16 DEBUG : >WaitForWriters: 
--- FAIL: TestDirRemoveAll (1287.42s)
=== RUN   TestDirRemoveName
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 01:44:16 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 01:46:16 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:46:16 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 01:46:16 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 01:46:17 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 01:46:18 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 1/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:48:23 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:48:23 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 01:48:24 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 01:48:25 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 01:48:26 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 2/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:50:31 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:50:31 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 01:50:31 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 01:50:36 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 01:50:37 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 3/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:52:04 DEBUG : forgetting directory cache
2026/10/17 01:52:04 DEBUG : dir: forgetting directory cache
2026/10/17 01:52:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/17 01:52:04 DEBUG : dir: forgetting directory cache
2026/10/17 01:52:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/17 01:52:42 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:52:42 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 01:52:42 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 01:52:43 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 01:52:44 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 4/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:54:16 DEBUG : forgetting directory cache
2026/10/17 01:54:50 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:54:50 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 01:54:50 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 01:54:51 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 01:54:52 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 5/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:56:57 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:56:57 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 01:56:57 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 01:56:58 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 01:57:00 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 6/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:59:05 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 01:59:05 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 01:59:05 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 01:59:06 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 01:59:07 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 7/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 02:01:12 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 02:01:12 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 02:01:17 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 02:01:18 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 02:01:19 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 8/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 02:02:04 DEBUG : dir: forgetting directory cache
2026/10/17 02:02:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/17 02:02:04 DEBUG : forgetting directory cache
2026/10/17 02:02:04 DEBUG : dir: forgetting directory cache
2026/10/17 02:02:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/17 02:03:24 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 02:03:24 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 02:03:24 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 02:03:25 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 02:03:26 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 9/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 02:05:32 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 02:05:32 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 02:05:32 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 02:05:33 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 02:05:34 DEBUG : pacer: Reducing sleep to 10ms
    run.go:303: Failed to put "dir/file1" to "pcloud root 'rclone-test-hisifad5jopa'": Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF
2026/10/17 02:05:37 DEBUG : WaitForWriters: timeout=30s
2026/10/17 02:05:37 DEBUG : Looking for writers
2026/10/17 02:05:37 DEBUG : >WaitForWriters: 
--- FAIL: TestDirRemoveName (1281.63s)
=== RUN   TestDirRename
    run.go:198: Remote "pcloud root 'rclone-test-hisifad5jopa'", Local "Local file system at /tmp/rclone2950321852", Modify Window "1s"
2026/10/17 02:05:37 NOTICE: pcloud root 'rclone-test-hisifad5jopa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/17 02:07:38 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 02:07:38 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 02:07:38 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 02:07:39 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 02:07:40 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 1/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 02:09:46 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 02:09:46 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 02:09:46 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 02:09:47 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 02:09:48 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 2/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 02:11:53 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 02:11:53 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 02:11:53 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 02:11:55 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 02:11:56 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 3/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 02:12:04 DEBUG : forgetting directory cache
2026/10/17 02:12:04 DEBUG : dir: forgetting directory cache
2026/10/17 02:12:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/17 02:12:04 DEBUG : dir: forgetting directory cache
2026/10/17 02:12:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/17 02:14:01 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 02:14:01 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 02:14:01 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 02:14:02 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 02:14:03 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 4/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 02:15:37 DEBUG : forgetting directory cache
2026/10/17 02:16:09 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 02:16:09 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 02:16:09 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 02:16:10 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 02:16:11 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 5/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 02:18:16 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
2026/10/17 02:18:16 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/17 02:18:16 DEBUG : pacer: Reducing sleep to 15ms
2026/10/17 02:18:17 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/17 02:18:18 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-hisifad5jopa': 6/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27146892290&mtime=981173106&nopartial=1": EOF)
panic: test timed out after 1h0m0s
	running tests:
		TestDirRename (14m39s)

goroutine 23951 [running]:
testing.(*M).startAlarm.func1()
	/usr/local/go/src/testing/testing.go:2959 +0x34a
created by time.goFunc
	/usr/local/go/src/time/sleep.go:182 +0x2d

goroutine 1 [chan receive, 14 minutes]:
testing.(*T).Run(0x23ca45af8008, {0x256f68c?, 0x23ca453f7a58?}, 0x49d7980)
	/usr/local/go/src/testing/testing.go:2266 +0x4f2
testing.runTests.func1(0x23ca45af8008)
	/usr/local/go/src/testing/testing.go:2742 +0x37
testing.tRunner(0x23ca45af8008, 0x23ca453f7b80)
	/usr/local/go/src/testing/testing.go:2193 +0xea
testing.runTests({0x25997bf, 0x18}, {0x25ab077, 0x1c}, 0x23ca458edde8, {0x4cb2ee0, 0x6c, 0x6c}, {0xc2acd4b83134bd33, 0x3469c801d78, ...})
	/usr/local/go/src/testing/testing.go:2740 +0x510
testing.(*M).Run(0x23ca45d01720)
	/usr/local/go/src/testing/testing.go:2600 +0x6af
github.com/rclone/rclone/fstest.TestMain(0x23ca45d01720)
	/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:75 +0xa6
github.com/rclone/rclone/vfs.TestMain(...)
	/home/rclone/go/src/github.com/rclone/rclone/vfs/vfs_test.go:36
main.main()
	_testmain.go:264 +0xa6

goroutine 22 [syscall, 60 minutes]:
os/signal.signal_recv()
	/usr/local/go/src/runtime/sigqueue.go:152 +0x98
os/signal.loop()
	/usr/local/go/src/os/signal/signal_unix.go:23 +0x13
created by os/signal.Notify.func2.1 in goroutine 1
	/usr/local/go/src/os/signal/signal.go:164 +0x1f

goroutine 23 [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 +0xae

goroutine 24 [select, 60 minutes]:
github.com/rclone/rclone/lib/oauthutil.(*Renew).renewOnExpiry(0x23ca454ca940)
	/home/rclone/go/src/github.com/rclone/rclone/lib/oauthutil/renew.go:43 +0x85
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 +0xfa

goroutine 19867 [select, 3 minutes]:
net/http.(*persistConn).roundTrip(0x23ca45964640, 0x23ca45aea550)
	/usr/local/go/src/net/http/transport.go:3069 +0x84b
net/http.(*Transport).roundTrip(0x23ca45bdefc0, 0x23ca454d0b40)
	/usr/local/go/src/net/http/transport.go:725 +0xada
net/http.(*Transport).RoundTrip(...)
	/usr/local/go/src/net/http/roundtrip.go:33
github.com/rclone/rclone/fs/fshttp.(*Transport).RoundTrip(0x23ca4567e780, 0x23ca454d0b40)
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:709 +0x657
golang.org/x/oauth2.(*Transport).RoundTrip(0x23ca45cfc000, 0x23ca454d0a00)
	/home/rclone/go/pkg/mod/golang.org/x/oauth2@v0.36.0/transport.go:55 +0x15b
net/http.send(0x23ca454d0a00, {0x4998b30, 0x23ca45cfc000}, {0x23ca45de2c20?, 0x497406?, 0x0?})
	/usr/local/go/src/net/http/client.go:266 +0x654
net/http.(*Client).send(0x23ca45d2e330, 0x23ca454d0a00, {0x271ba40?, 0x1?, 0x0?})
	/usr/local/go/src/net/http/client.go:187 +0x250
net/http.(*Client).do(0x23ca45d2e330, 0x23ca454d0a00)
	/usr/local/go/src/net/http/client.go:745 +0x9f7
net/http.(*Client).Do(...)
	/usr/local/go/src/net/http/client.go:604
github.com/rclone/rclone/lib/rest.(*Client).Call(0x23ca45bbc050, {0x49bcfc0, 0x4cf7140}, 0x23ca45da5080)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:511 +0xe85
github.com/rclone/rclone/lib/rest.(*Client).callCodec(0x23ca45bbc050, {0x49bcfc0, 0x4cf7140}, 0x745c17046a00?, {0x0?, 0x0?}, {0x415f750, 0x23ca45c11bc0}, 0x41ea85?, 0x49d95e0, ...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:757 +0x4e8
github.com/rclone/rclone/lib/rest.(*Client).CallJSON(...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:694
github.com/rclone/rclone/backend/pcloud.(*Object).Update.func1()
	/home/rclone/go/src/github.com/rclone/rclone/backend/pcloud/pcloud.go:1551 +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(0x23ca4567e540, 0x23ca45990780, 0x1)
	/home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:228 +0xd2
github.com/rclone/rclone/lib/pacer.(*Pacer).CallNoRetry(...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:256
github.com/rclone/rclone/backend/pcloud.(*Object).Update(0x23ca45545680, {0x49bcfc0, 0x4cf7140}, {0x4994f30, 0x23ca4592de60}, {0x49c65d0, 0x23ca4565b9d0}, {0x0, 0x0, 0x0})
	/home/rclone/go/src/github.com/rclone/rclone/backend/pcloud/pcloud.go:1550 +0xbf0
github.com/rclone/rclone/backend/pcloud.(*Fs).Put(0x23ca458864d0, {0x49bcfc0, 0x4cf7140}, {0x4994f30, 0x23ca4592de60}, {0x49c65d0, 0x23ca4565b9d0}, {0x0, 0x0, 0x0})
	/home/rclone/go/src/github.com/rclone/rclone/backend/pcloud/pcloud.go:781 +0x14c
github.com/rclone/rclone/fstest.(*Run).WriteObjectTo(0x23ca4565a2a0, {0x49bcfc0, 0x4cf7140}, {0x49cc988, 0x23ca458864d0}, {0x256313a, 0x9}, {0x2572d76, 0xe}, {0x1dcd64ff, ...}, ...)
	/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:293 +0x408
github.com/rclone/rclone/fstest.(*Run).WriteObject(...)
	/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:310
github.com/rclone/rclone/vfs.dirCreate(0x23ca454fc908)
	/home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:28 +0xb2
github.com/rclone/rclone/vfs.TestDirRename(0x23ca454fc908)
	/home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:618 +0x45
testing.tRunner(0x23ca454fc908, 0x49d7980)
	/usr/local/go/src/testing/testing.go:2193 +0xea
created by testing.(*T).Run in goroutine 1
	/usr/local/go/src/testing/testing.go:2258 +0x4d4

goroutine 19868 [select]:
net/http.(*persistConn).roundTrip(0x23ca4613c640, 0x23ca45aea0a0)
	/usr/local/go/src/net/http/transport.go:3069 +0x84b
net/http.(*Transport).roundTrip(0x23ca45bdefc0, 0x23ca4613c500)
	/usr/local/go/src/net/http/transport.go:725 +0xada
net/http.(*Transport).RoundTrip(...)
	/usr/local/go/src/net/http/roundtrip.go:33
github.com/rclone/rclone/fs/fshttp.(*Transport).RoundTrip(0x23ca4567e780, 0x23ca4613c500)
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:709 +0x657
golang.org/x/oauth2.(*Transport).RoundTrip(0x23ca45cfc000, 0x23ca4613c000)
	/home/rclone/go/pkg/mod/golang.org/x/oauth2@v0.36.0/transport.go:55 +0x15b
net/http.send(0x23ca4613c000, {0x4998b30, 0x23ca45cfc000}, {0x23ca45de7198?, 0x497406?, 0x0?})
	/usr/local/go/src/net/http/client.go:266 +0x654
net/http.(*Client).send(0x23ca45d2e330, 0x23ca4613c000, {0x271ba40?, 0x23ca45de71d8?, 0x0?})
	/usr/local/go/src/net/http/client.go:187 +0x250
net/http.(*Client).do(0x23ca45d2e330, 0x23ca4613c000)
	/usr/local/go/src/net/http/client.go:745 +0x9f7
net/http.(*Client).Do(...)
	/usr/local/go/src/net/http/client.go:604
github.com/rclone/rclone/lib/rest.(*Client).Call(0x23ca45bbc050, {0x49bd110, 0x23ca458ce070}, 0x23ca45de7b40)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:511 +0xe85
github.com/rclone/rclone/lib/rest.(*Client).callCodec(0x23ca45bbc050, {0x49bd110, 0x23ca458ce070}, 0x745bd03ad430?, {0x0?, 0x0?}, {0x4159870, 0x23ca46208000}, 0x429ab28?, 0x49d95e0, ...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:757 +0x4e8
github.com/rclone/rclone/lib/rest.(*Client).CallJSON(...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:694
github.com/rclone/rclone/backend/pcloud.(*Fs).changeNotifyLoop(0x23ca458864d0, {0x49bd0a0, 0x23ca45aea500}, 0x23ca45d02880, 0x23ca45449490)
	/home/rclone/go/src/github.com/rclone/rclone/backend/pcloud/pcloud.go:1209 +0x4ad
created by github.com/rclone/rclone/backend/pcloud.(*Fs).ChangeNotify in goroutine 19867
	/home/rclone/go/src/github.com/rclone/rclone/backend/pcloud/pcloud.go:1114 +0xb4

goroutine 19896 [select, 14 minutes]:
github.com/rclone/rclone/vfs.(*VFS).signalHandler(0x23ca45edd600, {0x49bd0a0, 0x23ca45aea500})
	/home/rclone/go/src/github.com/rclone/rclone/vfs/vfs.go:307 +0xc5
created by github.com/rclone/rclone/vfs.New in goroutine 19867
	/home/rclone/go/src/github.com/rclone/rclone/vfs/vfs.go:282 +0x8fc

goroutine 23882 [IO wait, 3 minutes]:
internal/poll.runtime_pollWait(0x745bd03ace00, 0x72)
	/usr/local/go/src/runtime/netpoll.go:351 +0x85
internal/poll.(*pollDesc).wait(0x23ca46039000?, 0x23ca45e60000?, 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(0x23ca46039000, {0x23ca45e60000, 0x1980, 0x1980})
	/usr/local/go/src/internal/poll/fd_unix.go:170 +0x2a8
net.(*netFD).Read(0x23ca46039000, {0x23ca45e60000?, 0x23ca45e60005?, 0x23ca45830310?})
	/usr/local/go/src/net/fd_posix.go:68 +0x25
net.(*conn).Read(0x23ca45830310, {0x23ca45e60000?, 0x0?, 0x170023ca45e8aa10?})
	/usr/local/go/src/net/net.go:196 +0x45
github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0x23ca45a48a38, {0x23ca45e60000?, 0x745bce1bebc8?, 0x745c17047bf0?})
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29
crypto/tls.(*Conn).readFromUntil(0x23ca45b0e008, {0x745bcd0d6040, 0x23ca45a48a38}, 0x23ca459c1ef9?)
	/usr/local/go/src/crypto/tls/conn.go:820 +0xf4
crypto/tls.(*Conn).readRecordOrCCS(0x23ca45b0e008, 0x0)
	/usr/local/go/src/crypto/tls/conn.go:626 +0x3fb
crypto/tls.(*Conn).readRecord(...)
	/usr/local/go/src/crypto/tls/conn.go:588
crypto/tls.(*Conn).Read(0x23ca45b0e008, {0x23ca45e32000, 0x1000, 0x70?})
	/usr/local/go/src/crypto/tls/conn.go:1392 +0x148
net/http.(*persistConn).Read(0x23ca45964640, {0x23ca45e32000?, 0x70?, 0x0?})
	/usr/local/go/src/net/http/transport.go:2300 +0x47
bufio.(*Reader).fill(0x23ca45f5c2a0)
	/usr/local/go/src/bufio/bufio.go:113 +0x103
bufio.(*Reader).Peek(0x23ca45f5c2a0, 0x1)
	/usr/local/go/src/bufio/bufio.go:152 +0x52
net/http.(*persistConn).readLoop(0x23ca45964640)
	/usr/local/go/src/net/http/transport.go:2483 +0x172
created by net/http.(*Transport).dialConn in goroutine 23878
	/usr/local/go/src/net/http/transport.go:2123 +0x1da5

goroutine 23883 [select, 3 minutes]:
net/http.(*persistConn).writeLoop(0x23ca45964640)
	/usr/local/go/src/net/http/transport.go:2810 +0xe6
created by net/http.(*Transport).dialConn in goroutine 23878
	/usr/local/go/src/net/http/transport.go:2124 +0x1e05

goroutine 23956 [select]:
net/http.(*persistConn).writeLoop(0x23ca4613c640)
	/usr/local/go/src/net/http/transport.go:2810 +0xe6
created by net/http.(*Transport).dialConn in goroutine 23947
	/usr/local/go/src/net/http/transport.go:2124 +0x1e05

goroutine 23955 [IO wait]:
internal/poll.runtime_pollWait(0x745bd03ad400, 0x72)
	/usr/local/go/src/runtime/netpoll.go:351 +0x85
internal/poll.(*pollDesc).wait(0x23ca46038700?, 0x23ca46097980?, 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(0x23ca46038700, {0x23ca46097980, 0x1980, 0x1980})
	/usr/local/go/src/internal/poll/fd_unix.go:170 +0x2a8
net.(*netFD).Read(0x23ca46038700, {0x23ca46097980?, 0x23ca460979d4?, 0x23ca458300b0?})
	/usr/local/go/src/net/fd_posix.go:68 +0x25
net.(*conn).Read(0x23ca458300b0, {0x23ca46097980?, 0x23ca45ee9a18?, 0x170023ca45ee9a10?})
	/usr/local/go/src/net/net.go:196 +0x45
github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0x23ca45a480d8, {0x23ca46097980?, 0x745bccfae520?, 0x745c17047bf0?})
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29
crypto/tls.(*Conn).readFromUntil(0x23ca45b0e408, {0x745bcd0d6040, 0x23ca45a480d8}, 0x23ca45e301b9?)
	/usr/local/go/src/crypto/tls/conn.go:820 +0xf4
crypto/tls.(*Conn).readRecordOrCCS(0x23ca45b0e408, 0x0)
	/usr/local/go/src/crypto/tls/conn.go:626 +0x3fb
crypto/tls.(*Conn).readRecord(...)
	/usr/local/go/src/crypto/tls/conn.go:588
crypto/tls.(*Conn).Read(0x23ca45b0e408, {0x23ca45796000, 0x1000, 0x70?})
	/usr/local/go/src/crypto/tls/conn.go:1392 +0x148
net/http.(*persistConn).Read(0x23ca4613c640, {0x23ca45796000?, 0x70?, 0x0?})
	/usr/local/go/src/net/http/transport.go:2300 +0x47
bufio.(*Reader).fill(0x23ca45f5c660)
	/usr/local/go/src/bufio/bufio.go:113 +0x103
bufio.(*Reader).Peek(0x23ca45f5c660, 0x1)
	/usr/local/go/src/bufio/bufio.go:152 +0x52
net/http.(*persistConn).readLoop(0x23ca4613c640)
	/usr/local/go/src/net/http/transport.go:2483 +0x172
created by net/http.(*Transport).dialConn in goroutine 23947
	/usr/local/go/src/net/http/transport.go:2123 +0x1da5
"./vfs.test -test.v -test.timeout 1h0m0s -remote TestPcloud: -verbose" - Finished ERROR in 1h0m1.824154016s (try 1/5): exit status 2: Failed [TestDirRemoveAll TestDirRemoveName]