"./vfs.test -test.v -test.timeout 1h0m0s -remote TestPcloud: -verbose" - Starting (try 1/5)
2026/10/02 02:43:53 DEBUG : Creating backend with remote "TestPcloud:rclone-test-pupuvul9liqa"
2026/10/02 02:43:53 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/10/02 02:43:54 DEBUG : Creating backend with remote "/tmp/rclone3309407505"
=== RUN   TestDirHandleMethods
    run.go:198: Remote "pcloud root 'rclone-test-pupuvul9liqa'", Local "Local file system at /tmp/rclone3309407505", Modify Window "1s"
2026/10/02 02:43:54 NOTICE: pcloud root 'rclone-test-pupuvul9liqa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/02 02:43:55 DEBUG : pcloud root 'rclone-test-pupuvul9liqa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/02 02:43:55 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/02 02:43:55 DEBUG : >changeNotify: 
2026/10/02 02:43:55 DEBUG : pcloud root 'rclone-test-pupuvul9liqa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/02 02:43:55 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/02 02:43:55 DEBUG : >changeNotify: 
2026/10/02 02:43:55 DEBUG : WaitForWriters: timeout=30s
2026/10/02 02:43:55 DEBUG : dir: Looking for writers
2026/10/02 02:43:55 DEBUG : Looking for writers
2026/10/02 02:43:55 DEBUG : dir: reading active writers
2026/10/02 02:43:55 DEBUG : >WaitForWriters: 
--- PASS: TestDirHandleMethods (1.44s)
=== RUN   TestDirHandleReaddir
    run.go:198: Remote "pcloud root 'rclone-test-pupuvul9liqa'", Local "Local file system at /tmp/rclone3309407505", Modify Window "1s"
2026/10/02 02:43:55 NOTICE: pcloud root 'rclone-test-pupuvul9liqa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/02 02:43:56 DEBUG : pcloud root 'rclone-test-pupuvul9liqa': ChangeNotify: detected change in "dir" (type: 0)
2026/10/02 02:43:56 DEBUG : changeNotify: relativePath="dir", type=0
2026/10/02 02:43:56 DEBUG : >changeNotify: 
2026/10/02 02:43:56 DEBUG : pcloud root 'rclone-test-pupuvul9liqa': ChangeNotify: detected change in "dir/file1" (type: 1)
2026/10/02 02:43:56 DEBUG : changeNotify: relativePath="dir/file1", type=1
2026/10/02 02:43:56 DEBUG : >changeNotify: 
2026/10/02 02:43:56 DEBUG : pcloud root 'rclone-test-pupuvul9liqa': ChangeNotify: detected change in "dir/file2" (type: 1)
2026/10/02 02:43:56 DEBUG : changeNotify: relativePath="dir/file2", type=1
2026/10/02 02:43:56 DEBUG : >changeNotify: 
2026/10/02 02:43:56 DEBUG : pcloud root 'rclone-test-pupuvul9liqa': ChangeNotify: detected change in "dir/subdir" (type: 0)
2026/10/02 02:43:56 DEBUG : changeNotify: relativePath="dir/subdir", type=0
2026/10/02 02:43:56 DEBUG : >changeNotify: 
2026/10/02 02:43:56 DEBUG : pcloud root 'rclone-test-pupuvul9liqa': ChangeNotify: detected change in "dir/subdir/file3" (type: 1)
2026/10/02 02:43:56 DEBUG : changeNotify: relativePath="dir/subdir/file3", type=1
2026/10/02 02:43:56 DEBUG : >changeNotify: 
2026/10/02 02:43:57 DEBUG : WaitForWriters: timeout=30s
2026/10/02 02:43:57 DEBUG : dir/subdir: Looking for writers
2026/10/02 02:43:57 DEBUG : dir: Looking for writers
2026/10/02 02:43:57 DEBUG : file2: reading active writers
2026/10/02 02:43:57 DEBUG : subdir: reading active writers
2026/10/02 02:43:57 DEBUG : file1: reading active writers
2026/10/02 02:43:57 DEBUG : Looking for writers
2026/10/02 02:43:57 DEBUG : dir: reading active writers
2026/10/02 02:43:57 DEBUG : >WaitForWriters: 
--- PASS: TestDirHandleReaddir (1.91s)
=== RUN   TestDirHandleReaddirnames
    run.go:198: Remote "pcloud root 'rclone-test-pupuvul9liqa'", Local "Local file system at /tmp/rclone3309407505", Modify Window "1s"
2026/10/02 02:43:57 NOTICE: pcloud root 'rclone-test-pupuvul9liqa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/02 02:45:58 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 02:45:58 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 02:45:58 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 02:45:59 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 02:46:00 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 1/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 02:48:06 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 02:48:06 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 02:48:06 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 02:48:07 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 02:48:08 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 2/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 02:50:14 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 02:50:14 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 02:50:14 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 02:50:15 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 02:50:16 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 3/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 02:52:21 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 02:52:21 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 02:52:21 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 02:52:22 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 02:52:23 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 4/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 02:53:55 DEBUG : dir: forgetting directory cache
2026/10/02 02:53:55 DEBUG : forgetting directory cache
2026/10/02 02:53:55 DEBUG : dir: forgetting directory cache
2026/10/02 02:53:57 DEBUG : forgetting directory cache
2026/10/02 02:53:57 DEBUG : dir: forgetting directory cache
2026/10/02 02:53:57 DEBUG : dir/subdir: forgetting directory cache
2026/10/02 02:53:57 DEBUG : forgetting directory cache
2026/10/02 02:54:29 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 02:54:29 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 02:54:29 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 02:54:30 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 02:54:31 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 5/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 02:56:36 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 02:56:36 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 02:56:36 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 02:56:37 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 02:56:39 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 6/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 02:58:44 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 02:58:44 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 02:58:44 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 02:58:45 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 02:58:46 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 7/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:00:51 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:00:51 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:00:52 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:00:53 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:00:54 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 8/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:02:59 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:02:59 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:02:59 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:03:00 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:03:01 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 9/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:05:07 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:05:07 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:05:07 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:05:08 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:05:09 DEBUG : pacer: Reducing sleep to 10ms
    run.go:303: Failed to put "dir/file1" to "pcloud root 'rclone-test-pupuvul9liqa'": Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF
2026/10/02 03:05:12 DEBUG : WaitForWriters: timeout=30s
2026/10/02 03:05:12 DEBUG : Looking for writers
2026/10/02 03:05:12 DEBUG : >WaitForWriters: 
--- FAIL: TestDirHandleReaddirnames (1274.87s)
=== RUN   TestDirMethods
    run.go:198: Remote "pcloud root 'rclone-test-pupuvul9liqa'", Local "Local file system at /tmp/rclone3309407505", Modify Window "1s"
2026/10/02 03:05:12 NOTICE: pcloud root 'rclone-test-pupuvul9liqa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/02 03:07:12 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:07:12 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:07:12 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:07:13 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:07:15 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 1/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:09:20 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:09:20 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:09:20 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:09:21 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:09:22 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 2/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:11:27 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:11:27 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:11:27 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:11:29 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:11:30 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 3/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:13:35 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:13:35 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:13:35 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:13:36 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:13:37 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 4/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:15:12 DEBUG : forgetting directory cache
2026/10/02 03:15:43 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:15:43 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:15:43 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:15:44 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:15:45 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 5/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:17:50 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:17:50 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:17:50 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:17:51 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:17:52 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 6/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:19:58 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:19:58 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:19:58 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:19:59 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:20:00 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 7/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:22:05 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:22:05 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:22:05 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:22:07 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:22:08 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 8/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:24:13 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:24:13 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:24:13 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:24:14 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:24:15 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 9/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:26:20 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:26:20 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:26:21 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:26:22 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:26:23 DEBUG : pacer: Reducing sleep to 10ms
    run.go:303: Failed to put "dir/file1" to "pcloud root 'rclone-test-pupuvul9liqa'": Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF
2026/10/02 03:26:26 DEBUG : WaitForWriters: timeout=30s
2026/10/02 03:26:26 DEBUG : Looking for writers
2026/10/02 03:26:26 DEBUG : >WaitForWriters: 
--- FAIL: TestDirMethods (1273.98s)
=== RUN   TestDirForgetAll
    run.go:198: Remote "pcloud root 'rclone-test-pupuvul9liqa'", Local "Local file system at /tmp/rclone3309407505", Modify Window "1s"
2026/10/02 03:26:26 NOTICE: pcloud root 'rclone-test-pupuvul9liqa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/10/02 03:28:26 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:28:26 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:28:26 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:28:27 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:28:29 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 1/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:30:34 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:30:34 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:30:34 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:30:35 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:30:36 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 2/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:32:41 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:32:41 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:32:41 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:32:43 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:32:44 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 3/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:34:49 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:34:49 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:34:49 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:34:50 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:34:51 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 4/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:36:26 DEBUG : forgetting directory cache
2026/10/02 03:36:57 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:36:57 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:36:57 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:36:58 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:36:59 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 5/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:39:04 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:39:04 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:39:04 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:39:05 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:39:06 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 6/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:41:12 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:41:12 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:41:12 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:41:13 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:41:14 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 7/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:43:19 DEBUG : pacer: low level retry 1/1 (error Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
2026/10/02 03:43:19 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/10/02 03:43:19 DEBUG : pacer: Reducing sleep to 15ms
2026/10/02 03:43:20 DEBUG : pacer: Reducing sleep to 11.25ms
2026/10/02 03:43:22 DEBUG : pacer: Reducing sleep to 10ms
    run.go:299: Retry Put of "dir/file1" to pcloud root 'rclone-test-pupuvul9liqa': 8/10 (Put "https://eapi.pcloud.com/uploadfile?filename=file1&folderid=26870580600&mtime=981173106&nopartial=1": EOF)
panic: test timed out after 1h0m0s
	running tests:
		TestDirForgetAll (17m28s)

goroutine 2078 [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, 17 minutes]:
testing.(*T).Run(0x3ce061648b48, {0x251549b?, 0x3ce061001a58?}, 0x49339f0)
	/usr/local/go/src/testing/testing.go:2266 +0x4f2
testing.runTests.func1(0x3ce061648b48)
	/usr/local/go/src/testing/testing.go:2742 +0x37
testing.tRunner(0x3ce061648b48, 0x3ce061001b80)
	/usr/local/go/src/testing/testing.go:2193 +0xea
testing.runTests({0x25351ca, 0x18}, {0x25468b8, 0x1c}, 0x3ce061455bd8, {0x4c0da60, 0x66, 0x66}, {0xc2a7e7fe9bccb0ca, 0x3465de03222, ...})
	/usr/local/go/src/testing/testing.go:2740 +0x510
testing.(*M).Run(0x3ce0618acfa0)
	/usr/local/go/src/testing/testing.go:2600 +0x6af
github.com/rclone/rclone/fstest.TestMain(0x3ce0618acfa0)
	/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:252 +0xa6

goroutine 53 [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 54 [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 55 [select, 60 minutes]:
github.com/rclone/rclone/lib/oauthutil.(*Renew).renewOnExpiry(0x3ce061579300)
	/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 2092 [IO wait]:
internal/poll.runtime_pollWait(0x784782638000, 0x72)
	/usr/local/go/src/runtime/netpoll.go:351 +0x85
internal/poll.(*pollDesc).wait(0x3ce061b38e80?, 0x3ce061991980?, 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(0x3ce061b38e80, {0x3ce061991980, 0x1980, 0x1980})
	/usr/local/go/src/internal/poll/fd_unix.go:170 +0x2a8
net.(*netFD).Read(0x3ce061b38e80, {0x3ce061991980?, 0x3ce0619919d4?, 0x3ce060f96160?})
	/usr/local/go/src/net/fd_posix.go:68 +0x25
net.(*conn).Read(0x3ce060f96160, {0x3ce061991980?, 0x3ce061c35a18?, 0x17003ce061c35a10?})
	/usr/local/go/src/net/net.go:196 +0x45
github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0x3ce061a8c1f8, {0x3ce061991980?, 0x7847390541e0?, 0x7847826fbbf0?})
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29
crypto/tls.(*Conn).readFromUntil(0x3ce061690008, {0x784738610040, 0x3ce061a8c1f8}, 0x3ce061819a39?)
	/usr/local/go/src/crypto/tls/conn.go:820 +0xf4
crypto/tls.(*Conn).readRecordOrCCS(0x3ce061690008, 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(0x3ce061690008, {0x3ce0619de000, 0x1000, 0x70?})
	/usr/local/go/src/crypto/tls/conn.go:1392 +0x148
net/http.(*persistConn).Read(0x3ce0617677c0, {0x3ce0619de000?, 0x70?, 0x0?})
	/usr/local/go/src/net/http/transport.go:2300 +0x47
bufio.(*Reader).fill(0x3ce0619d8240)
	/usr/local/go/src/bufio/bufio.go:113 +0x103
bufio.(*Reader).Peek(0x3ce0619d8240, 0x1)
	/usr/local/go/src/bufio/bufio.go:152 +0x52
net/http.(*persistConn).readLoop(0x3ce0617677c0)
	/usr/local/go/src/net/http/transport.go:2483 +0x172
created by net/http.(*Transport).dialConn in goroutine 2117
	/usr/local/go/src/net/http/transport.go:2123 +0x1da5

goroutine 1626 [select]:
net/http.(*persistConn).roundTrip(0x3ce0617677c0, 0x3ce061456af0)
	/usr/local/go/src/net/http/transport.go:3069 +0x84b
net/http.(*Transport).roundTrip(0x3ce0615ca380, 0x3ce061767540)
	/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(0x3ce061108540, 0x3ce061767540)
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:700 +0x63b
golang.org/x/oauth2.(*Transport).RoundTrip(0x3ce0617951c0, 0x3ce061767400)
	/home/rclone/go/pkg/mod/golang.org/x/oauth2@v0.36.0/transport.go:55 +0x15b
net/http.send(0x3ce061767400, {0x48f4fb0, 0x3ce0617951c0}, {0x3ce0617f4e18?, 0x497406?, 0x0?})
	/usr/local/go/src/net/http/client.go:266 +0x654
net/http.(*Client).send(0x3ce061789c80, 0x3ce061767400, {0x26b3bf8?, 0x1?, 0x0?})
	/usr/local/go/src/net/http/client.go:187 +0x250
net/http.(*Client).do(0x3ce061789c80, 0x3ce061767400)
	/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(0x3ce06161c190, {0x4919228, 0x4c51b60}, 0x3ce061750580)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:457 +0xe85
github.com/rclone/rclone/lib/rest.(*Client).callCodec(0x3ce06161c190, {0x4919228, 0x4c51b60}, 0x3ce0619245a0?, {0x0?, 0x0?}, {0x40c95b0, 0x3ce06141d0e0}, 0x44e0b60?, 0x4935688, ...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:703 +0x4e8
github.com/rclone/rclone/lib/rest.(*Client).CallJSON(...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:640
github.com/rclone/rclone/backend/pcloud.(*Object).Update.func1()
	/home/rclone/go/src/github.com/rclone/rclone/backend/pcloud/pcloud.go:1534 +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(0x3ce061108600, 0x3ce06144d680, 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(0x3ce061754fc0, {0x4919228, 0x4c51b60}, {0x48f12b0, 0x3ce061529260}, {0x49227b0, 0x3ce061681420}, {0x0, 0x0, 0x0})
	/home/rclone/go/src/github.com/rclone/rclone/backend/pcloud/pcloud.go:1533 +0xbf0
github.com/rclone/rclone/backend/pcloud.(*Fs).Put(0x3ce061103ce0, {0x4919228, 0x4c51b60}, {0x48f12b0, 0x3ce061529260}, {0x49227b0, 0x3ce061681420}, {0x0, 0x0, 0x0})
	/home/rclone/go/src/github.com/rclone/rclone/backend/pcloud/pcloud.go:764 +0x14c
github.com/rclone/rclone/fstest.(*Run).WriteObjectTo(0x3ce06142ebd0, {0x4919228, 0x4c51b60}, {0x4928ae8, 0x3ce061103ce0}, {0x24ff0d9, 0x9}, {0x250eb78, 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(0x3ce061171448)
	/home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:26 +0xb2
github.com/rclone/rclone/vfs.TestDirForgetAll(0x3ce061171448)
	/home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:88 +0x3f
testing.tRunner(0x3ce061171448, 0x49339f0)
	/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 2068 [select, 2 minutes]:
net/http.(*persistConn).writeLoop(0x3ce06162c780)
	/usr/local/go/src/net/http/transport.go:2810 +0xe6
created by net/http.(*Transport).dialConn in goroutine 2030
	/usr/local/go/src/net/http/transport.go:2124 +0x1e05

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

goroutine 1632 [select, 17 minutes]:
github.com/rclone/rclone/vfs.(*VFS).signalHandler(0x3ce061a1a000, {0x4919308, 0x3ce061a6f310})
	/home/rclone/go/src/github.com/rclone/rclone/vfs/vfs.go:307 +0xc5
created by github.com/rclone/rclone/vfs.New in goroutine 1626
	/home/rclone/go/src/github.com/rclone/rclone/vfs/vfs.go:282 +0x8a8

goroutine 2067 [IO wait, 2 minutes]:
internal/poll.runtime_pollWait(0x784782638400, 0x72)
	/usr/local/go/src/runtime/netpoll.go:351 +0x85
internal/poll.(*pollDesc).wait(0x3ce061625e00?, 0x3ce061920c80?, 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(0x3ce061625e00, {0x3ce061920c80, 0x1980, 0x1980})
	/usr/local/go/src/internal/poll/fd_unix.go:170 +0x2a8
net.(*netFD).Read(0x3ce061625e00, {0x3ce061920c80?, 0x3ce061920c85?, 0x3ce060f966c8?})
	/usr/local/go/src/net/fd_posix.go:68 +0x25
net.(*conn).Read(0x3ce060f966c8, {0x3ce061920c80?, 0x3ce0619c5a18?, 0x17003ce0619c5a10?})
	/usr/local/go/src/net/net.go:196 +0x45
github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0x3ce061a8c660, {0x3ce061920c80?, 0x7847390541e0?, 0x7847826fb2f8?})
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29
crypto/tls.(*Conn).readFromUntil(0x3ce061690408, {0x784738610040, 0x3ce061a8c660}, 0x3ce061818af9?)
	/usr/local/go/src/crypto/tls/conn.go:820 +0xf4
crypto/tls.(*Conn).readRecordOrCCS(0x3ce061690408, 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(0x3ce061690408, {0x3ce061b40000, 0x1000, 0x70?})
	/usr/local/go/src/crypto/tls/conn.go:1392 +0x148
net/http.(*persistConn).Read(0x3ce06162c780, {0x3ce061b40000?, 0x70?, 0x0?})
	/usr/local/go/src/net/http/transport.go:2300 +0x47
bufio.(*Reader).fill(0x3ce06197e8a0)
	/usr/local/go/src/bufio/bufio.go:113 +0x103
bufio.(*Reader).Peek(0x3ce06197e8a0, 0x1)
	/usr/local/go/src/bufio/bufio.go:152 +0x52
net/http.(*persistConn).readLoop(0x3ce06162c780)
	/usr/local/go/src/net/http/transport.go:2483 +0x172
created by net/http.(*Transport).dialConn in goroutine 2030
	/usr/local/go/src/net/http/transport.go:2123 +0x1da5

goroutine 1627 [select, 2 minutes]:
net/http.(*persistConn).roundTrip(0x3ce06162c780, 0x3ce06161cfa0)
	/usr/local/go/src/net/http/transport.go:3069 +0x84b
net/http.(*Transport).roundTrip(0x3ce0615ca380, 0x3ce06162c640)
	/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(0x3ce061108540, 0x3ce06162c640)
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:700 +0x63b
golang.org/x/oauth2.(*Transport).RoundTrip(0x3ce0617951c0, 0x3ce06162c500)
	/home/rclone/go/pkg/mod/golang.org/x/oauth2@v0.36.0/transport.go:55 +0x15b
net/http.send(0x3ce06162c500, {0x48f4fb0, 0x3ce0617951c0}, {0x3ce061a37198?, 0x497406?, 0x0?})
	/usr/local/go/src/net/http/client.go:266 +0x654
net/http.(*Client).send(0x3ce061789c80, 0x3ce06162c500, {0x26b3bf8?, 0x1?, 0x0?})
	/usr/local/go/src/net/http/client.go:187 +0x250
net/http.(*Client).do(0x3ce061789c80, 0x3ce06162c500)
	/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(0x3ce06161c190, {0x4919378, 0x3ce061757d50}, 0x3ce061a37b40)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:457 +0xe85
github.com/rclone/rclone/lib/rest.(*Client).callCodec(0x3ce06161c190, {0x4919378, 0x3ce061757d50}, 0x784782638030?, {0x0?, 0x0?}, {0x40c3a38, 0x3ce061aaf980}, 0x4203c58?, 0x4935688, ...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:703 +0x4e8
github.com/rclone/rclone/lib/rest.(*Client).CallJSON(...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:640
github.com/rclone/rclone/backend/pcloud.(*Fs).changeNotifyLoop(0x3ce061103ce0, {0x4919308, 0x3ce061a6f310}, 0x3ce0617190f0, 0x3ce061a0a4d0)
	/home/rclone/go/src/github.com/rclone/rclone/backend/pcloud/pcloud.go:1192 +0x4ad
created by github.com/rclone/rclone/backend/pcloud.(*Fs).ChangeNotify in goroutine 1626
	/home/rclone/go/src/github.com/rclone/rclone/backend/pcloud/pcloud.go:1097 +0xb4
"./vfs.test -test.v -test.timeout 1h0m0s -remote TestPcloud: -verbose" - Finished ERROR in 1h0m0.786056604s (try 1/5): exit status 2: Failed [TestDirHandleReaddirnames TestDirMethods]