"./vfs.test -test.v -test.timeout 1h0m0s -remote TestPcloud: -verbose" - Starting (try 1/5)
2026/10/21 01:12:55 DEBUG : Creating backend with remote "TestPcloud:rclone-test-bolucaq7suji"
2026/10/21 01:12:55 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/10/21 01:12:56 DEBUG : Creating backend with remote "/tmp/rclone341005904"
=== RUN   TestDirHandleMethods
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:12:56 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:12:57 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir" (type: 0)
2026/10/21 01:12:57 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/21 01:12:57 DEBUG : >changeNotify: 
2026/10/21 01:12:57 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/21 01:12:57 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/21 01:12:57 DEBUG : >changeNotify: 
2026/10/21 01:12:58 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:12:58 DEBUG : dir: Looking for writers
2026/10/21 01:12:58 DEBUG : Looking for writers
2026/10/21 01:12:58 DEBUG : dir: reading active writers
2026/10/21 01:12:58 DEBUG : >WaitForWriters: 
--- PASS: TestDirHandleMethods (2.60s)
=== RUN   TestDirHandleReaddir
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:12:59 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:12:59 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir" (type: 0)
2026/10/21 01:12:59 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/21 01:12:59 DEBUG : >changeNotify: 
2026/10/21 01:12:59 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/21 01:12:59 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/21 01:12:59 DEBUG : >changeNotify: 
2026/10/21 01:12:59 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file2" (type: 1)
2026/10/21 01:12:59 DEBUG : changeNotify: relativePath="dir/file2", type=1
2026/10/21 01:12:59 DEBUG : >changeNotify: 
2026/10/21 01:12:59 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/subdir" (type: 0)
2026/10/21 01:12:59 DEBUG : changeNotify: relativePath="dir/subdir", type=0
2026/10/21 01:12:59 DEBUG : >changeNotify: 
2026/10/21 01:12:59 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/subdir/file3" (type: 1)
2026/10/21 01:12:59 DEBUG : changeNotify: relativePath="dir/subdir/file3", type=1
2026/10/21 01:12:59 DEBUG : >changeNotify: 
2026/10/21 01:13:00 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:13:00 DEBUG : dir/subdir: Looking for writers
2026/10/21 01:13:00 DEBUG : dir: Looking for writers
2026/10/21 01:13:00 DEBUG : file1: reading active writers
2026/10/21 01:13:00 DEBUG : file2: reading active writers
2026/10/21 01:13:00 DEBUG : subdir: reading active writers
2026/10/21 01:13:00 DEBUG : Looking for writers
2026/10/21 01:13:00 DEBUG : dir: reading active writers
2026/10/21 01:13:00 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: TestDirHandleReaddir (18.65s)
=== RUN   TestDirHandleReaddirnames
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:13:17 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:13:17 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir" (type: 0)
2026/10/21 01:13:17 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/21 01:13:17 DEBUG : >changeNotify: 
2026/10/21 01:13:18 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/21 01:13:18 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/21 01:13:18 DEBUG : >changeNotify: 
2026/10/21 01:13:18 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:13:18 DEBUG : dir: Looking for writers
2026/10/21 01:13:18 DEBUG : file1: reading active writers
2026/10/21 01:13:18 DEBUG : Looking for writers
2026/10/21 01:13:18 DEBUG : dir: reading active writers
2026/10/21 01:13:18 DEBUG : >WaitForWriters: 
--- PASS: TestDirHandleReaddirnames (1.08s)
=== RUN   TestDirLinksInvalidName
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:13:18 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:13:18 NOTICE: pcloud root 'rclone-test-bolucaq7suji': Symlinks support enabled
2026/10/21 01:13:18 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir" (type: 0)
2026/10/21 01:13:18 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/21 01:13:18 DEBUG : >changeNotify: 
2026/10/21 01:13:19 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/...rclonelink" (type: 1)
2026/10/21 01:13:19 DEBUG : changeNotify: relativePath="dir/...rclonelink", type=1
2026/10/21 01:13:19 DEBUG : >changeNotify: 
2026/10/21 01:13:19 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/21 01:13:19 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/21 01:13:19 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/21 01:13:28 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:13:28 DEBUG : dir: Looking for writers
2026/10/21 01:13:28 DEBUG : file1: reading active writers
2026/10/21 01:13:28 DEBUG : Looking for writers
2026/10/21 01:13:28 DEBUG : dir: reading active writers
2026/10/21 01:13:28 DEBUG : >WaitForWriters: 
--- PASS: TestDirLinksInvalidName (9.85s)
=== RUN   TestDirMethods
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:13:28 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:13:28 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir" (type: 0)
2026/10/21 01:13:28 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/21 01:13:28 DEBUG : >changeNotify: 
2026/10/21 01:13:28 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/21 01:13:28 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/21 01:13:28 DEBUG : >changeNotify: 
2026/10/21 01:13:29 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:13:29 DEBUG : dir: Looking for writers
2026/10/21 01:13:29 DEBUG : Looking for writers
2026/10/21 01:13:29 DEBUG : dir: reading active writers
2026/10/21 01:13:29 DEBUG : >WaitForWriters: 
--- PASS: TestDirMethods (0.97s)
=== RUN   TestDirForgetAll
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:13:29 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:13:29 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir" (type: 0)
2026/10/21 01:13:29 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/21 01:13:29 DEBUG : >changeNotify: 
2026/10/21 01:13:29 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/21 01:13:29 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/21 01:13:29 DEBUG : >changeNotify: 
2026/10/21 01:13:30 DEBUG : dir: forgetting directory cache
2026/10/21 01:13:30 DEBUG : forgetting directory cache
2026/10/21 01:13:30 DEBUG : dir: forgetting directory cache
2026/10/21 01:13:30 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:13:30 DEBUG : Looking for writers
2026/10/21 01:13:30 DEBUG : >WaitForWriters: 
--- PASS: TestDirForgetAll (1.05s)
=== RUN   TestDirForgetPath
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:13:30 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:13:30 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir" (type: 0)
2026/10/21 01:13:30 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/21 01:13:30 DEBUG : >changeNotify: 
2026/10/21 01:13:30 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/21 01:13:30 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/21 01:13:30 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/21 01:13:40 DEBUG : ForgetPath: relativePath="dir/notfound", type=1
2026/10/21 01:13:40 DEBUG : dir: invalidating directory cache
2026/10/21 01:13:40 DEBUG : >ForgetPath: 
2026/10/21 01:13:40 DEBUG : ForgetPath: relativePath="dir", type=0
2026/10/21 01:13:40 DEBUG : invalidating directory cache
2026/10/21 01:13:40 DEBUG : dir: forgetting directory cache
2026/10/21 01:13:40 DEBUG : >ForgetPath: 
2026/10/21 01:13:40 DEBUG : ForgetPath: relativePath="not/in/cache", type=0
2026/10/21 01:13:40 DEBUG : >ForgetPath: 
2026/10/21 01:13:40 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:13:40 DEBUG : dir: Looking for writers
2026/10/21 01:13:40 DEBUG : Looking for writers
2026/10/21 01:13:40 DEBUG : dir: reading active writers
2026/10/21 01:13:40 DEBUG : >WaitForWriters: 
--- PASS: TestDirForgetPath (9.84s)
=== RUN   TestDirWalk
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:13:40 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:13:40 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir" (type: 0)
2026/10/21 01:13:40 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/21 01:13:40 DEBUG : >changeNotify: 
2026/10/21 01:13:40 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/21 01:13:40 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/21 01:13:40 DEBUG : >changeNotify: 
2026/10/21 01:13:41 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "fil" (type: 0)
2026/10/21 01:13:41 DEBUG : changeNotify: relativePath="fil", type=0
2026/10/21 01:13:41 DEBUG : invalidating directory cache
2026/10/21 01:13:41 DEBUG : >changeNotify: 
2026/10/21 01:13:41 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "fil/a" (type: 0)
2026/10/21 01:13:41 DEBUG : changeNotify: relativePath="fil/a", type=0
2026/10/21 01:13:41 DEBUG : >changeNotify: 
2026/10/21 01:13:41 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "fil/a/b" (type: 0)
2026/10/21 01:13:41 DEBUG : changeNotify: relativePath="fil/a/b", type=0
2026/10/21 01:13:41 DEBUG : >changeNotify: 
2026/10/21 01:13:41 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "fil/a/b/c" (type: 1)
2026/10/21 01:13:41 DEBUG : changeNotify: relativePath="fil/a/b/c", type=1
2026/10/21 01:13:41 DEBUG : >changeNotify: 
2026/10/21 01:13:42 DEBUG : forgetting directory cache
2026/10/21 01:13:42 DEBUG : dir: forgetting directory cache
2026/10/21 01:13:42 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:13:42 DEBUG : dir: Looking for writers
2026/10/21 01:13:42 DEBUG : fil/a/b: Looking for writers
2026/10/21 01:13:42 DEBUG : fil/a: Looking for writers
2026/10/21 01:13:42 DEBUG : b: reading active writers
2026/10/21 01:13:42 DEBUG : fil: Looking for writers
2026/10/21 01:13:42 DEBUG : a: reading active writers
2026/10/21 01:13:42 DEBUG : Looking for writers
2026/10/21 01:13:42 DEBUG : dir: reading active writers
2026/10/21 01:13:42 DEBUG : fil: reading active writers
2026/10/21 01:13:42 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: TestDirWalk (10.87s)
=== RUN   TestDirSetModTime
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:13:51 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:13:51 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir" (type: 0)
2026/10/21 01:13:51 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/21 01:13:51 DEBUG : >changeNotify: 
2026/10/21 01:13:51 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/21 01:13:51 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/21 01:13:51 DEBUG : >changeNotify: 
2026/10/21 01:13:51 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:13:51 DEBUG : dir: Looking for writers
2026/10/21 01:13:51 DEBUG : Looking for writers
2026/10/21 01:13:51 DEBUG : dir: reading active writers
2026/10/21 01:13:51 DEBUG : >WaitForWriters: 
--- PASS: TestDirSetModTime (0.96s)
=== RUN   TestDirStat
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:13:52 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:13:52 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir" (type: 0)
2026/10/21 01:13:52 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/21 01:13:52 DEBUG : >changeNotify: 
2026/10/21 01:13:52 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/21 01:13:52 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/21 01:13:52 DEBUG : >changeNotify: 
2026/10/21 01:13:53 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:13:53 DEBUG : dir: Looking for writers
2026/10/21 01:13:53 DEBUG : file1: reading active writers
2026/10/21 01:13:53 DEBUG : Looking for writers
2026/10/21 01:13:53 DEBUG : dir: reading active writers
2026/10/21 01:13:53 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: TestDirStat (9.90s)
=== RUN   TestDirReadDirAll
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:14:02 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:14:02 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir" (type: 0)
2026/10/21 01:14:02 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/21 01:14:02 DEBUG : >changeNotify: 
2026/10/21 01:14:02 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/21 01:14:02 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/21 01:14:02 DEBUG : >changeNotify: 
2026/10/21 01:14:02 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file2" (type: 1)
2026/10/21 01:14:02 DEBUG : changeNotify: relativePath="dir/file2", type=1
2026/10/21 01:14:02 DEBUG : >changeNotify: 
2026/10/21 01:14:02 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/subdir" (type: 0)
2026/10/21 01:14:02 DEBUG : changeNotify: relativePath="dir/subdir", type=0
2026/10/21 01:14:02 DEBUG : >changeNotify: 
2026/10/21 01:14:02 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/subdir/file3" (type: 1)
2026/10/21 01:14:02 DEBUG : changeNotify: relativePath="dir/subdir/file3", type=1
2026/10/21 01:14:02 DEBUG : >changeNotify: 
=== RUN   TestDirReadDirAll/Virtual
2026/10/21 01:14:03 DEBUG : dir: Added virtual directory entry vAddFile: "virtualFile"
2026/10/21 01:14:03 DEBUG : dir: Added virtual directory entry vAddDir: "virtualDir"
2026/10/21 01:14:03 DEBUG : dir: Added virtual directory entry vDel: "file2"
2026/10/21 01:14:03 DEBUG : dir: Added virtual directory entry vDel: "subdir"
2026/10/21 01:14:03 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/virtualFile" (type: 1)
2026/10/21 01:14:03 DEBUG : changeNotify: relativePath="dir/virtualFile", type=1
2026/10/21 01:14:03 DEBUG : dir: invalidating directory cache
2026/10/21 01:14:03 DEBUG : >changeNotify: 
2026/10/21 01:14:03 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/virtualDir" (type: 0)
2026/10/21 01:14:03 DEBUG : changeNotify: relativePath="dir/virtualDir", type=0
2026/10/21 01:14:03 DEBUG : >changeNotify: 
2026/10/21 01:14:03 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/virtualDir/testFile" (type: 1)
2026/10/21 01:14:03 DEBUG : changeNotify: relativePath="dir/virtualDir/testFile", type=1
2026/10/21 01:14:03 DEBUG : >changeNotify: 
2026/10/21 01:14:04 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file2" (type: 1)
2026/10/21 01:14:04 DEBUG : changeNotify: relativePath="dir/file2", type=1
2026/10/21 01:14:04 DEBUG : >changeNotify: 
2026/10/21 01:14:04 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/subdir" (type: 0)
2026/10/21 01:14:04 DEBUG : changeNotify: relativePath="dir/subdir", type=0
2026/10/21 01:14:04 DEBUG : dir: Removed virtual directory entry vDel: "subdir"
2026/10/21 01:14:04 DEBUG : dir: Removed virtual directory entry vAddDir: "virtualDir"
2026/10/21 01:14:04 DEBUG : dir: Removed virtual directory entry vDel: "file2"
2026/10/21 01:14:04 DEBUG : dir/file1: Reset virtual modtime
2026/10/21 01:14:04 DEBUG : dir: Removed virtual directory entry vAddFile: "virtualFile"
2026/10/21 01:14:04 DEBUG : dir/virtualFile: Reset virtual modtime
2026/10/21 01:14:04 DEBUG : dir: Added virtual directory entry vAddFile: "virtualFile2"
2026/10/21 01:14:04 DEBUG : dir: Added virtual directory entry vAddDir: "virtualDir2"
2026/10/21 01:14:04 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/10/21 01:14:04 DEBUG : dir: invalidating directory cache
2026/10/21 01:14:04 DEBUG : dir: Removed virtual directory entry vDel: "file1"
2026/10/21 01:14:04 DEBUG : dir: Removed virtual directory entry vAddDir: "virtualDir2"
2026/10/21 01:14:04 DEBUG : dir/virtualFile: Reset virtual modtime
2026/10/21 01:14:04 DEBUG : dir: invalidating directory cache
2026/10/21 01:14:04 DEBUG : >changeNotify: 
2026/10/21 01:14:04 DEBUG : forgetting directory cache
2026/10/21 01:14:04 DEBUG : dir: forgetting directory cache
2026/10/21 01:14:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/21 01:14:04 DEBUG : dir/file1: Reset virtual modtime
2026/10/21 01:14:04 DEBUG : dir/virtualFile: Reset virtual modtime
2026/10/21 01:14:04 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:14:04 DEBUG : dir/virtualDir: Looking for writers
2026/10/21 01:14:04 DEBUG : dir: Looking for writers
2026/10/21 01:14:04 DEBUG : virtualFile: reading active writers
2026/10/21 01:14:04 DEBUG : virtualDir: reading active writers
2026/10/21 01:14:04 DEBUG : file1: reading active writers
2026/10/21 01:14:04 DEBUG : virtualFile2: reading active writers
2026/10/21 01:14:04 DEBUG : Looking for writers
2026/10/21 01:14:04 DEBUG : dir: reading active writers
2026/10/21 01:14:04 DEBUG : >WaitForWriters: 
--- PASS: TestDirReadDirAll (3.07s)
    --- PASS: TestDirReadDirAll/Virtual (0.99s)
=== RUN   TestDirOpen
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:14:05 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:14:05 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir" (type: 0)
2026/10/21 01:14:05 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/21 01:14:05 DEBUG : >changeNotify: 
2026/10/21 01:14:05 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/21 01:14:05 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/21 01:14:05 DEBUG : >changeNotify: 
2026/10/21 01:14:05 ERROR : dir/: Can only open directories read only
2026/10/21 01:14:05 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:14:05 DEBUG : dir: Looking for writers
2026/10/21 01:14:05 DEBUG : Looking for writers
2026/10/21 01:14:05 DEBUG : dir: reading active writers
2026/10/21 01:14:05 DEBUG : >WaitForWriters: 
--- PASS: TestDirOpen (0.95s)
=== RUN   TestDirCreate
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:14:06 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:14:06 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir" (type: 0)
2026/10/21 01:14:06 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/21 01:14:06 DEBUG : >changeNotify: 
2026/10/21 01:14:06 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/21 01:14:06 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/21 01:14:06 DEBUG : >changeNotify: 
2026/10/21 01:14:07 DEBUG : dir/potato: Open: flags=O_WRONLY|O_CREATE
2026/10/21 01:14:07 DEBUG : dir: Added virtual directory entry vAddFile: "potato"
2026/10/21 01:14:07 DEBUG : dir/potato: >Open: fd=dir/potato (w), err=<nil>
2026/10/21 01:14:07 DEBUG : dir: Added virtual directory entry vAddFile: "potato"
2026/10/21 01:14:07 DEBUG : pcloud root 'rclone-test-bolucaq7suji': File to upload is small (5 bytes), uploading instead of streaming
2026/10/21 01:14:07 DEBUG : dir/potato: size = 5 OK
2026/10/21 01:14:07 DEBUG : dir/potato: sha1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK
2026/10/21 01:14:07 DEBUG : dir/potato: Size and sha1 of src and dst objects identical
2026/10/21 01:14:07 DEBUG : dir: Added virtual directory entry vAddFile: "potato"
2026/10/21 01:14:07 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:14:07 DEBUG : dir: Looking for writers
2026/10/21 01:14:07 DEBUG : file1: reading active writers
2026/10/21 01:14:07 DEBUG : potato: reading active writers
2026/10/21 01:14:07 DEBUG : Looking for writers
2026/10/21 01:14:07 DEBUG : dir: reading active writers
2026/10/21 01:14:07 DEBUG : >WaitForWriters: 
--- PASS: TestDirCreate (1.35s)
=== RUN   TestDirMkdir
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:14:07 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:14:07 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir" (type: 0)
2026/10/21 01:14:07 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/21 01:14:07 DEBUG : >changeNotify: 
2026/10/21 01:14:07 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/21 01:14:07 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/21 01:14:07 DEBUG : >changeNotify: 
2026/10/21 01:14:08 DEBUG : dir: Added virtual directory entry vAddDir: "sub"
2026/10/21 01:14:08 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/sub" (type: 0)
2026/10/21 01:14:08 DEBUG : changeNotify: relativePath="dir/sub", type=0
2026/10/21 01:14:08 DEBUG : dir: invalidating directory cache
2026/10/21 01:14:08 DEBUG : dir/sub: invalidating directory cache
2026/10/21 01:14:08 DEBUG : >changeNotify: 
2026/10/21 01:14:08 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:14:08 DEBUG : dir/sub: Looking for writers
2026/10/21 01:14:08 DEBUG : dir: Looking for writers
2026/10/21 01:14:08 DEBUG : file1: reading active writers
2026/10/21 01:14:08 DEBUG : sub: reading active writers
2026/10/21 01:14:08 DEBUG : Looking for writers
2026/10/21 01:14:08 DEBUG : dir: reading active writers
2026/10/21 01:14:08 DEBUG : >WaitForWriters: 
--- PASS: TestDirMkdir (1.83s)
=== RUN   TestDirMkdirSub
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:14:09 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:14:09 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir" (type: 0)
2026/10/21 01:14:09 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/21 01:14:09 DEBUG : >changeNotify: 
2026/10/21 01:14:09 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/21 01:14:09 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/21 01:14:09 DEBUG : >changeNotify: 
2026/10/21 01:14:10 DEBUG : dir: Added virtual directory entry vAddDir: "sub"
2026/10/21 01:14:10 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/sub" (type: 0)
2026/10/21 01:14:10 DEBUG : changeNotify: relativePath="dir/sub", type=0
2026/10/21 01:14:10 DEBUG : dir: invalidating directory cache
2026/10/21 01:14:10 DEBUG : dir/sub: invalidating directory cache
2026/10/21 01:14:10 DEBUG : >changeNotify: 
2026/10/21 01:14:10 DEBUG : dir/sub: Added virtual directory entry vAddDir: "subsub"
2026/10/21 01:14:10 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/sub/subsub" (type: 0)
2026/10/21 01:14:10 DEBUG : changeNotify: relativePath="dir/sub/subsub", type=0
2026/10/21 01:14:10 DEBUG : dir: Removed virtual directory entry vAddDir: "sub"
2026/10/21 01:14:10 DEBUG : dir/file1: Reset virtual modtime
2026/10/21 01:14:10 DEBUG : dir/sub: Removed virtual directory entry vAddDir: "subsub"
2026/10/21 01:14:10 DEBUG : dir/sub: invalidating directory cache
2026/10/21 01:14:10 DEBUG : dir/sub/subsub: invalidating directory cache
2026/10/21 01:14:10 DEBUG : >changeNotify: 
2026/10/21 01:14:11 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:14:11 DEBUG : dir/sub/subsub: Looking for writers
2026/10/21 01:14:11 DEBUG : dir/sub: Looking for writers
2026/10/21 01:14:11 DEBUG : subsub: reading active writers
2026/10/21 01:14:11 DEBUG : dir: Looking for writers
2026/10/21 01:14:11 DEBUG : file1: reading active writers
2026/10/21 01:14:11 DEBUG : sub: reading active writers
2026/10/21 01:14:11 DEBUG : Looking for writers
2026/10/21 01:14:11 DEBUG : dir: reading active writers
2026/10/21 01:14:11 DEBUG : >WaitForWriters: 
--- PASS: TestDirMkdirSub (2.24s)
=== RUN   TestDirUnsafeName
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:14:11 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:14:11 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir" (type: 0)
2026/10/21 01:14:11 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/21 01:14:11 DEBUG : >changeNotify: 
2026/10/21 01:14:11 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/21 01:14:11 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/21 01:14:11 DEBUG : >changeNotify: 
=== RUN   TestDirUnsafeName/""_in_""
2026/10/21 01:14:12 ERROR : /: Refusing unsafe name: unsafe path component ""
2026/10/21 01:14:12 ERROR : /: Refusing unsafe name: unsafe path component ""
2026/10/21 01:14:12 ERROR : /: Refusing unsafe name: unsafe path component ""
2026/10/21 01:14:12 ERROR : Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/"."_in_""
2026/10/21 01:14:12 ERROR : /: Refusing unsafe name: unsafe path component "."
2026/10/21 01:14:12 ERROR : /: Refusing unsafe name: unsafe path component "."
2026/10/21 01:14:12 ERROR : /: Refusing unsafe name: unsafe path component "."
2026/10/21 01:14:12 ERROR : .: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/".."_in_""
2026/10/21 01:14:12 ERROR : /: Refusing unsafe name: unsafe path component ".."
2026/10/21 01:14:12 ERROR : /: Refusing unsafe name: unsafe path component ".."
2026/10/21 01:14:12 ERROR : /: Refusing unsafe name: unsafe path component ".."
2026/10/21 01:14:12 ERROR : ..: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/"sub/dir"_in_""
2026/10/21 01:14:12 ERROR : /: Refusing unsafe name: path component "sub/dir" contains a "/"
2026/10/21 01:14:12 ERROR : /: Refusing unsafe name: path component "sub/dir" contains a "/"
2026/10/21 01:14:12 ERROR : /: Refusing unsafe name: path component "sub/dir" contains a "/"
2026/10/21 01:14:12 ERROR : sub/dir: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/"../escape"_in_""
2026/10/21 01:14:12 ERROR : /: Refusing unsafe name: path component "../escape" contains a "/"
2026/10/21 01:14:12 ERROR : /: Refusing unsafe name: path component "../escape" contains a "/"
2026/10/21 01:14:12 ERROR : /: Refusing unsafe name: path component "../escape" contains a "/"
2026/10/21 01:14:12 ERROR : ../escape: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/"escape/.."_in_""
2026/10/21 01:14:12 ERROR : /: Refusing unsafe name: path component "escape/.." contains a "/"
2026/10/21 01:14:12 ERROR : /: Refusing unsafe name: path component "escape/.." contains a "/"
2026/10/21 01:14:12 ERROR : /: Refusing unsafe name: path component "escape/.." contains a "/"
2026/10/21 01:14:12 ERROR : .: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/""_in_"dir"
2026/10/21 01:14:12 ERROR : dir/: Refusing unsafe name: unsafe path component ""
2026/10/21 01:14:12 ERROR : dir/: Refusing unsafe name: unsafe path component ""
2026/10/21 01:14:12 ERROR : dir/: Refusing unsafe name: unsafe path component ""
2026/10/21 01:14:12 ERROR : dir: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/"."_in_"dir"
2026/10/21 01:14:12 ERROR : dir/: Refusing unsafe name: unsafe path component "."
2026/10/21 01:14:12 ERROR : dir/: Refusing unsafe name: unsafe path component "."
2026/10/21 01:14:12 ERROR : dir/: Refusing unsafe name: unsafe path component "."
2026/10/21 01:14:12 ERROR : dir: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/".."_in_"dir"
2026/10/21 01:14:12 ERROR : dir/: Refusing unsafe name: unsafe path component ".."
2026/10/21 01:14:12 ERROR : dir/: Refusing unsafe name: unsafe path component ".."
2026/10/21 01:14:12 ERROR : dir/: Refusing unsafe name: unsafe path component ".."
2026/10/21 01:14:12 ERROR : .: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/"sub/dir"_in_"dir"
2026/10/21 01:14:12 ERROR : dir/: Refusing unsafe name: path component "sub/dir" contains a "/"
2026/10/21 01:14:12 ERROR : dir/: Refusing unsafe name: path component "sub/dir" contains a "/"
2026/10/21 01:14:12 ERROR : dir/: Refusing unsafe name: path component "sub/dir" contains a "/"
2026/10/21 01:14:12 ERROR : dir/sub/dir: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/"../escape"_in_"dir"
2026/10/21 01:14:12 ERROR : dir/: Refusing unsafe name: path component "../escape" contains a "/"
2026/10/21 01:14:12 ERROR : dir/: Refusing unsafe name: path component "../escape" contains a "/"
2026/10/21 01:14:12 ERROR : dir/: Refusing unsafe name: path component "../escape" contains a "/"
2026/10/21 01:14:12 ERROR : escape: Dir.Rename error: file does not exist
=== RUN   TestDirUnsafeName/"escape/.."_in_"dir"
2026/10/21 01:14:12 ERROR : dir/: Refusing unsafe name: path component "escape/.." contains a "/"
2026/10/21 01:14:12 ERROR : dir/: Refusing unsafe name: path component "escape/.." contains a "/"
2026/10/21 01:14:12 ERROR : dir/: Refusing unsafe name: path component "escape/.." contains a "/"
2026/10/21 01:14:12 ERROR : dir: Dir.Rename error: file does not exist
2026/10/21 01:14:12 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:14:12 DEBUG : dir: Looking for writers
2026/10/21 01:14:12 DEBUG : file1: reading active writers
2026/10/21 01:14:12 DEBUG : Looking for writers
2026/10/21 01:14:12 DEBUG : dir: reading active writers
2026/10/21 01:14:12 DEBUG : >WaitForWriters: 
--- PASS: TestDirUnsafeName (1.23s)
    --- 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-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:14:12 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:14:13 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir" (type: 0)
2026/10/21 01:14:13 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/21 01:14:13 DEBUG : >changeNotify: 
2026/10/21 01:14:13 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/21 01:14:13 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/21 01:14:13 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/21 01:14:22 ERROR : dir/: Dir.Remove not empty
2026/10/21 01:14:22 DEBUG : dir/file1: Remove: 
2026/10/21 01:14:22 DEBUG : pcloud root 'rclone-test-bolucaq7suji': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/21 01:14:22 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/21 01:14:22 DEBUG : dir: invalidating directory cache
2026/10/21 01:14:22 DEBUG : >changeNotify: 
2026/10/21 01:14:22 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/10/21 01:14:22 DEBUG : dir/file1: >Remove: err=<nil>
2026/10/21 01:14:22 DEBUG : dir: Removed virtual directory entry vDel: "file1"
2026/10/21 01:14:22 ERROR : dir/: Dir.Remove not empty
    dir_test.go:536: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:536
        	Error:      	Received unexpected error:
        	            	Directory not empty
        	Test:       	TestDirRemove
2026/10/21 01:14:22 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:14:22 DEBUG : dir: Looking for writers
2026/10/21 01:14:22 DEBUG : file1: reading active writers
2026/10/21 01:14:22 DEBUG : Looking for writers
2026/10/21 01:14:22 DEBUG : dir: reading active writers
2026/10/21 01:14:22 DEBUG : >WaitForWriters: 
--- FAIL: TestDirRemove (9.63s)
=== RUN   TestDirRemoveVirtuals
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:14:22 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:16:22 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:16:22 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:16:22 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:16:23 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:16:24 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 1/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:18:30 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:18:30 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:18:30 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:18:31 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:18:32 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 2/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:20:37 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:20:37 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:20:37 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:20:38 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:20:40 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 3/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:22:45 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:22:45 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:22:45 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:22:46 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:22:47 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 4/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:22:58 DEBUG : dir: forgetting directory cache
2026/10/21 01:22:58 DEBUG : forgetting directory cache
2026/10/21 01:22:58 DEBUG : dir: forgetting directory cache
2026/10/21 01:23:00 DEBUG : forgetting directory cache
2026/10/21 01:23:00 DEBUG : dir: forgetting directory cache
2026/10/21 01:23:00 DEBUG : dir/subdir: forgetting directory cache
2026/10/21 01:23:18 DEBUG : forgetting directory cache
2026/10/21 01:23:18 DEBUG : dir: forgetting directory cache
2026/10/21 01:23:28 DEBUG : forgetting directory cache
2026/10/21 01:23:28 DEBUG : dir: forgetting directory cache
2026/10/21 01:23:29 DEBUG : forgetting directory cache
2026/10/21 01:23:29 DEBUG : dir: forgetting directory cache
2026/10/21 01:23:29 DEBUG : dir: forgetting directory cache
2026/10/21 01:23:40 DEBUG : forgetting directory cache
2026/10/21 01:23:40 DEBUG : dir: forgetting directory cache
2026/10/21 01:23:42 DEBUG : forgetting directory cache
2026/10/21 01:23:42 DEBUG : dir: forgetting directory cache
2026/10/21 01:23:42 DEBUG : dir: forgetting directory cache
2026/10/21 01:23:42 DEBUG : fil: forgetting directory cache
2026/10/21 01:23:42 DEBUG : fil/a: forgetting directory cache
2026/10/21 01:23:42 DEBUG : fil/a/b: forgetting directory cache
2026/10/21 01:23:51 DEBUG : forgetting directory cache
2026/10/21 01:23:51 DEBUG : dir: forgetting directory cache
2026/10/21 01:23:51 DEBUG : dir: forgetting directory cache
2026/10/21 01:23:52 DEBUG : forgetting directory cache
2026/10/21 01:23:52 DEBUG : dir: forgetting directory cache
2026/10/21 01:24:03 DEBUG : dir/subdir: forgetting directory cache
2026/10/21 01:24:04 DEBUG : dir/virtualDir2: forgetting directory cache
2026/10/21 01:24:04 DEBUG : forgetting directory cache
2026/10/21 01:24:04 DEBUG : dir: forgetting directory cache
2026/10/21 01:24:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/21 01:24:05 DEBUG : forgetting directory cache
2026/10/21 01:24:05 DEBUG : dir: forgetting directory cache
2026/10/21 01:24:05 DEBUG : dir: forgetting directory cache
2026/10/21 01:24:06 DEBUG : forgetting directory cache
2026/10/21 01:24:06 DEBUG : dir: forgetting directory cache
2026/10/21 01:24:06 DEBUG : dir: Removed virtual directory entry vAddFile: "potato"
2026/10/21 01:24:08 DEBUG : forgetting directory cache
2026/10/21 01:24:08 DEBUG : dir: forgetting directory cache
2026/10/21 01:24:08 DEBUG : dir/sub: forgetting directory cache
2026/10/21 01:24:08 DEBUG : dir: Removed virtual directory entry vAddDir: "sub"
2026/10/21 01:24:10 DEBUG : forgetting directory cache
2026/10/21 01:24:10 DEBUG : dir: forgetting directory cache
2026/10/21 01:24:10 DEBUG : dir/sub: forgetting directory cache
2026/10/21 01:24:10 DEBUG : dir/sub/subsub: forgetting directory cache
2026/10/21 01:24:12 DEBUG : forgetting directory cache
2026/10/21 01:24:12 DEBUG : dir: forgetting directory cache
2026/10/21 01:24:21 DEBUG : forgetting directory cache
2026/10/21 01:24:21 DEBUG : dir: forgetting directory cache
2026/10/21 01:24:22 DEBUG : forgetting directory cache
2026/10/21 01:24:52 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:24:52 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:24:52 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:24:54 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:24:55 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 5/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:27:00 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:27:00 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:27:00 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:27:01 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:27:02 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 6/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:29:08 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:29:08 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:29:08 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:29:09 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:29:10 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 7/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:31:15 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:31:15 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:31:15 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:31:16 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:31:17 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 8/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:33:23 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:33:23 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:33:23 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:33:24 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:33:25 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 9/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:34:04 DEBUG : dir: forgetting directory cache
2026/10/21 01:34:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/21 01:34:04 DEBUG : forgetting directory cache
2026/10/21 01:34:04 DEBUG : dir: forgetting directory cache
2026/10/21 01:34:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/21 01:35:30 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:35:30 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:35:30 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:35:31 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:35:33 DEBUG : pacer: Reducing sleep to 10ms
    run.go:303: Failed to put "dir/file1" to "pcloud root 'rclone-test-bolucaq7suji'": Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF
2026/10/21 01:35:36 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:35:36 DEBUG : Looking for writers
2026/10/21 01:35:36 DEBUG : >WaitForWriters: 
--- FAIL: TestDirRemoveVirtuals (1273.86s)
=== RUN   TestDirRemoveAll
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:35:36 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:37:36 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:37:36 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:37:36 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:37:37 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:37:38 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 1/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:39:44 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:39:44 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:39:44 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:39:45 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:39:46 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 2/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:41:51 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:41:51 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:41:51 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:41:52 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:41:53 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 3/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:43:59 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:43:59 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:43:59 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:44:00 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:44:01 DEBUG : pacer: Reducing sleep to 10ms
2026/10/21 01:44:04 DEBUG : forgetting directory cache
2026/10/21 01:44:04 DEBUG : dir: forgetting directory cache
2026/10/21 01:44:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/21 01:44:04 DEBUG : dir: forgetting directory cache
2026/10/21 01:44:04 DEBUG : dir/virtualDir: forgetting directory cache
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 4/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:45:36 DEBUG : forgetting directory cache
2026/10/21 01:46:06 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:46:06 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:46:06 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:46:07 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:46:09 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 5/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:48:14 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:48:14 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:48:14 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:48:15 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:48:16 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 6/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:50:21 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:50:21 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:50:21 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:50:23 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:50:24 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 7/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:52:29 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:52:29 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:52:29 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:52:30 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:52:31 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 8/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:54:04 DEBUG : forgetting directory cache
2026/10/21 01:54:04 DEBUG : dir: forgetting directory cache
2026/10/21 01:54:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/21 01:54:04 DEBUG : dir: forgetting directory cache
2026/10/21 01:54:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/21 01:54:37 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:54:37 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:54:37 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:54:38 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:54:39 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 9/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:56:44 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:56:44 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:56:44 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:56:45 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:56:46 DEBUG : pacer: Reducing sleep to 10ms
    run.go:303: Failed to put "dir/file1" to "pcloud root 'rclone-test-bolucaq7suji'": Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF
2026/10/21 01:56:50 DEBUG : WaitForWriters: timeout=30s
2026/10/21 01:56:50 DEBUG : Looking for writers
2026/10/21 01:56:50 DEBUG : >WaitForWriters: 
--- FAIL: TestDirRemoveAll (1273.82s)
=== RUN   TestDirRemoveName
    run.go:198: Remote "pcloud root 'rclone-test-bolucaq7suji'", Local "Local file system at /tmp/rclone341005904", Modify Window "1s"
2026/10/21 01:56:50 NOTICE: pcloud root 'rclone-test-bolucaq7suji': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/21 01:58:50 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 01:58:50 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 01:58:50 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 01:58:51 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 01:58:52 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 1/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 02:00:57 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 02:00:57 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 02:00:57 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 02:00:59 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 02:01:00 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 2/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 02:03:05 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 02:03:05 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 02:03:05 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 02:03:06 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 02:03:07 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 3/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 02:04:04 DEBUG : dir: forgetting directory cache
2026/10/21 02:04:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/21 02:04:04 DEBUG : forgetting directory cache
2026/10/21 02:04:04 DEBUG : dir: forgetting directory cache
2026/10/21 02:04:04 DEBUG : dir/virtualDir: forgetting directory cache
2026/10/21 02:05:13 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 02:05:13 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 02:05:13 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 02:05:14 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 02:05:15 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 4/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 02:06:50 DEBUG : forgetting directory cache
2026/10/21 02:07:20 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 02:07:20 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 02:07:20 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 02:07:21 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 02:07:22 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 5/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 02:09:28 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 02:09:28 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 02:09:28 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 02:09:29 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 02:09:30 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 6/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 02:11:35 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
2026/10/21 02:11:35 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/21 02:11:35 DEBUG : pacer: Reducing sleep to 15ms
2026/10/21 02:11:36 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/21 02:11:37 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-bolucaq7suji': 7/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=27212743799&mtime=981173106&nopartial=1": EOF)
panic: test timed out after 1h0m0s
	running tests:
		TestDirRemoveName (16m6s)

goroutine 32138 [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, 16 minutes]:
testing.(*T).Run(0x347d44c4fb08, {0x25f56a9?, 0x347d4484ba58?}, 0x4aca178)
	/usr/local/go/src/testing/testing.go:2266 +0x4f2
testing.runTests.func1(0x347d44c4fb08)
	/usr/local/go/src/testing/testing.go:2742 +0x37
testing.tRunner(0x347d44c4fb08, 0x347d4484bb80)
	/usr/local/go/src/testing/testing.go:2193 +0xea
testing.runTests({0x2612096, 0x18}, {0x2623b8e, 0x1c}, 0x347d44fe87b0, {0x4da55c0, 0x6d, 0x6d}, {0xc2ae25ca1b2b4fa4, 0x3467146f8cf, ...})
	/usr/local/go/src/testing/testing.go:2740 +0x510
testing.(*M).Run(0x347d4513b360)
	/usr/local/go/src/testing/testing.go:2600 +0x6af
github.com/rclone/rclone/fstest.TestMain(0x347d4513b360)
	/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:266 +0xa6

goroutine 52 [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 53 [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 10 [select, 60 minutes]:
github.com/rclone/rclone/lib/oauthutil.(*Renew).renewOnExpiry(0x347d4493aa00)
	/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 19907 [select, 1 minutes]:
net/http.(*persistConn).roundTrip(0x347d44d06140, 0x347d4549aa50)
	/usr/local/go/src/net/http/transport.go:3069 +0x84b
net/http.(*Transport).roundTrip(0x347d44c22540, 0x347d44b5bb80)
	/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(0x347d44bdc180, 0x347d44b5bb80)
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:709 +0x657
golang.org/x/oauth2.(*Transport).RoundTrip(0x347d4514ab80, 0x347d44b5ba40)
	/home/rclone/go/pkg/mod/golang.org/x/oauth2@v0.37.0/transport.go:55 +0x15b
net/http.send(0x347d44b5ba40, {0x4a8adc8, 0x347d4514ab80}, {0x347d45034df8?, 0x497406?, 0x0?})
	/usr/local/go/src/net/http/client.go:266 +0x654
net/http.(*Client).send(0x347d451439e0, 0x347d44b5ba40, {0x27995c0?, 0x1?, 0x0?})
	/usr/local/go/src/net/http/client.go:187 +0x250
net/http.(*Client).do(0x347d451439e0, 0x347d44b5ba40)
	/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(0x347d44c0e000, {0x4aaf240, 0x4de98e0}, 0x347d453cbce0)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:511 +0xe85
github.com/rclone/rclone/lib/rest.(*Client).callCodec(0x347d44c0e000, {0x4aaf240, 0x4de98e0}, 0x450347?, {0x0?, 0x0?}, {0x423dd88, 0x347d4517f2c0}, 0x41ea85?, 0x4acbdf8, ...)
	/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, 0x100000000000009?)
	/home/rclone/go/src/github.com/rclone/rclone/fs/pacer.go:86 +0x32
github.com/rclone/rclone/lib/pacer.(*Pacer).call(0x347d44898600, 0x347d44d4e000, 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(0x347d455d1830, {0x4aaf240, 0x4de98e0}, {0x4a87268, 0x347d44e331d0}, {0x4ab8948, 0x347d44e63490}, {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(0x347d4497a000, {0x4aaf240, 0x4de98e0}, {0x4a87268, 0x347d44e331d0}, {0x4ab8948, 0x347d44e63490}, {0x0, 0x0, 0x0})
	/home/rclone/go/src/github.com/rclone/rclone/backend/pcloud/pcloud.go:781 +0x14c
github.com/rclone/rclone/fstest.(*Run).WriteObjectTo(0x347d44c6a460, {0x4aaf240, 0x4de98e0}, {0x4abee18, 0x347d4497a000}, {0x25db2b7, 0x9}, {0x25eb0fd, 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(0x347d44c4fd48)
	/home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:28 +0xb2
github.com/rclone/rclone/vfs.TestDirRemoveName(0x347d44c4fd48)
	/home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:596 +0x27
testing.tRunner(0x347d44c4fd48, 0x4aca178)
	/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 31072 [select, 1 minutes]:
net/http.(*persistConn).writeLoop(0x347d44d06140)
	/usr/local/go/src/net/http/transport.go:2810 +0xe6
created by net/http.(*Transport).dialConn in goroutine 31166
	/usr/local/go/src/net/http/transport.go:2124 +0x1e05

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

goroutine 19908 [select]:
net/http.(*persistConn).roundTrip(0x347d44940280, 0x347d45400f50)
	/usr/local/go/src/net/http/transport.go:3069 +0x84b
net/http.(*Transport).roundTrip(0x347d44c22540, 0x347d4539bcc0)
	/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(0x347d44bdc180, 0x347d4539bcc0)
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:709 +0x657
golang.org/x/oauth2.(*Transport).RoundTrip(0x347d4514ab80, 0x347d4539bb80)
	/home/rclone/go/pkg/mod/golang.org/x/oauth2@v0.37.0/transport.go:55 +0x15b
net/http.send(0x347d4539bb80, {0x4a8adc8, 0x347d4514ab80}, {0x347d45039198?, 0x497406?, 0x0?})
	/usr/local/go/src/net/http/client.go:266 +0x654
net/http.(*Client).send(0x347d451439e0, 0x347d4539bb80, {0x27995c0?, 0x1?, 0x0?})
	/usr/local/go/src/net/http/client.go:187 +0x250
net/http.(*Client).do(0x347d451439e0, 0x347d4539bb80)
	/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(0x347d44c0e000, {0x4aaf390, 0x347d44c0bab0}, 0x347d45039b40)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:511 +0xe85
github.com/rclone/rclone/lib/rest.(*Client).callCodec(0x347d44c0e000, {0x4aaf390, 0x347d44c0bab0}, 0x74008884d030?, {0x0?, 0x0?}, {0x4237ea8, 0x347d45630fc0}, 0x437bf60?, 0x4acbdf8, ...)
	/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(0x347d4497a000, {0x4aaf320, 0x347d4497ed20}, 0x347d44f7c100, 0x347d4489a770)
	/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 19907
	/home/rclone/go/src/github.com/rclone/rclone/backend/pcloud/pcloud.go:1114 +0xb4

goroutine 31071 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x74008884d400, 0x72)
	/usr/local/go/src/runtime/netpoll.go:351 +0x85
internal/poll.(*pollDesc).wait(0x347d45571080?, 0x347d45354000?, 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(0x347d45571080, {0x347d45354000, 0x1980, 0x1980})
	/usr/local/go/src/internal/poll/fd_unix.go:170 +0x2a8
net.(*netFD).Read(0x347d45571080, {0x347d45354000?, 0x347d45354005?, 0x347d44902608?})
	/usr/local/go/src/net/fd_posix.go:68 +0x25
net.(*conn).Read(0x347d44902608, {0x347d45354000?, 0x0?, 0x1700347d451b3a10?})
	/usr/local/go/src/net/net.go:196 +0x45
github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0x347d44c05290, {0x347d45354000?, 0x740088801ae8?, 0x7400889c12f8?})
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29
crypto/tls.(*Conn).readFromUntil(0x347d44c4b808, {0x7400403f9838, 0x347d44c05290}, 0x347d44922739?)
	/usr/local/go/src/crypto/tls/conn.go:820 +0xf4
crypto/tls.(*Conn).readRecordOrCCS(0x347d44c4b808, 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(0x347d44c4b808, {0x347d45071000, 0x1000, 0x70?})
	/usr/local/go/src/crypto/tls/conn.go:1392 +0x148
net/http.(*persistConn).Read(0x347d44d06140, {0x347d45071000?, 0x70?, 0x0?})
	/usr/local/go/src/net/http/transport.go:2300 +0x47
bufio.(*Reader).fill(0x347d4506e660)
	/usr/local/go/src/bufio/bufio.go:113 +0x103
bufio.(*Reader).Peek(0x347d4506e660, 0x1)
	/usr/local/go/src/bufio/bufio.go:152 +0x52
net/http.(*persistConn).readLoop(0x347d44d06140)
	/usr/local/go/src/net/http/transport.go:2483 +0x172
created by net/http.(*Transport).dialConn in goroutine 31166
	/usr/local/go/src/net/http/transport.go:2123 +0x1da5

goroutine 32173 [IO wait]:
internal/poll.runtime_pollWait(0x74008884ce00, 0x72)
	/usr/local/go/src/runtime/netpoll.go:351 +0x85
internal/poll.(*pollDesc).wait(0x347d4491c180?, 0x347d452ef980?, 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(0x347d4491c180, {0x347d452ef980, 0x1980, 0x1980})
	/usr/local/go/src/internal/poll/fd_unix.go:170 +0x2a8
net.(*netFD).Read(0x347d4491c180, {0x347d452ef980?, 0x347d452ef985?, 0x347d44d4a4b8?})
	/usr/local/go/src/net/fd_posix.go:68 +0x25
net.(*conn).Read(0x347d44d4a4b8, {0x347d452ef980?, 0x347d44876a18?, 0x1700347d44876a10?})
	/usr/local/go/src/net/net.go:196 +0x45
github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0x347d44c04348, {0x347d452ef980?, 0x7400404cec28?, 0x7400889c12f8?})
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29
crypto/tls.(*Conn).readFromUntil(0x347d44d37c08, {0x7400403f9838, 0x347d44c04348}, 0x347d455417f9?)
	/usr/local/go/src/crypto/tls/conn.go:820 +0xf4
crypto/tls.(*Conn).readRecordOrCCS(0x347d44d37c08, 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(0x347d44d37c08, {0x347d45340000, 0x1000, 0x70?})
	/usr/local/go/src/crypto/tls/conn.go:1392 +0x148
net/http.(*persistConn).Read(0x347d44940280, {0x347d45340000?, 0x70?, 0x0?})
	/usr/local/go/src/net/http/transport.go:2300 +0x47
bufio.(*Reader).fill(0x347d453bf8c0)
	/usr/local/go/src/bufio/bufio.go:113 +0x103
bufio.(*Reader).Peek(0x347d453bf8c0, 0x1)
	/usr/local/go/src/bufio/bufio.go:152 +0x52
net/http.(*persistConn).readLoop(0x347d44940280)
	/usr/local/go/src/net/http/transport.go:2483 +0x172
created by net/http.(*Transport).dialConn in goroutine 32151
	/usr/local/go/src/net/http/transport.go:2123 +0x1da5

goroutine 20118 [select, 16 minutes]:
github.com/rclone/rclone/vfs.(*VFS).signalHandler(0x347d44f7e420, {0x4aaf320, 0x347d4497ed20})
	/home/rclone/go/src/github.com/rclone/rclone/vfs/vfs.go:307 +0xc5
created by github.com/rclone/rclone/vfs.New in goroutine 19907
	/home/rclone/go/src/github.com/rclone/rclone/vfs/vfs.go:282 +0x8fc
"./vfs.test -test.v -test.timeout 1h0m0s -remote TestPcloud: -verbose" - Finished ERROR in 1h0m1.101054873s (try 1/5): exit status 2: Failed [TestDirRemove TestDirRemoveVirtuals TestDirRemoveAll]