"./vfs.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestDirMethods|TestDirOpen|TestDirWalk|TestFileMethods)$|^TestFileRename$/^off,forceCache=false$'" - Starting (try 2/5)
2024/10/30 01:43:15 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-gaqurev1zifo"
2024/10/30 01:43:15 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/10/30 01:43:15 DEBUG : Creating backend with remote "/tmp/rclone703004893"
=== RUN   TestDirMethods
    run.go:180: Remote "files root 'rclone-test-gaqurev1zifo'", Local "Local file system at /tmp/rclone703004893", Modify Window "1s"
2024/10/30 01:43:15 INFO  : files root 'rclone-test-gaqurev1zifo': poll-interval is not supported by this remote
2024/10/30 01:43:17 DEBUG : WaitForWriters: timeout=30s
2024/10/30 01:43:17 DEBUG : dir: Looking for writers
2024/10/30 01:43:17 DEBUG : : Looking for writers
2024/10/30 01:43:17 DEBUG : dir: reading active writers
2024/10/30 01:43:17 DEBUG : >WaitForWriters: 
--- PASS: TestDirMethods (2.29s)
=== RUN   TestDirWalk
    run.go:180: Remote "files root 'rclone-test-gaqurev1zifo'", Local "Local file system at /tmp/rclone703004893", Modify Window "1s"
2024/10/30 01:43:17 INFO  : files root 'rclone-test-gaqurev1zifo': poll-interval is not supported by this remote
2024/10/30 01:43:20 DEBUG : : forgetting directory cache
2024/10/30 01:43:20 DEBUG : dir: forgetting directory cache
2024/10/30 01:43:20 DEBUG : WaitForWriters: timeout=30s
2024/10/30 01:43:20 DEBUG : dir: Looking for writers
2024/10/30 01:43:20 DEBUG : fil/a/b: Looking for writers
2024/10/30 01:43:20 DEBUG : fil/a: Looking for writers
2024/10/30 01:43:20 DEBUG : b: reading active writers
2024/10/30 01:43:20 DEBUG : fil: Looking for writers
2024/10/30 01:43:20 DEBUG : a: reading active writers
2024/10/30 01:43:20 DEBUG : : Looking for writers
2024/10/30 01:43:20 DEBUG : dir: reading active writers
2024/10/30 01:43:20 DEBUG : fil: reading active writers
2024/10/30 01:43:20 DEBUG : >WaitForWriters: 
2024/10/30 01:43:21 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-gaqurev1zifo/fil not empty`)
2024/10/30 01:43:21 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2024/10/30 01:43:22 DEBUG : pacer: Reducing sleep to 15ms
2024/10/30 01:43:22 DEBUG : pacer: Reducing sleep to 11.25ms
2024/10/30 01:43:22 DEBUG : pacer: Reducing sleep to 10ms
--- PASS: TestDirWalk (4.62s)
=== RUN   TestDirOpen
    run.go:180: Remote "files root 'rclone-test-gaqurev1zifo'", Local "Local file system at /tmp/rclone703004893", Modify Window "1s"
2024/10/30 01:43:22 INFO  : files root 'rclone-test-gaqurev1zifo': poll-interval is not supported by this remote
    run.go:285: Failed to put "dir/file1" to "files root 'rclone-test-gaqurev1zifo'": object not found
2024/10/30 01:43:23 DEBUG : WaitForWriters: timeout=30s
2024/10/30 01:43:23 DEBUG : : Looking for writers
2024/10/30 01:43:23 DEBUG : >WaitForWriters: 
--- FAIL: TestDirOpen (0.99s)
=== RUN   TestFileMethods
    run.go:180: Remote "files root 'rclone-test-gaqurev1zifo'", Local "Local file system at /tmp/rclone703004893", Modify Window "1s"
2024/10/30 01:43:23 INFO  : files root 'rclone-test-gaqurev1zifo': poll-interval is not supported by this remote
2024/10/30 01:43:24 DEBUG : WaitForWriters: timeout=30s
2024/10/30 01:43:24 DEBUG : dir: Looking for writers
2024/10/30 01:43:24 DEBUG : file1: reading active writers
2024/10/30 01:43:24 DEBUG : : Looking for writers
2024/10/30 01:43:24 DEBUG : dir: reading active writers
2024/10/30 01:43:24 DEBUG : >WaitForWriters: 
--- PASS: TestFileMethods (2.02s)
=== RUN   TestFileRename
=== RUN   TestFileRename/off,forceCache=false
    run.go:180: Remote "files root 'rclone-test-gaqurev1zifo'", Local "Local file system at /tmp/rclone703004893", Modify Window "1s"
2024/10/30 01:43:25 INFO  : files root 'rclone-test-gaqurev1zifo': poll-interval is not supported by this remote
2024/10/30 01:43:26 DEBUG : WaitForWriters: timeout=30s
2024/10/30 01:43:26 DEBUG : dir: Looking for writers
2024/10/30 01:43:26 DEBUG : file1: reading active writers
2024/10/30 01:43:26 DEBUG : : Looking for writers
2024/10/30 01:43:26 DEBUG : dir: reading active writers
2024/10/30 01:43:26 DEBUG : >WaitForWriters: 
2024/10/30 01:43:27 INFO  : dir/file1: Moved (server-side) to: newLeaf
2024/10/30 01:43:27 DEBUG : newLeaf: Updating file with newLeaf 0xc000197140
2024/10/30 01:43:27 DEBUG : dir: Added virtual directory entry vDel: "file1"
2024/10/30 01:43:27 DEBUG : : Added virtual directory entry vAddFile: "newLeaf"
2024/10/30 01:43:28 INFO  : newLeaf: Moved (server-side) to: dir/file1
2024/10/30 01:43:28 DEBUG : dir/file1: Updating file with dir/file1 0xc000197140
2024/10/30 01:43:28 DEBUG : : Added virtual directory entry vDel: "newLeaf"
2024/10/30 01:43:28 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2024/10/30 01:43:28 DEBUG : dir/file1: Open: flags=O_WRONLY|O_TRUNC
2024/10/30 01:43:28 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err=<nil>
2024/10/30 01:43:28 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2024/10/30 01:43:28 DEBUG : dir/file1: File is currently open, delaying rename 0xc000197140
2024/10/30 01:43:28 DEBUG : dir: Added virtual directory entry vDel: "file1"
2024/10/30 01:43:28 DEBUG : : Added virtual directory entry vAddFile: "newLeaf"
2024/10/30 01:43:28 DEBUG : files root 'rclone-test-gaqurev1zifo': File to upload is small (25 bytes), uploading instead of streaming
2024/10/30 01:43:29 DEBUG : dir/file1: Dst hash empty - aborting Src hash check
2024/10/30 01:43:29 DEBUG : dir/file1: Size of src and dst objects identical
2024/10/30 01:43:29 DEBUG : : Added virtual directory entry vAddFile: "newLeaf"
2024/10/30 01:43:29 DEBUG : newLeaf: Running delayed rename now
2024/10/30 01:43:30 INFO  : dir/file1: Moved (server-side) to: newLeaf
2024/10/30 01:43:30 DEBUG : newLeaf: Updating file with newLeaf 0xc000197140
2024/10/30 01:43:30 DEBUG : WaitForWriters: timeout=30s
2024/10/30 01:43:30 DEBUG : dir: Looking for writers
2024/10/30 01:43:30 DEBUG : : Looking for writers
2024/10/30 01:43:30 DEBUG : dir: reading active writers
2024/10/30 01:43:30 DEBUG : newLeaf: reading active writers
2024/10/30 01:43:30 DEBUG : >WaitForWriters: 
2024/10/30 01:43:30 DEBUG : WaitForWriters: timeout=30s
2024/10/30 01:43:30 DEBUG : dir: Looking for writers
2024/10/30 01:43:30 DEBUG : : Looking for writers
2024/10/30 01:43:30 DEBUG : dir: reading active writers
2024/10/30 01:43:30 DEBUG : newLeaf: reading active writers
2024/10/30 01:43:30 DEBUG : >WaitForWriters: 
--- PASS: TestFileRename (5.91s)
    --- PASS: TestFileRename/off,forceCache=false (5.91s)
FAIL
2024/10/30 01:43:31 DEBUG : files root 'rclone-test-gaqurev1zifo': Purge remote
"./vfs.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestDirMethods|TestDirOpen|TestDirWalk|TestFileMethods)$|^TestFileRename$/^off,forceCache=false$'" - Finished ERROR in 16.411374035s (try 2/5): exit status 1: Failed [TestDirOpen]