"./vfs.test -test.v -test.timeout 1h0m0s -remote TestPcloud: -verbose -test.run '^(TestFileSetModTime|TestWriteFileModTimeWithOpenWriters)$/^(cache=full,open=false,write=false|cache=full,open=true,write=false|cache=off,open=false,write=false|cache=off,open=true,write=false|cache=off,open=true,write=true)$'" - Starting (try 2/5)
2022/03/23 06:25:16 DEBUG : Creating backend with remote "TestPcloud:rclone-test-lekotal7mukeham3vexivok9"
2022/03/23 06:25:16 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2022/03/23 06:25:16 DEBUG : Creating backend with remote "/tmp/rclone3374346625"
=== RUN   TestFileSetModTime
=== RUN   TestFileSetModTime/cache=off,open=false,write=false
    run.go:181: Remote "pcloud root 'rclone-test-lekotal7mukeham3vexivok9'", Local "Local file system at /tmp/rclone3374346625", Modify Window "1s"
2022/03/23 06:25:16 INFO  : pcloud root 'rclone-test-lekotal7mukeham3vexivok9': poll-interval is not supported by this remote
2022/03/23 06:25:16 NOTICE: pcloud root 'rclone-test-lekotal7mukeham3vexivok9': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2022/03/23 06:25:18 DEBUG : Can set mod time: false
    file_test.go:98: can't set mod time
2022/03/23 06:25:18 DEBUG : WaitForWriters: timeout=30s
2022/03/23 06:25:18 DEBUG : dir: Looking for writers
2022/03/23 06:25:18 DEBUG : file1: reading active writers
2022/03/23 06:25:18 DEBUG : : Looking for writers
2022/03/23 06:25:18 DEBUG : dir: reading active writers
2022/03/23 06:25:18 DEBUG : >WaitForWriters: 
=== RUN   TestFileSetModTime/cache=off,open=true,write=false
    file_test.go:93: can't set mod time
=== RUN   TestFileSetModTime/cache=off,open=true,write=true
    file_test.go:93: can't set mod time
=== RUN   TestFileSetModTime/cache=full,open=false,write=false
    file_test.go:93: can't set mod time
=== RUN   TestFileSetModTime/cache=full,open=true,write=false
    file_test.go:93: can't set mod time
--- PASS: TestFileSetModTime (2.72s)
    --- SKIP: TestFileSetModTime/cache=off,open=false,write=false (2.72s)
    --- SKIP: TestFileSetModTime/cache=off,open=true,write=false (0.00s)
    --- SKIP: TestFileSetModTime/cache=off,open=true,write=true (0.00s)
    --- SKIP: TestFileSetModTime/cache=full,open=false,write=false (0.00s)
    --- SKIP: TestFileSetModTime/cache=full,open=true,write=false (0.00s)
=== RUN   TestWriteFileModTimeWithOpenWriters
    run.go:181: Remote "pcloud root 'rclone-test-lekotal7mukeham3vexivok9'", Local "Local file system at /tmp/rclone3374346625", Modify Window "1s"
2022/03/23 06:25:19 INFO  : pcloud root 'rclone-test-lekotal7mukeham3vexivok9': poll-interval is not supported by this remote
2022/03/23 06:25:19 NOTICE: pcloud root 'rclone-test-lekotal7mukeham3vexivok9': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2022/03/23 06:25:19 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2022/03/23 06:25:19 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2022/03/23 06:25:19 DEBUG : : Added virtual directory entry vAddFile: "file1"
2022/03/23 06:25:19 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2022/03/23 06:25:19 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
    write_test.go:265: can't set mod time
2022/03/23 06:25:19 DEBUG : WaitForWriters: timeout=30s
2022/03/23 06:25:19 DEBUG : : Looking for writers
2022/03/23 06:25:19 DEBUG : file1: reading active writers
2022/03/23 06:25:19 DEBUG : file1: active writers 1
2022/03/23 06:25:19 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms
2022/03/23 06:25:19 DEBUG : : Looking for writers
2022/03/23 06:25:19 DEBUG : file1: reading active writers
2022/03/23 06:25:19 DEBUG : file1: active writers 1
2022/03/23 06:25:19 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms
2022/03/23 06:25:19 DEBUG : : Looking for writers
2022/03/23 06:25:19 DEBUG : file1: reading active writers
2022/03/23 06:25:19 DEBUG : file1: active writers 1
2022/03/23 06:25:19 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms
2022/03/23 06:25:19 DEBUG : : Looking for writers
2022/03/23 06:25:19 DEBUG : file1: reading active writers
2022/03/23 06:25:19 DEBUG : file1: active writers 1
2022/03/23 06:25:19 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms
2022/03/23 06:25:19 DEBUG : : Looking for writers
2022/03/23 06:25:19 DEBUG : file1: reading active writers
2022/03/23 06:25:19 DEBUG : file1: active writers 1
2022/03/23 06:25:19 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms
2022/03/23 06:25:19 DEBUG : : Looking for writers
2022/03/23 06:25:19 DEBUG : file1: reading active writers
2022/03/23 06:25:19 DEBUG : file1: active writers 1
2022/03/23 06:25:19 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms
2022/03/23 06:25:20 DEBUG : : Looking for writers
2022/03/23 06:25:20 DEBUG : file1: reading active writers
2022/03/23 06:25:20 DEBUG : file1: active writers 1
2022/03/23 06:25:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms
2022/03/23 06:25:20 DEBUG : : Looking for writers
2022/03/23 06:25:20 DEBUG : file1: reading active writers
2022/03/23 06:25:20 DEBUG : file1: active writers 1
2022/03/23 06:25:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:21 DEBUG : : Looking for writers
2022/03/23 06:25:21 DEBUG : file1: reading active writers
2022/03/23 06:25:21 DEBUG : file1: active writers 1
2022/03/23 06:25:21 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:22 DEBUG : : Looking for writers
2022/03/23 06:25:22 DEBUG : file1: reading active writers
2022/03/23 06:25:22 DEBUG : file1: active writers 1
2022/03/23 06:25:22 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:23 DEBUG : : Looking for writers
2022/03/23 06:25:23 DEBUG : file1: reading active writers
2022/03/23 06:25:23 DEBUG : file1: active writers 1
2022/03/23 06:25:23 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:24 DEBUG : : Looking for writers
2022/03/23 06:25:24 DEBUG : file1: reading active writers
2022/03/23 06:25:24 DEBUG : file1: active writers 1
2022/03/23 06:25:24 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:25 DEBUG : : Looking for writers
2022/03/23 06:25:25 DEBUG : file1: reading active writers
2022/03/23 06:25:25 DEBUG : file1: active writers 1
2022/03/23 06:25:25 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:26 DEBUG : : Looking for writers
2022/03/23 06:25:26 DEBUG : file1: reading active writers
2022/03/23 06:25:26 DEBUG : file1: active writers 1
2022/03/23 06:25:26 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:27 DEBUG : : Looking for writers
2022/03/23 06:25:27 DEBUG : file1: reading active writers
2022/03/23 06:25:27 DEBUG : file1: active writers 1
2022/03/23 06:25:27 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:28 DEBUG : : Looking for writers
2022/03/23 06:25:28 DEBUG : file1: reading active writers
2022/03/23 06:25:28 DEBUG : file1: active writers 1
2022/03/23 06:25:28 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:29 DEBUG : : Looking for writers
2022/03/23 06:25:29 DEBUG : file1: reading active writers
2022/03/23 06:25:29 DEBUG : file1: active writers 1
2022/03/23 06:25:29 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:30 DEBUG : : Looking for writers
2022/03/23 06:25:30 DEBUG : file1: reading active writers
2022/03/23 06:25:30 DEBUG : file1: active writers 1
2022/03/23 06:25:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:31 DEBUG : : Looking for writers
2022/03/23 06:25:31 DEBUG : file1: reading active writers
2022/03/23 06:25:31 DEBUG : file1: active writers 1
2022/03/23 06:25:31 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:32 DEBUG : : Looking for writers
2022/03/23 06:25:32 DEBUG : file1: reading active writers
2022/03/23 06:25:32 DEBUG : file1: active writers 1
2022/03/23 06:25:32 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:33 DEBUG : : Looking for writers
2022/03/23 06:25:33 DEBUG : file1: reading active writers
2022/03/23 06:25:33 DEBUG : file1: active writers 1
2022/03/23 06:25:33 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:34 DEBUG : : Looking for writers
2022/03/23 06:25:34 DEBUG : file1: reading active writers
2022/03/23 06:25:34 DEBUG : file1: active writers 1
2022/03/23 06:25:34 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:35 DEBUG : : Looking for writers
2022/03/23 06:25:35 DEBUG : file1: reading active writers
2022/03/23 06:25:35 DEBUG : file1: active writers 1
2022/03/23 06:25:35 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:36 DEBUG : : Looking for writers
2022/03/23 06:25:36 DEBUG : file1: reading active writers
2022/03/23 06:25:36 DEBUG : file1: active writers 1
2022/03/23 06:25:36 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:37 DEBUG : : Looking for writers
2022/03/23 06:25:37 DEBUG : file1: reading active writers
2022/03/23 06:25:37 DEBUG : file1: active writers 1
2022/03/23 06:25:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:38 DEBUG : : Looking for writers
2022/03/23 06:25:38 DEBUG : file1: reading active writers
2022/03/23 06:25:38 DEBUG : file1: active writers 1
2022/03/23 06:25:38 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:39 DEBUG : : Looking for writers
2022/03/23 06:25:39 DEBUG : file1: reading active writers
2022/03/23 06:25:39 DEBUG : file1: active writers 1
2022/03/23 06:25:39 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:40 DEBUG : : Looking for writers
2022/03/23 06:25:40 DEBUG : file1: reading active writers
2022/03/23 06:25:40 DEBUG : file1: active writers 1
2022/03/23 06:25:40 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:41 DEBUG : : Looking for writers
2022/03/23 06:25:41 DEBUG : file1: reading active writers
2022/03/23 06:25:41 DEBUG : file1: active writers 1
2022/03/23 06:25:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:42 DEBUG : : Looking for writers
2022/03/23 06:25:42 DEBUG : file1: reading active writers
2022/03/23 06:25:42 DEBUG : file1: active writers 1
2022/03/23 06:25:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:43 DEBUG : : Looking for writers
2022/03/23 06:25:43 DEBUG : file1: reading active writers
2022/03/23 06:25:43 DEBUG : file1: active writers 1
2022/03/23 06:25:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:44 DEBUG : : Looking for writers
2022/03/23 06:25:44 DEBUG : file1: reading active writers
2022/03/23 06:25:44 DEBUG : file1: active writers 1
2022/03/23 06:25:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:45 DEBUG : : Looking for writers
2022/03/23 06:25:45 DEBUG : file1: reading active writers
2022/03/23 06:25:45 DEBUG : file1: active writers 1
2022/03/23 06:25:45 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:46 DEBUG : : Looking for writers
2022/03/23 06:25:46 DEBUG : file1: reading active writers
2022/03/23 06:25:46 DEBUG : file1: active writers 1
2022/03/23 06:25:46 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:47 DEBUG : : Looking for writers
2022/03/23 06:25:47 DEBUG : file1: reading active writers
2022/03/23 06:25:47 DEBUG : file1: active writers 1
2022/03/23 06:25:47 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:48 DEBUG : : Looking for writers
2022/03/23 06:25:48 DEBUG : file1: reading active writers
2022/03/23 06:25:48 DEBUG : file1: active writers 1
2022/03/23 06:25:48 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2022/03/23 06:25:49 ERROR : Exiting even though 1 writers active and 0 cache items in use after 30s
Cache: <nil>
2022/03/23 06:25:49 DEBUG : >WaitForWriters: 
--- SKIP: TestWriteFileModTimeWithOpenWriters (30.50s)
PASS
2022/03/23 06:25:49 DEBUG : pcloud root 'rclone-test-lekotal7mukeham3vexivok9': Purge remote
"./vfs.test -test.v -test.timeout 1h0m0s -remote TestPcloud: -verbose -test.run '^(TestFileSetModTime|TestWriteFileModTimeWithOpenWriters)$/^(cache=full,open=false,write=false|cache=full,open=true,write=false|cache=off,open=false,write=false|cache=off,open=true,write=false|cache=off,open=true,write=true)$'" - Finished OK in 33.821844257s (try 2/5)