"./vfs.test -test.v -test.timeout 1h0m0s -remote TestOneDrive: -verbose" - Starting (try 1/5)
2026/03/12 01:54:15 DEBUG : Creating backend with remote "TestOneDrive:rclone-test-wozehug0vego"
2026/03/12 01:54:15 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/03/12 01:54:15 DEBUG : TestOneDrive: Set overridden config ["user_agent"] for backend startup
2026/03/12 01:54:16 DEBUG : Creating backend with remote "/tmp/rclone1419377252"
=== RUN   TestDirHandleMethods
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:54:16 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzcyNTYyNDcwMDAwOzE1NTEyNDg5NTU7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:54:16 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:54:17 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:54:18 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:54:20 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:54:20 DEBUG : dir: Looking for writers
2026/03/12 01:54:20 DEBUG : Looking for writers
2026/03/12 01:54:20 DEBUG : dir: reading active writers
2026/03/12 01:54:20 DEBUG : >WaitForWriters: 
--- PASS: TestDirHandleMethods (6.49s)
=== RUN   TestDirHandleReaddir
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:54:22 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzcyNjI1NTcwMDAwOzE1NTEyNDkwMzg7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:54:22 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:54:23 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:54:24 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:54:25 DEBUG : dir/file2: Starting multipart upload
2026/03/12 01:54:25 DEBUG : dir/file2: Uploading segment 0/15 size 15
2026/03/12 01:54:26 DEBUG : dir/subdir/file3: Starting multipart upload
2026/03/12 01:54:27 DEBUG : dir/subdir/file3: Uploading segment 0/16 size 16
2026/03/12 01:54:29 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:54:29 DEBUG : dir/subdir: Looking for writers
2026/03/12 01:54:29 DEBUG : dir: Looking for writers
2026/03/12 01:54:29 DEBUG : file1: reading active writers
2026/03/12 01:54:29 DEBUG : file2: reading active writers
2026/03/12 01:54:29 DEBUG : subdir: reading active writers
2026/03/12 01:54:29 DEBUG : Looking for writers
2026/03/12 01:54:29 DEBUG : dir: reading active writers
2026/03/12 01:54:29 DEBUG : >WaitForWriters: 
--- PASS: TestDirHandleReaddir (9.52s)
=== RUN   TestDirHandleReaddirnames
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:54:32 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzcyNzIxNjAwMDAwOzE1NTEyNDkxNTk7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:54:32 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:54:33 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:54:33 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:54:35 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:54:35 DEBUG : dir: Looking for writers
2026/03/12 01:54:35 DEBUG : file1: reading active writers
2026/03/12 01:54:35 DEBUG : Looking for writers
2026/03/12 01:54:35 DEBUG : dir: reading active writers
2026/03/12 01:54:35 DEBUG : >WaitForWriters: 
--- PASS: TestDirHandleReaddirnames (4.45s)
=== RUN   TestDirMethods
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:54:36 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzcyNzY1NjAwMDAwOzE1NTEyNDkyMDc7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:54:36 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:54:37 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:54:37 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:54:39 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:54:39 DEBUG : dir: Looking for writers
2026/03/12 01:54:39 DEBUG : Looking for writers
2026/03/12 01:54:39 DEBUG : dir: reading active writers
2026/03/12 01:54:39 DEBUG : >WaitForWriters: 
--- PASS: TestDirMethods (4.23s)
=== RUN   TestDirForgetAll
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:54:40 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzcyODA4NTcwMDAwOzE1NTEyNDkyNTY7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:54:40 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:54:41 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:54:42 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:54:44 DEBUG : dir: forgetting directory cache
2026/03/12 01:54:44 DEBUG : forgetting directory cache
2026/03/12 01:54:44 DEBUG : dir: forgetting directory cache
2026/03/12 01:54:44 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:54:44 DEBUG : Looking for writers
2026/03/12 01:54:44 DEBUG : >WaitForWriters: 
--- PASS: TestDirForgetAll (4.74s)
=== RUN   TestDirForgetPath
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:54:45 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzcyODU1ODAwMDAwOzE1NTEyNDkzMDU7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:54:45 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:54:46 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:54:47 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:54:48 DEBUG : ForgetPath: relativePath="dir/notfound", type=1
2026/03/12 01:54:48 DEBUG : dir: invalidating directory cache
2026/03/12 01:54:48 DEBUG : >ForgetPath: 
2026/03/12 01:54:48 DEBUG : ForgetPath: relativePath="dir", type=0
2026/03/12 01:54:48 DEBUG : invalidating directory cache
2026/03/12 01:54:48 DEBUG : dir: forgetting directory cache
2026/03/12 01:54:48 DEBUG : >ForgetPath: 
2026/03/12 01:54:48 DEBUG : ForgetPath: relativePath="not/in/cache", type=0
2026/03/12 01:54:48 DEBUG : >ForgetPath: 
2026/03/12 01:54:48 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:54:48 DEBUG : dir: Looking for writers
2026/03/12 01:54:48 DEBUG : Looking for writers
2026/03/12 01:54:48 DEBUG : dir: reading active writers
2026/03/12 01:54:48 DEBUG : >WaitForWriters: 
--- PASS: TestDirForgetPath (4.56s)
=== RUN   TestDirWalk
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:54:50 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzcyOTAxODcwMDAwOzE1NTEyNDkzNTA7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:54:50 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:54:50 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:54:51 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:54:54 DEBUG : fil/a/b/c: Starting multipart upload
2026/03/12 01:54:55 DEBUG : fil/a/b/c: Uploading segment 0/15 size 15
2026/03/12 01:54:57 DEBUG : forgetting directory cache
2026/03/12 01:54:57 DEBUG : dir: forgetting directory cache
2026/03/12 01:54:58 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:54:58 DEBUG : fil/a/b: Looking for writers
2026/03/12 01:54:58 DEBUG : fil/a: Looking for writers
2026/03/12 01:54:58 DEBUG : b: reading active writers
2026/03/12 01:54:58 DEBUG : fil: Looking for writers
2026/03/12 01:54:58 DEBUG : a: reading active writers
2026/03/12 01:54:58 DEBUG : dir: Looking for writers
2026/03/12 01:54:58 DEBUG : Looking for writers
2026/03/12 01:54:58 DEBUG : dir: reading active writers
2026/03/12 01:54:58 DEBUG : fil: reading active writers
2026/03/12 01:54:58 DEBUG : >WaitForWriters: 
--- PASS: TestDirWalk (11.90s)
=== RUN   TestDirSetModTime
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:55:02 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzczMDIwODcwMDAwOzE1NTEyNDk0NTk7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:55:02 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:55:03 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:55:03 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:55:05 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:55:05 DEBUG : dir: Looking for writers
2026/03/12 01:55:05 DEBUG : Looking for writers
2026/03/12 01:55:05 DEBUG : dir: reading active writers
2026/03/12 01:55:05 DEBUG : >WaitForWriters: 
--- PASS: TestDirSetModTime (4.92s)
=== RUN   TestDirStat
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:55:07 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzczMDY5ODAwMDAwOzE1NTEyNDk0OTQ7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:55:07 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:55:07 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:55:08 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:55:10 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:55:10 DEBUG : dir: Looking for writers
2026/03/12 01:55:10 DEBUG : file1: reading active writers
2026/03/12 01:55:10 DEBUG : Looking for writers
2026/03/12 01:55:10 DEBUG : dir: reading active writers
2026/03/12 01:55:10 DEBUG : >WaitForWriters: 
--- PASS: TestDirStat (4.59s)
=== RUN   TestDirReadDirAll
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:55:11 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzczMTE1NTMwMDAwOzE1NTEyNDk1Mzk7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:55:11 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:55:12 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:55:12 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:55:13 DEBUG : dir/file2: Starting multipart upload
2026/03/12 01:55:14 DEBUG : dir/file2: Uploading segment 0/15 size 15
2026/03/12 01:55:15 DEBUG : dir/subdir/file3: Starting multipart upload
2026/03/12 01:55:15 DEBUG : dir/subdir/file3: Uploading segment 0/16 size 16
=== RUN   TestDirReadDirAll/Virtual
2026/03/12 01:55:17 DEBUG : dir: Added virtual directory entry vAddFile: "virtualFile"
2026/03/12 01:55:17 DEBUG : dir: Added virtual directory entry vAddDir: "virtualDir"
2026/03/12 01:55:17 DEBUG : dir: Added virtual directory entry vDel: "file2"
2026/03/12 01:55:17 DEBUG : dir: Added virtual directory entry vDel: "subdir"
2026/03/12 01:55:17 DEBUG : dir/virtualFile: Starting multipart upload
2026/03/12 01:55:18 DEBUG : dir/virtualFile: Uploading segment 0/20 size 20
2026/03/12 01:55:19 DEBUG : dir/virtualDir/testFile: Starting multipart upload
2026/03/12 01:55:20 DEBUG : dir/virtualDir/testFile: Uploading segment 0/17 size 17
2026/03/12 01:55:21 DEBUG : dir: invalidating directory cache
2026/03/12 01:55:21 DEBUG : dir: Removed virtual directory entry vDel: "subdir"
2026/03/12 01:55:21 DEBUG : dir: Removed virtual directory entry vAddDir: "virtualDir"
2026/03/12 01:55:21 DEBUG : dir: Removed virtual directory entry vDel: "file2"
2026/03/12 01:55:21 DEBUG : dir/file1: Reset virtual modtime
2026/03/12 01:55:21 DEBUG : dir: Removed virtual directory entry vAddFile: "virtualFile"
2026/03/12 01:55:21 DEBUG : dir/virtualFile: Reset virtual modtime
2026/03/12 01:55:21 DEBUG : dir: Added virtual directory entry vAddFile: "virtualFile2"
2026/03/12 01:55:21 DEBUG : dir: Added virtual directory entry vAddDir: "virtualDir2"
2026/03/12 01:55:21 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/03/12 01:55:21 DEBUG : dir: invalidating directory cache
2026/03/12 01:55:21 DEBUG : dir: Removed virtual directory entry vAddDir: "virtualDir2"
2026/03/12 01:55:21 DEBUG : dir: Removed virtual directory entry vDel: "file1"
2026/03/12 01:55:21 DEBUG : dir/virtualFile: Reset virtual modtime
2026/03/12 01:55:21 DEBUG : forgetting directory cache
2026/03/12 01:55:21 DEBUG : dir: forgetting directory cache
2026/03/12 01:55:21 DEBUG : dir/virtualDir: forgetting directory cache
2026/03/12 01:55:21 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:55:21 DEBUG : dir/virtualDir: Looking for writers
2026/03/12 01:55:21 DEBUG : dir: Looking for writers
2026/03/12 01:55:21 DEBUG : file1: reading active writers
2026/03/12 01:55:21 DEBUG : virtualFile2: reading active writers
2026/03/12 01:55:21 DEBUG : virtualFile: reading active writers
2026/03/12 01:55:21 DEBUG : virtualDir: reading active writers
2026/03/12 01:55:21 DEBUG : Looking for writers
2026/03/12 01:55:21 DEBUG : dir: reading active writers
2026/03/12 01:55:21 DEBUG : >WaitForWriters: 
--- PASS: TestDirReadDirAll (13.19s)
    --- PASS: TestDirReadDirAll/Virtual (4.14s)
=== RUN   TestDirOpen
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:55:24 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzczMjQ3NDAwMDAwOzE1NTEyNDk2ODk7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:55:24 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:55:25 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:55:26 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:55:27 ERROR : dir/: Can only open directories read only
2026/03/12 01:55:27 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:55:27 DEBUG : dir: Looking for writers
2026/03/12 01:55:27 DEBUG : Looking for writers
2026/03/12 01:55:27 DEBUG : dir: reading active writers
2026/03/12 01:55:27 DEBUG : >WaitForWriters: 
--- PASS: TestDirOpen (4.28s)
=== RUN   TestDirCreate
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:55:29 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzczMjkwMTAwMDAwOzE1NTEyNDk3Mzg7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:55:29 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:55:29 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:55:30 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:55:32 DEBUG : dir/potato: Open: flags=O_WRONLY|O_CREATE
2026/03/12 01:55:32 DEBUG : dir: Added virtual directory entry vAddFile: "potato"
2026/03/12 01:55:32 DEBUG : dir/potato: >Open: fd=dir/potato (w), err=<nil>
2026/03/12 01:55:32 DEBUG : dir: Added virtual directory entry vAddFile: "potato"
2026/03/12 01:55:32 DEBUG : OneDrive root 'rclone-test-wozehug0vego': File to upload is small (5 bytes), uploading instead of streaming
2026/03/12 01:55:32 DEBUG : dir/potato: Starting multipart upload
2026/03/12 01:55:32 DEBUG : dir/potato: Uploading segment 0/5 size 5
2026/03/12 01:55:33 DEBUG : dir/potato: size = 5 OK
2026/03/12 01:55:33 DEBUG : dir/potato: quickxor = 6828031bd8f00600000000000500000000000000 OK
2026/03/12 01:55:33 DEBUG : dir/potato: Size and quickxor of src and dst objects identical
2026/03/12 01:55:33 DEBUG : dir: Added virtual directory entry vAddFile: "potato"
2026/03/12 01:55:33 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:55:33 DEBUG : dir: Looking for writers
2026/03/12 01:55:33 DEBUG : file1: reading active writers
2026/03/12 01:55:33 DEBUG : potato: reading active writers
2026/03/12 01:55:33 DEBUG : Looking for writers
2026/03/12 01:55:33 DEBUG : dir: reading active writers
2026/03/12 01:55:33 DEBUG : >WaitForWriters: 
--- PASS: TestDirCreate (6.40s)
=== RUN   TestDirMkdir
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:55:35 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzczMzU0MTAwMDAwOzE1NTEyNDk4MTM7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:55:35 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:55:36 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:55:36 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:55:39 DEBUG : dir: Added virtual directory entry vAddDir: "sub"
2026/03/12 01:55:40 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:55:40 DEBUG : dir/sub: Looking for writers
2026/03/12 01:55:40 DEBUG : dir: Looking for writers
2026/03/12 01:55:40 DEBUG : file1: reading active writers
2026/03/12 01:55:40 DEBUG : sub: reading active writers
2026/03/12 01:55:40 DEBUG : Looking for writers
2026/03/12 01:55:40 DEBUG : dir: reading active writers
2026/03/12 01:55:40 DEBUG : >WaitForWriters: 
--- PASS: TestDirMkdir (7.28s)
=== RUN   TestDirMkdirSub
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:55:42 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzczNDI2ODMwMDAwOzE1NTEyNDk4ODE7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:55:42 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:55:43 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:55:44 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:55:46 DEBUG : dir: Added virtual directory entry vAddDir: "sub"
2026/03/12 01:55:47 DEBUG : dir/sub: Added virtual directory entry vAddDir: "subsub"
2026/03/12 01:55:49 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:55:49 DEBUG : dir/sub/subsub: Looking for writers
2026/03/12 01:55:49 DEBUG : dir/sub: Looking for writers
2026/03/12 01:55:49 DEBUG : subsub: reading active writers
2026/03/12 01:55:49 DEBUG : dir: Looking for writers
2026/03/12 01:55:49 DEBUG : file1: reading active writers
2026/03/12 01:55:49 DEBUG : sub: reading active writers
2026/03/12 01:55:49 DEBUG : Looking for writers
2026/03/12 01:55:49 DEBUG : dir: reading active writers
2026/03/12 01:55:49 DEBUG : >WaitForWriters: 
--- PASS: TestDirMkdirSub (9.49s)
=== RUN   TestDirRemove
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:55:52 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzczNTIxNDcwMDAwOzE1NTEyNDk5NzM7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:55:52 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:55:52 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:55:53 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:55:54 ERROR : dir/: Dir.Remove not empty
2026/03/12 01:55:54 DEBUG : dir/file1: Remove: 
2026/03/12 01:55:55 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/03/12 01:55:55 DEBUG : dir/file1: >Remove: err=<nil>
2026/03/12 01:55:55 DEBUG : Added virtual directory entry vDel: "dir"
2026/03/12 01:55:56 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:55:56 DEBUG : Looking for writers
2026/03/12 01:55:56 DEBUG : >WaitForWriters: 
--- PASS: TestDirRemove (4.56s)
=== RUN   TestDirRemoveAll
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:55:56 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzczNTY3NTAwMDAwOzE1NTEyNTAwMjU7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:55:56 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:55:57 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:55:58 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:55:59 DEBUG : dir/file1: Remove: 
2026/03/12 01:55:59 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/03/12 01:55:59 DEBUG : dir/file1: >Remove: err=<nil>
2026/03/12 01:56:00 DEBUG : Added virtual directory entry vDel: "dir"
2026/03/12 01:56:00 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:56:00 DEBUG : Looking for writers
2026/03/12 01:56:00 DEBUG : >WaitForWriters: 
--- PASS: TestDirRemoveAll (4.32s)
=== RUN   TestDirRemoveName
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:56:01 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzczNjEwNDcwMDAwOzE1NTEyNTAwNzA7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:56:01 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:56:01 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:56:02 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:56:04 DEBUG : dir/file1: Remove: 
2026/03/12 01:56:04 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/03/12 01:56:04 DEBUG : dir/file1: >Remove: err=<nil>
2026/03/12 01:56:05 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:56:05 DEBUG : dir: Looking for writers
2026/03/12 01:56:05 DEBUG : Looking for writers
2026/03/12 01:56:05 DEBUG : dir: reading active writers
2026/03/12 01:56:05 DEBUG : >WaitForWriters: 
--- PASS: TestDirRemoveName (5.24s)
=== RUN   TestDirRename
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:56:06 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzczNjYyODAwMDAwOzE1NTEyNTAxMjE7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:56:06 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:56:07 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:56:07 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:56:08 DEBUG : dir/file3: Starting multipart upload
2026/03/12 01:56:09 DEBUG : dir/file3: Uploading segment 0/15 size 15
2026/03/12 01:56:10 ERROR : dir/not found: Dir.Rename error: file does not exist
2026/03/12 01:56:11 DEBUG : dir: Updating dir with dir2 0x10040d127450
2026/03/12 01:56:11 DEBUG : dir: forgetting directory cache
2026/03/12 01:56:11 DEBUG : Added virtual directory entry vDel: "dir"
2026/03/12 01:56:11 DEBUG : Added virtual directory entry vAddDir: "dir2"
2026/03/12 01:56:13 INFO  : dir2/file1: Moved (server-side) to: file2
2026/03/12 01:56:13 DEBUG : file2: Updating file with file2 0x10040c827380
2026/03/12 01:56:13 DEBUG : dir2: Added virtual directory entry vDel: "file1"
2026/03/12 01:56:13 DEBUG : Added virtual directory entry vAddFile: "file2"
2026/03/12 01:56:14 INFO  : dir2/file3: Deleted
2026/03/12 01:56:15 INFO  : file2: Moved (server-side) to: dir2/file3
2026/03/12 01:56:15 DEBUG : dir2/file3: Updating file with dir2/file3 0x10040c827380
2026/03/12 01:56:15 DEBUG : Added virtual directory entry vDel: "file2"
2026/03/12 01:56:15 DEBUG : dir2: Added virtual directory entry vAddFile: "file3"
2026/03/12 01:56:16 DEBUG : Added virtual directory entry vAddDir: "empty directory"
2026/03/12 01:56:17 DEBUG : empty directory: Updating dir with renamed empty directory 0x10040d049ad0
2026/03/12 01:56:17 DEBUG : empty directory: forgetting directory cache
2026/03/12 01:56:17 DEBUG : Added virtual directory entry vDel: "empty directory"
2026/03/12 01:56:17 DEBUG : Added virtual directory entry vAddDir: "renamed empty directory"
2026/03/12 01:56:17 DEBUG : dir2: Renaming to "dir3"
2026/03/12 01:56:17 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:56:17 DEBUG : dir3: Looking for writers
2026/03/12 01:56:17 DEBUG : file3: reading active writers
2026/03/12 01:56:17 DEBUG : renamed empty directory: Looking for writers
2026/03/12 01:56:17 DEBUG : Looking for writers
2026/03/12 01:56:17 DEBUG : renamed empty directory: reading active writers
2026/03/12 01:56:17 DEBUG : dir3: reading active writers
2026/03/12 01:56:17 DEBUG : >WaitForWriters: 
--- PASS: TestDirRename (13.10s)
=== RUN   TestDirStructSize
    dir_test.go:611: Dir struct has size 200 bytes
--- PASS: TestDirStructSize (0.00s)
=== RUN   TestDirFileOpen
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:56:19 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzczNzkzMzMwMDAwOzE1NTEyNTAyNTg7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:56:19 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:56:20 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:56:20 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:56:22 DEBUG : dir: Added virtual directory entry vAddDir: "sub"
2026/03/12 01:56:22 DEBUG : dir/sub/file0: OpenFile: flags=O_RDWR|O_CREATE|O_TRUNC, perm=-rw-rw-rw-
2026/03/12 01:56:23 DEBUG : dir/sub/file0: Open: flags=O_RDWR|O_CREATE|O_TRUNC
2026/03/12 01:56:23 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file0"
2026/03/12 01:56:23 DEBUG : dir/sub/file0: >Open: fd=dir/sub/file0 (w), err=<nil>
2026/03/12 01:56:23 DEBUG : dir/sub/file0: >OpenFile: fd=dir/sub/file0 (w), err=<nil>
2026/03/12 01:56:23 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file0"
2026/03/12 01:56:23 DEBUG : dir/sub/file2: OpenFile: flags=O_RDWR|O_CREATE|O_TRUNC, perm=-rw-rw-rw-
2026/03/12 01:56:23 DEBUG : dir/sub/file2: Open: flags=O_RDWR|O_CREATE|O_TRUNC
2026/03/12 01:56:23 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file2"
2026/03/12 01:56:23 DEBUG : dir/sub/file2: >Open: fd=dir/sub/file2 (w), err=<nil>
2026/03/12 01:56:23 DEBUG : dir/sub/file2: >OpenFile: fd=dir/sub/file2 (w), err=<nil>
2026/03/12 01:56:23 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file2"
2026/03/12 01:56:23 DEBUG : OneDrive root 'rclone-test-wozehug0vego': File to upload is small (12 bytes), uploading instead of streaming
2026/03/12 01:56:23 DEBUG : dir/sub/file2: Starting multipart upload
2026/03/12 01:56:23 DEBUG : dir/sub/file2: Uploading segment 0/12 size 12
2026/03/12 01:56:24 DEBUG : dir/sub/file2: size = 12 OK
2026/03/12 01:56:24 DEBUG : dir/sub/file2: quickxor = 6828031bd8f00610dce10d726c03194200000000 OK
2026/03/12 01:56:24 DEBUG : dir/sub/file2: Size and quickxor of src and dst objects identical
2026/03/12 01:56:24 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file2"
2026/03/12 01:56:24 DEBUG : forgetting directory cache
2026/03/12 01:56:24 DEBUG : dir: forgetting directory cache
2026/03/12 01:56:24 DEBUG : dir/sub: forgetting directory cache
2026/03/12 01:56:24 DEBUG : dir/sub: Removed virtual directory entry vAddFile: "file2"
2026/03/12 01:56:24 DEBUG : dir: Removed virtual directory entry vAddDir: "sub"
2026/03/12 01:56:24 DEBUG : OneDrive root 'rclone-test-wozehug0vego': File to upload is small (5 bytes), uploading instead of streaming
2026/03/12 01:56:24 DEBUG : dir/sub/file0: Starting multipart upload
2026/03/12 01:56:24 DEBUG : dir/sub/file0: Uploading segment 0/5 size 5
2026/03/12 01:56:25 DEBUG : dir/sub/file0: size = 5 OK
2026/03/12 01:56:25 DEBUG : dir/sub/file0: quickxor = 6828031bd8f00600000000000500000000000000 OK
2026/03/12 01:56:25 DEBUG : dir/sub/file0: Size and quickxor of src and dst objects identical
2026/03/12 01:56:25 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file0"
2026/03/12 01:56:25 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:56:25 DEBUG : dir/sub: Looking for writers
2026/03/12 01:56:25 DEBUG : file0: reading active writers
2026/03/12 01:56:25 DEBUG : file2: reading active writers
2026/03/12 01:56:25 DEBUG : dir: Looking for writers
2026/03/12 01:56:25 DEBUG : file1: reading active writers
2026/03/12 01:56:25 DEBUG : sub: reading active writers
2026/03/12 01:56:25 DEBUG : Looking for writers
2026/03/12 01:56:25 DEBUG : dir: reading active writers
2026/03/12 01:56:25 DEBUG : >WaitForWriters: 
--- PASS: TestDirFileOpen (8.77s)
=== RUN   TestDirEntryModTimeInvalidation
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:56:28 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzczODc3ODMwMDAwOzE1NTEyNTAzNDQ7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:56:28 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
    dir_test.go:666: Need DirModTimeUpdatesOnWrite
2026/03/12 01:56:28 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:56:28 DEBUG : Looking for writers
2026/03/12 01:56:28 DEBUG : >WaitForWriters: 
--- SKIP: TestDirEntryModTimeInvalidation (0.67s)
=== RUN   TestDirMetadataExtension
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:56:28 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzczODc3ODMwMDAwOzE1NTEyNTAzNDQ7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:56:28 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:56:29 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:56:30 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:56:31 DEBUG : dir: Added virtual directory entry vAddFile: "file1.metadata"
2026/03/12 01:56:31 DEBUG : dir/file1.metadata: OpenFile: flags=O_RDONLY, perm=----------
2026/03/12 01:56:31 DEBUG : dir/file1.metadata: Open: flags=O_RDONLY
2026/03/12 01:56:31 DEBUG : dir/file1.metadata: >Open: fd=dir/file1.metadata (r), err=<nil>
2026/03/12 01:56:31 DEBUG : dir/file1.metadata: >OpenFile: fd=dir/file1.metadata (r), err=<nil>
2026/03/12 01:56:31 DEBUG : dir/file1.metadata: ChunkedReader.openRange at 0 length 134217728
2026/03/12 01:56:31 DEBUG : dir/file1.metadata: ChunkedReader.Read at 0 length 512 chunkOffset 0 chunkSize 134217728
2026/03/12 01:56:31 DEBUG : Added virtual directory entry vAddFile: "dir.metadata"
2026/03/12 01:56:31 DEBUG : dir.metadata: OpenFile: flags=O_RDONLY, perm=----------
2026/03/12 01:56:31 DEBUG : dir.metadata: Open: flags=O_RDONLY
2026/03/12 01:56:31 DEBUG : dir.metadata: >Open: fd=dir.metadata (r), err=<nil>
2026/03/12 01:56:31 DEBUG : dir.metadata: >OpenFile: fd=dir.metadata (r), err=<nil>
2026/03/12 01:56:31 DEBUG : dir.metadata: ChunkedReader.openRange at 0 length 134217728
2026/03/12 01:56:31 DEBUG : dir.metadata: ChunkedReader.Read at 0 length 512 chunkOffset 0 chunkSize 134217728
2026/03/12 01:56:31 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:56:31 DEBUG : dir: Looking for writers
2026/03/12 01:56:31 DEBUG : file1: reading active writers
2026/03/12 01:56:31 DEBUG : file1.metadata: reading active writers
2026/03/12 01:56:31 DEBUG : Looking for writers
2026/03/12 01:56:31 DEBUG : dir: reading active writers
2026/03/12 01:56:31 DEBUG : dir.metadata: reading active writers
2026/03/12 01:56:31 DEBUG : >WaitForWriters: 
--- PASS: TestDirMetadataExtension (4.21s)
=== RUN   TestErrorError
--- PASS: TestErrorError (0.00s)
=== RUN   TestFileMethods
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:56:33 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzczOTI5ODMwMDAwOzE1NTEyNTA0MTA7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:56:33 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:56:33 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:56:34 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:56:35 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:56:35 DEBUG : dir: Looking for writers
2026/03/12 01:56:35 DEBUG : file1: reading active writers
2026/03/12 01:56:35 DEBUG : Looking for writers
2026/03/12 01:56:35 DEBUG : dir: reading active writers
2026/03/12 01:56:35 DEBUG : >WaitForWriters: 
--- PASS: TestFileMethods (4.48s)
=== RUN   TestFileSetModTime
=== RUN   TestFileSetModTime/cache=off,open=false,write=false
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:56:37 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4NzczOTc1MTAwMDAwOzE1NTEyNTA0NTk7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:56:37 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:56:38 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:56:38 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:56:40 DEBUG : time_test: Starting multipart upload
2026/03/12 01:56:41 DEBUG : time_test: Uploading segment 0/5 size 5
2026/03/12 01:56:42 DEBUG : Can set mod time: true
2026/03/12 01:56:43 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK
2026/03/12 01:56:43 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:56:43 DEBUG : dir: Looking for writers
2026/03/12 01:56:43 DEBUG : file1: reading active writers
2026/03/12 01:56:43 DEBUG : Looking for writers
2026/03/12 01:56:43 DEBUG : dir: reading active writers
2026/03/12 01:56:43 DEBUG : >WaitForWriters: 
=== RUN   TestFileSetModTime/cache=off,open=true,write=false
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:56:46 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4Nzc0MDYyMzMwMDAwOzE1NTEyNTA1ODE7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:56:46 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:56:46 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:56:47 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:56:49 DEBUG : dir/file1: Open: flags=O_WRONLY|O_TRUNC
2026/03/12 01:56:49 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err=<nil>
2026/03/12 01:56:49 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/03/12 01:56:49 DEBUG : OneDrive root 'rclone-test-wozehug0vego': File to upload is small (0 bytes), uploading instead of streaming
2026/03/12 01:56:49 DEBUG : dir/file1: Starting singlepart upload
2026/03/12 01:56:51 DEBUG : dir/file1: size = 0 OK
2026/03/12 01:56:51 DEBUG : dir/file1: quickxor = 0000000000000000000000000000000000000000 OK
2026/03/12 01:56:51 DEBUG : dir/file1: Size and quickxor of src and dst objects identical
2026/03/12 01:56:51 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK
2026/03/12 01:56:51 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/03/12 01:56:51 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:56:51 DEBUG : dir: Looking for writers
2026/03/12 01:56:51 DEBUG : file1: reading active writers
2026/03/12 01:56:51 DEBUG : Looking for writers
2026/03/12 01:56:51 DEBUG : dir: reading active writers
2026/03/12 01:56:51 DEBUG : >WaitForWriters: 
2026/03/12 01:56:52 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:56:52 DEBUG : dir: Looking for writers
2026/03/12 01:56:52 DEBUG : file1: reading active writers
2026/03/12 01:56:52 DEBUG : Looking for writers
2026/03/12 01:56:52 DEBUG : dir: reading active writers
2026/03/12 01:56:52 DEBUG : >WaitForWriters: 
=== RUN   TestFileSetModTime/cache=off,open=true,write=true
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:56:54 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4Nzc0MTQyNzAwMDAwOzE1NTEyNTA2Nzc7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:56:54 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:56:55 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:56:55 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:56:57 DEBUG : dir/file1: Open: flags=O_WRONLY|O_TRUNC
2026/03/12 01:56:57 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err=<nil>
2026/03/12 01:56:57 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/03/12 01:56:57 DEBUG : OneDrive root 'rclone-test-wozehug0vego': File to upload is small (5 bytes), uploading instead of streaming
2026/03/12 01:56:57 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:56:57 DEBUG : dir/file1: Uploading segment 0/5 size 5
2026/03/12 01:56:58 DEBUG : dir/file1: size = 5 OK
2026/03/12 01:56:58 DEBUG : dir/file1: quickxor = 6828031bd8f00600000000000500000000000000 OK
2026/03/12 01:56:58 DEBUG : dir/file1: Size and quickxor of src and dst objects identical
2026/03/12 01:56:58 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK
2026/03/12 01:56:58 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/03/12 01:56:58 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:56:58 DEBUG : dir: Looking for writers
2026/03/12 01:56:58 DEBUG : file1: reading active writers
2026/03/12 01:56:58 DEBUG : Looking for writers
2026/03/12 01:56:58 DEBUG : dir: reading active writers
2026/03/12 01:56:58 DEBUG : >WaitForWriters: 
2026/03/12 01:56:59 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:56:59 DEBUG : dir: Looking for writers
2026/03/12 01:56:59 DEBUG : file1: reading active writers
2026/03/12 01:56:59 DEBUG : Looking for writers
2026/03/12 01:56:59 DEBUG : dir: reading active writers
2026/03/12 01:56:59 DEBUG : >WaitForWriters: 
=== RUN   TestFileSetModTime/cache=full,open=false,write=false
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:57:00 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4Nzc0MjA0MDcwMDAwOzE1NTEyNTA3NDQ7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:57:00 DEBUG : OneDrive root 'rclone-test-wozehug0vego': vfs cache: root is "/home/rclone/.cache/rclone"
2026/03/12 01:57:00 DEBUG : OneDrive root 'rclone-test-wozehug0vego': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:00 DEBUG : OneDrive root 'rclone-test-wozehug0vego': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:00 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:00 DEBUG : Config file has changed externally - reloading
2026/03/12 01:57:00 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/03/12 01:57:00 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-wozehug0vego" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:00 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:00 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/03/12 01:57:00 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestOneDrive/rclone-test-wozehug0vego" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:00 INFO  : OneDrive root 'rclone-test-wozehug0vego': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2026/03/12 01:57:01 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:57:01 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:57:03 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK
2026/03/12 01:57:03 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:57:03 DEBUG : dir: Looking for writers
2026/03/12 01:57:03 DEBUG : file1: reading active writers
2026/03/12 01:57:03 DEBUG : Looking for writers
2026/03/12 01:57:03 DEBUG : dir: reading active writers
2026/03/12 01:57:03 DEBUG : >WaitForWriters: 
2026/03/12 01:57:03 DEBUG : OneDrive root 'rclone-test-wozehug0vego': vfs cache: cleaner exiting
=== RUN   TestFileSetModTime/cache=full,open=true,write=false
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:57:05 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4Nzc0MjUyMDAwMDAwOzE1NTEyNTA4MDk7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:57:05 DEBUG : OneDrive root 'rclone-test-wozehug0vego': vfs cache: root is "/home/rclone/.cache/rclone"
2026/03/12 01:57:05 DEBUG : OneDrive root 'rclone-test-wozehug0vego': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:05 DEBUG : OneDrive root 'rclone-test-wozehug0vego': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:05 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:05 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/03/12 01:57:05 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-wozehug0vego" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:05 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:05 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/03/12 01:57:05 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestOneDrive/rclone-test-wozehug0vego" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:05 INFO  : OneDrive root 'rclone-test-wozehug0vego': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2026/03/12 01:57:06 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:57:06 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:57:08 DEBUG : dir/file1: Open: flags=O_WRONLY
2026/03/12 01:57:08 DEBUG : dir/file1: newRWFileHandle: 
2026/03/12 01:57:08 DEBUG : dir/file1: >newRWFileHandle: err=<nil>
2026/03/12 01:57:08 DEBUG : dir/file1: >Open: fd=dir/file1 (rw), err=<nil>
2026/03/12 01:57:08 DEBUG : dir/file1(0x10040cadd980): close: 
2026/03/12 01:57:08 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK
2026/03/12 01:57:08 DEBUG : dir/file1(0x10040cadd980): >close: err=<nil>
2026/03/12 01:57:08 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:57:08 DEBUG : dir: Looking for writers
2026/03/12 01:57:08 DEBUG : file1: reading active writers
2026/03/12 01:57:08 DEBUG : Looking for writers
2026/03/12 01:57:08 DEBUG : dir: reading active writers
2026/03/12 01:57:08 DEBUG : >WaitForWriters: 
2026/03/12 01:57:09 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:57:09 DEBUG : dir: Looking for writers
2026/03/12 01:57:09 DEBUG : file1: reading active writers
2026/03/12 01:57:09 DEBUG : Looking for writers
2026/03/12 01:57:09 DEBUG : dir: reading active writers
2026/03/12 01:57:09 DEBUG : >WaitForWriters: 
2026/03/12 01:57:09 DEBUG : OneDrive root 'rclone-test-wozehug0vego': vfs cache: cleaner exiting
=== RUN   TestFileSetModTime/cache=full,open=true,write=true
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:57:10 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4Nzc0MzA0NjMwMDAwOzE1NTEyNTA4ODk7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:57:10 DEBUG : OneDrive root 'rclone-test-wozehug0vego': vfs cache: root is "/home/rclone/.cache/rclone"
2026/03/12 01:57:10 DEBUG : OneDrive root 'rclone-test-wozehug0vego': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:10 DEBUG : OneDrive root 'rclone-test-wozehug0vego': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:10 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:10 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/03/12 01:57:10 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-wozehug0vego" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:10 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:10 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/03/12 01:57:10 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestOneDrive/rclone-test-wozehug0vego" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:10 INFO  : OneDrive root 'rclone-test-wozehug0vego': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2026/03/12 01:57:11 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:57:11 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:57:13 DEBUG : dir/file1: Open: flags=O_WRONLY
2026/03/12 01:57:13 DEBUG : dir/file1: newRWFileHandle: 
2026/03/12 01:57:13 DEBUG : dir/file1: >newRWFileHandle: err=<nil>
2026/03/12 01:57:13 DEBUG : dir/file1: >Open: fd=dir/file1 (rw), err=<nil>
2026/03/12 01:57:13 DEBUG : dir/file1(0x10040d5683c0): _writeAt: size=5, off=0
2026/03/12 01:57:13 DEBUG : dir/file1(0x10040d5683c0): openPending: 
2026/03/12 01:57:13 DEBUG : dir/file1: vfs cache: checking remote fingerprint "14,2001-02-03 04:05:06 +0000 UTC,6648031bca1003108ce10d6eae4319dc40873900" against cached fingerprint ""
2026/03/12 01:57:13 DEBUG : dir/file1: vfs cache: truncate to size=14
2026/03/12 01:57:13 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/03/12 01:57:13 DEBUG : dir/file1(0x10040d5683c0): >openPending: err=<nil>
2026/03/12 01:57:13 DEBUG : dir/file1(0x10040d5683c0): >_writeAt: n=5, err=<nil>
2026/03/12 01:57:13 DEBUG : dir/file1: vfs cache: setting modification time to 2011-12-25 12:59:59.123456789 +0000 UTC
2026/03/12 01:57:13 DEBUG : dir/file1(0x10040d5683c0): close: 
2026/03/12 01:57:13 DEBUG : vfs cache: looking for range={Pos:0 Size:14} in [{Pos:0 Size:5}] - present false
2026/03/12 01:57:13 DEBUG : dir/file1: ChunkedReader.RangeSeek from -1 to 5 length -1
2026/03/12 01:57:13 DEBUG : dir/file1: ChunkedReader.Read at -1 length 32768 chunkOffset 5 chunkSize 134217728
2026/03/12 01:57:13 DEBUG : dir/file1: ChunkedReader.openRange at 5 length 134217728
2026/03/12 01:57:13 DEBUG : dir/file1: vfs cache: setting modification time to 2011-12-25 12:59:59.123456789 +0000 UTC
2026/03/12 01:57:13 INFO  : dir/file1: vfs cache: queuing for upload in 100ms
2026/03/12 01:57:13 DEBUG : dir/file1(0x10040d5683c0): >close: err=<nil>
2026/03/12 01:57:13 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:57:13 DEBUG : dir: Looking for writers
2026/03/12 01:57:13 DEBUG : file1: reading active writers
2026/03/12 01:57:13 DEBUG : Looking for writers
2026/03/12 01:57:13 DEBUG : dir: reading active writers
2026/03/12 01:57:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms
2026/03/12 01:57:13 DEBUG : dir: Looking for writers
2026/03/12 01:57:13 DEBUG : file1: reading active writers
2026/03/12 01:57:13 DEBUG : Looking for writers
2026/03/12 01:57:13 DEBUG : dir: reading active writers
2026/03/12 01:57:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms
2026/03/12 01:57:13 DEBUG : dir: Looking for writers
2026/03/12 01:57:13 DEBUG : file1: reading active writers
2026/03/12 01:57:13 DEBUG : Looking for writers
2026/03/12 01:57:13 DEBUG : dir: reading active writers
2026/03/12 01:57:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms
2026/03/12 01:57:13 DEBUG : dir: Looking for writers
2026/03/12 01:57:13 DEBUG : file1: reading active writers
2026/03/12 01:57:13 DEBUG : Looking for writers
2026/03/12 01:57:13 DEBUG : dir: reading active writers
2026/03/12 01:57:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms
2026/03/12 01:57:13 DEBUG : dir/file1: vfs cache: starting upload
2026/03/12 01:57:13 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:57:13 DEBUG : dir: Looking for writers
2026/03/12 01:57:13 DEBUG : file1: reading active writers
2026/03/12 01:57:13 DEBUG : Looking for writers
2026/03/12 01:57:13 DEBUG : dir: reading active writers
2026/03/12 01:57:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms
2026/03/12 01:57:14 DEBUG : dir: Looking for writers
2026/03/12 01:57:14 DEBUG : file1: reading active writers
2026/03/12 01:57:14 DEBUG : Looking for writers
2026/03/12 01:57:14 DEBUG : dir: reading active writers
2026/03/12 01:57:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms
2026/03/12 01:57:14 DEBUG : dir: Looking for writers
2026/03/12 01:57:14 DEBUG : file1: reading active writers
2026/03/12 01:57:14 DEBUG : Looking for writers
2026/03/12 01:57:14 DEBUG : dir: reading active writers
2026/03/12 01:57:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms
2026/03/12 01:57:14 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:57:15 DEBUG : dir/file1: size = 14 OK
2026/03/12 01:57:15 DEBUG : dir/file1: quickxor = 6828031bd8f006108ce10d6eae4319dc40873900 OK
2026/03/12 01:57:15 INFO  : dir/file1: Copied (replaced existing)
2026/03/12 01:57:15 DEBUG : dir/file1: vfs cache: fingerprint now "14,2011-12-25 12:59:59 +0000 UTC,6828031bd8f006108ce10d6eae4319dc40873900"
2026/03/12 01:57:15 DEBUG : dir/file1: vfs cache: writeback object to VFS layer
2026/03/12 01:57:15 DEBUG : dir/file1: Not setting pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC as it is already set
2026/03/12 01:57:15 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/03/12 01:57:15 INFO  : dir/file1: vfs cache: upload succeeded try #1
2026/03/12 01:57:15 DEBUG : dir: Looking for writers
2026/03/12 01:57:15 DEBUG : file1: reading active writers
2026/03/12 01:57:15 DEBUG : Looking for writers
2026/03/12 01:57:15 DEBUG : dir: reading active writers
2026/03/12 01:57:15 DEBUG : >WaitForWriters: 
2026/03/12 01:57:15 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:57:15 DEBUG : dir: Looking for writers
2026/03/12 01:57:15 DEBUG : file1: reading active writers
2026/03/12 01:57:15 DEBUG : Looking for writers
2026/03/12 01:57:15 DEBUG : dir: reading active writers
2026/03/12 01:57:15 DEBUG : >WaitForWriters: 
2026/03/12 01:57:15 DEBUG : OneDrive root 'rclone-test-wozehug0vego': vfs cache: cleaner exiting
--- PASS: TestFileSetModTime (39.57s)
    --- PASS: TestFileSetModTime/cache=off,open=false,write=false (8.66s)
    --- PASS: TestFileSetModTime/cache=off,open=true,write=false (8.14s)
    --- PASS: TestFileSetModTime/cache=off,open=true,write=true (6.11s)
    --- PASS: TestFileSetModTime/cache=full,open=false,write=false (4.83s)
    --- PASS: TestFileSetModTime/cache=full,open=true,write=false (5.28s)
    --- PASS: TestFileSetModTime/cache=full,open=true,write=true (6.55s)
=== RUN   TestFileOpenRead
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:57:17 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4Nzc0MzcxMDcwMDAwOzE1NTEyNTA5NjE7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:57:17 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:57:17 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:57:18 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:57:19 DEBUG : dir/file1: Open: flags=O_RDONLY
2026/03/12 01:57:19 DEBUG : dir/file1: >Open: fd=dir/file1 (r), err=<nil>
2026/03/12 01:57:19 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728
2026/03/12 01:57:20 DEBUG : dir/file1: ChunkedReader.Read at 0 length 512 chunkOffset 0 chunkSize 134217728
2026/03/12 01:57:20 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:57:20 DEBUG : dir: Looking for writers
2026/03/12 01:57:20 DEBUG : file1: reading active writers
2026/03/12 01:57:20 DEBUG : Looking for writers
2026/03/12 01:57:20 DEBUG : dir: reading active writers
2026/03/12 01:57:20 DEBUG : >WaitForWriters: 
--- PASS: TestFileOpenRead (4.55s)
=== RUN   TestFileOpenReadUnknownSize
2026/03/12 01:57:21 INFO  : Mock file system at root: poll-interval is not supported by this remote
2026/03/12 01:57:21 NOTICE: Mock file system at root: --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:57:21 DEBUG : file.txt: ChunkedReader.openRange at 0 length 134217728
2026/03/12 01:57:21 DEBUG : file.txt: ChunkedReader.Read at 0 length 4096 chunkOffset 0 chunkSize 134217728
    file_test.go:223: gotContents = "file contents"
2026/03/12 01:57:21 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:57:21 DEBUG : Looking for writers
2026/03/12 01:57:21 DEBUG : file.txt: reading active writers
2026/03/12 01:57:21 DEBUG : >WaitForWriters: 
--- PASS: TestFileOpenReadUnknownSize (0.00s)
=== RUN   TestFileOpenWrite
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:57:21 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4Nzc0NDE2MjAwMDAwOzE1NTEyNTEwMjM7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:57:21 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:57:22 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:57:23 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:57:24 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/03/12 01:57:24 DEBUG : OneDrive root 'rclone-test-wozehug0vego': File to upload is small (25 bytes), uploading instead of streaming
2026/03/12 01:57:24 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:57:25 DEBUG : dir/file1: Uploading segment 0/25 size 25
2026/03/12 01:57:25 DEBUG : dir/file1: size = 25 OK
2026/03/12 01:57:25 DEBUG : dir/file1: quickxor = 954e6302251b5e744b33bcf26f301bca00023794 OK
2026/03/12 01:57:25 DEBUG : dir/file1: Size and quickxor of src and dst objects identical
2026/03/12 01:57:25 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/03/12 01:57:25 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:57:25 DEBUG : dir: Looking for writers
2026/03/12 01:57:25 DEBUG : file1: reading active writers
2026/03/12 01:57:25 DEBUG : Looking for writers
2026/03/12 01:57:25 DEBUG : dir: reading active writers
2026/03/12 01:57:25 DEBUG : >WaitForWriters: 
--- PASS: TestFileOpenWrite (5.48s)
=== RUN   TestFileRemove
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:57:27 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4Nzc0NDcwODcwMDAwOzE1NTEyNTEwOTM7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:57:27 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:57:28 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:57:28 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:57:30 DEBUG : dir/file1: Remove: 
2026/03/12 01:57:30 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/03/12 01:57:30 DEBUG : dir/file1: >Remove: err=<nil>
2026/03/12 01:57:30 DEBUG : dir/file1: Remove: 
2026/03/12 01:57:30 DEBUG : dir/file1: >Remove: err=Read only file system
2026/03/12 01:57:30 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:57:30 DEBUG : dir: Looking for writers
2026/03/12 01:57:30 DEBUG : Looking for writers
2026/03/12 01:57:30 DEBUG : dir: reading active writers
2026/03/12 01:57:30 DEBUG : >WaitForWriters: 
--- PASS: TestFileRemove (4.98s)
=== RUN   TestFileRemoveAll
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:57:32 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4Nzc0NTIwMTcwMDAwOzE1NTEyNTExNDU7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:57:32 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:57:32 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:57:33 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:57:34 DEBUG : dir/file1: Remove: 
2026/03/12 01:57:35 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/03/12 01:57:35 DEBUG : dir/file1: >Remove: err=<nil>
2026/03/12 01:57:35 DEBUG : dir/file1: Remove: 
2026/03/12 01:57:35 DEBUG : dir/file1: >Remove: err=Read only file system
2026/03/12 01:57:35 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:57:35 DEBUG : dir: Looking for writers
2026/03/12 01:57:35 DEBUG : Looking for writers
2026/03/12 01:57:35 DEBUG : dir: reading active writers
2026/03/12 01:57:35 DEBUG : >WaitForWriters: 
--- PASS: TestFileRemoveAll (4.54s)
=== RUN   TestFileOpen
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:57:36 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4Nzc0NTY2MjcwMDAwOzE1NTEyNTEyMDc7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:57:36 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:57:37 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:57:38 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:57:39 DEBUG : dir/file1: Open: flags=O_RDONLY
2026/03/12 01:57:39 DEBUG : dir/file1: >Open: fd=dir/file1 (r), err=<nil>
2026/03/12 01:57:39 DEBUG : dir/file1: Open: flags=O_WRONLY
2026/03/12 01:57:39 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err=<nil>
2026/03/12 01:57:39 DEBUG : dir/file1: Open: flags=O_RDWR
2026/03/12 01:57:39 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err=<nil>
2026/03/12 01:57:39 DEBUG : dir/file1: Open: flags=0x3
2026/03/12 01:57:39 DEBUG : dir/file1: Can't figure out how to open with flags: 0x3
2026/03/12 01:57:39 DEBUG : dir/file1: >Open: fd=<nil>, err=permission denied
2026/03/12 01:57:39 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:57:39 DEBUG : dir: Looking for writers
2026/03/12 01:57:39 DEBUG : file1: reading active writers
2026/03/12 01:57:39 DEBUG : Looking for writers
2026/03/12 01:57:39 DEBUG : dir: reading active writers
2026/03/12 01:57:39 DEBUG : >WaitForWriters: 
--- PASS: TestFileOpen (4.49s)
=== RUN   TestFileRename
=== RUN   TestFileRename/off,forceCache=false
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:57:41 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4Nzc0NjExMjMwMDAwOzE1NTEyNTEyODk7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:57:41 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:57:41 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:57:42 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:57:43 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:57:43 DEBUG : dir: Looking for writers
2026/03/12 01:57:43 DEBUG : file1: reading active writers
2026/03/12 01:57:43 DEBUG : Looking for writers
2026/03/12 01:57:43 DEBUG : dir: reading active writers
2026/03/12 01:57:43 DEBUG : >WaitForWriters: 
2026/03/12 01:57:45 INFO  : dir/file1: Moved (server-side) to: newLeaf
2026/03/12 01:57:45 DEBUG : newLeaf: Updating file with newLeaf 0x10040cb7ea80
2026/03/12 01:57:45 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/03/12 01:57:45 DEBUG : Added virtual directory entry vAddFile: "newLeaf"
2026/03/12 01:57:46 INFO  : newLeaf: Moved (server-side) to: dir/file1
2026/03/12 01:57:46 DEBUG : dir/file1: Updating file with dir/file1 0x10040cb7ea80
2026/03/12 01:57:46 DEBUG : Added virtual directory entry vDel: "newLeaf"
2026/03/12 01:57:46 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/03/12 01:57:47 DEBUG : dir/file1: Open: flags=O_WRONLY|O_TRUNC
2026/03/12 01:57:47 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err=<nil>
2026/03/12 01:57:47 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/03/12 01:57:47 DEBUG : dir/file1: File is currently open, delaying rename 0x10040cb7ea80
2026/03/12 01:57:47 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/03/12 01:57:47 DEBUG : Added virtual directory entry vAddFile: "newLeaf"
2026/03/12 01:57:47 DEBUG : OneDrive root 'rclone-test-wozehug0vego': File to upload is small (25 bytes), uploading instead of streaming
2026/03/12 01:57:47 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:57:47 DEBUG : dir/file1: Uploading segment 0/25 size 25
2026/03/12 01:57:48 DEBUG : dir/file1: size = 25 OK
2026/03/12 01:57:48 DEBUG : dir/file1: quickxor = 954e6302251b5e744b33bcf26f301bca00023794 OK
2026/03/12 01:57:48 DEBUG : dir/file1: Size and quickxor of src and dst objects identical
2026/03/12 01:57:48 DEBUG : Added virtual directory entry vAddFile: "newLeaf"
2026/03/12 01:57:48 DEBUG : newLeaf: Running delayed rename now
2026/03/12 01:57:49 INFO  : dir/file1: Moved (server-side) to: newLeaf
2026/03/12 01:57:49 DEBUG : newLeaf: Updating file with newLeaf 0x10040cb7ea80
2026/03/12 01:57:49 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:57:49 DEBUG : dir: Looking for writers
2026/03/12 01:57:49 DEBUG : Looking for writers
2026/03/12 01:57:49 DEBUG : dir: reading active writers
2026/03/12 01:57:49 DEBUG : newLeaf: reading active writers
2026/03/12 01:57:49 DEBUG : >WaitForWriters: 
2026/03/12 01:57:49 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:57:49 DEBUG : dir: Looking for writers
2026/03/12 01:57:49 DEBUG : Looking for writers
2026/03/12 01:57:49 DEBUG : dir: reading active writers
2026/03/12 01:57:49 DEBUG : newLeaf: reading active writers
2026/03/12 01:57:49 DEBUG : >WaitForWriters: 
=== RUN   TestFileRename/minimal,forceCache=false
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:57:51 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Next delta token is: NDslMjM0OyUyMzE7MztkNjJlOThjNi0zM2NlLTRmYTUtYmNmOS04NGRkODc2NTE5ZmY7NjM5MDg4Nzc0NzA5MTAwMDAwOzE1NTEyNTEzOTE7JTIzOyUyMzslMjMwOyUyMw
2026/03/12 01:57:51 NOTICE: OneDrive root 'rclone-test-wozehug0vego': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/03/12 01:57:51 DEBUG : OneDrive root 'rclone-test-wozehug0vego': vfs cache: root is "/home/rclone/.cache/rclone"
2026/03/12 01:57:51 DEBUG : OneDrive root 'rclone-test-wozehug0vego': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:51 DEBUG : OneDrive root 'rclone-test-wozehug0vego': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:51 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:51 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/03/12 01:57:51 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-wozehug0vego" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:51 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:51 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/03/12 01:57:51 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestOneDrive/rclone-test-wozehug0vego" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestOneDrive/rclone-test-wozehug0vego"
2026/03/12 01:57:51 INFO  : OneDrive root 'rclone-test-wozehug0vego': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2026/03/12 01:57:52 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:57:52 DEBUG : dir/file1: Uploading segment 0/14 size 14
2026/03/12 01:57:53 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:57:53 DEBUG : dir: Looking for writers
2026/03/12 01:57:53 DEBUG : file1: reading active writers
2026/03/12 01:57:53 DEBUG : Looking for writers
2026/03/12 01:57:53 DEBUG : dir: reading active writers
2026/03/12 01:57:53 DEBUG : >WaitForWriters: 
2026/03/12 01:57:55 INFO  : dir/file1: Moved (server-side) to: newLeaf
2026/03/12 01:57:55 DEBUG : newLeaf: Updating file with newLeaf 0x10040ce4fd40
2026/03/12 01:57:55 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/03/12 01:57:55 DEBUG : Added virtual directory entry vAddFile: "newLeaf"
2026/03/12 01:57:57 INFO  : newLeaf: Moved (server-side) to: dir/file1
2026/03/12 01:57:57 DEBUG : dir/file1: Updating file with dir/file1 0x10040ce4fd40
2026/03/12 01:57:57 DEBUG : Added virtual directory entry vDel: "newLeaf"
2026/03/12 01:57:57 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/03/12 01:57:57 DEBUG : dir/file1: Open: flags=O_WRONLY|O_TRUNC
2026/03/12 01:57:57 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err=<nil>
2026/03/12 01:57:57 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/03/12 01:57:57 DEBUG : dir/file1: File is currently open, delaying rename 0x10040ce4fd40
2026/03/12 01:57:57 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/03/12 01:57:57 DEBUG : Added virtual directory entry vAddFile: "newLeaf"
2026/03/12 01:57:57 DEBUG : OneDrive root 'rclone-test-wozehug0vego': File to upload is small (25 bytes), uploading instead of streaming
2026/03/12 01:57:57 DEBUG : dir/file1: Starting multipart upload
2026/03/12 01:57:58 DEBUG : dir/file1: Uploading segment 0/25 size 25
2026/03/12 01:57:58 DEBUG : dir/file1: size = 25 OK
2026/03/12 01:57:58 DEBUG : dir/file1: quickxor = 954e6302251b5e744b33bcf26f301bca00023794 OK
2026/03/12 01:57:58 DEBUG : dir/file1: Size and quickxor of src and dst objects identical
2026/03/12 01:57:58 DEBUG : Added virtual directory entry vAddFile: "newLeaf"
2026/03/12 01:57:58 DEBUG : newLeaf: Running delayed rename now
2026/03/12 01:57:59 INFO  : dir/file1: Moved (server-side) to: newLeaf
2026/03/12 01:57:59 DEBUG : newLeaf: Updating file with newLeaf 0x10040ce4fd40
2026/03/12 01:57:59 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:57:59 DEBUG : dir: Looking for writers
2026/03/12 01:57:59 DEBUG : Looking for writers
2026/03/12 01:57:59 DEBUG : dir: reading active writers
2026/03/12 01:57:59 DEBUG : newLeaf: reading active writers
2026/03/12 01:57:59 DEBUG : >WaitForWriters: 
2026/03/12 01:58:00 DEBUG : WaitForWriters: timeout=30s
2026/03/12 01:58:00 DEBUG : dir: Looking for writers
2026/03/12 01:58:00 DEBUG : Looking for writers
2026/03/12 01:58:00 DEBUG : newLeaf: reading active writers
2026/03/12 01:58:00 DEBUG : dir: reading active writers
2026/03/12 01:58:00 DEBUG : >WaitForWriters: 
2026/03/12 01:58:00 DEBUG : OneDrive root 'rclone-test-wozehug0vego': vfs cache: cleaner exiting
=== RUN   TestFileRename/minimal,forceCache=true
    run.go:185: Remote "OneDrive root 'rclone-test-wozehug0vego'", Local "Local file system at /tmp/rclone1419377252", Modify Window "1s"
2026/03/12 01:58:31 ERROR : OneDrive root 'rclone-test-wozehug0vego': Could not get first deltaLink: UnknownError: 
2026/03/12 02:04:20 DEBUG : forgetting directory cache
2026/03/12 02:04:20 DEBUG : dir: forgetting directory cache
2026/03/12 02:04:29 DEBUG : forgetting directory cache
2026/03/12 02:04:29 DEBUG : dir: forgetting directory cache
2026/03/12 02:04:29 DEBUG : dir/subdir: forgetting directory cache
2026/03/12 02:04:34 DEBUG : forgetting directory cache
2026/03/12 02:04:34 DEBUG : dir: forgetting directory cache
2026/03/12 02:04:39 DEBUG : dir: forgetting directory cache
2026/03/12 02:04:39 DEBUG : forgetting directory cache
2026/03/12 02:04:39 DEBUG : dir: forgetting directory cache
2026/03/12 02:04:48 DEBUG : forgetting directory cache
2026/03/12 02:04:48 DEBUG : dir: forgetting directory cache
2026/03/12 02:04:57 DEBUG : dir: forgetting directory cache
2026/03/12 02:04:57 DEBUG : forgetting directory cache
2026/03/12 02:04:57 DEBUG : dir: forgetting directory cache
2026/03/12 02:04:57 DEBUG : fil: forgetting directory cache
2026/03/12 02:04:57 DEBUG : fil/a: forgetting directory cache
2026/03/12 02:04:57 DEBUG : fil/a/b: forgetting directory cache
2026/03/12 02:05:05 DEBUG : dir: forgetting directory cache
2026/03/12 02:05:05 DEBUG : forgetting directory cache
2026/03/12 02:05:05 DEBUG : dir: forgetting directory cache
2026/03/12 02:05:09 DEBUG : forgetting directory cache
2026/03/12 02:05:09 DEBUG : dir: forgetting directory cache
2026/03/12 02:05:17 DEBUG : dir/subdir: forgetting directory cache
2026/03/12 02:05:21 DEBUG : dir/virtualDir2: forgetting directory cache
2026/03/12 02:05:21 DEBUG : dir: forgetting directory cache
2026/03/12 02:05:21 DEBUG : dir/virtualDir: forgetting directory cache
2026/03/12 02:05:21 DEBUG : forgetting directory cache
2026/03/12 02:05:21 DEBUG : dir: forgetting directory cache
2026/03/12 02:05:21 DEBUG : dir/virtualDir: forgetting directory cache
2026/03/12 02:05:27 DEBUG : dir: forgetting directory cache
2026/03/12 02:05:27 DEBUG : forgetting directory cache
2026/03/12 02:05:27 DEBUG : dir: forgetting directory cache
2026/03/12 02:05:31 DEBUG : forgetting directory cache
2026/03/12 02:05:31 DEBUG : dir: forgetting directory cache
2026/03/12 02:05:31 DEBUG : dir: Removed virtual directory entry vAddFile: "potato"
2026/03/12 02:05:38 DEBUG : forgetting directory cache
2026/03/12 02:05:38 DEBUG : dir: forgetting directory cache
2026/03/12 02:05:38 DEBUG : dir/sub: forgetting directory cache
2026/03/12 02:05:38 DEBUG : dir: Removed virtual directory entry vAddDir: "sub"
2026/03/12 02:05:45 DEBUG : forgetting directory cache
2026/03/12 02:05:45 DEBUG : dir: forgetting directory cache
2026/03/12 02:05:45 DEBUG : dir/sub: forgetting directory cache
2026/03/12 02:05:45 DEBUG : dir/sub/subsub: forgetting directory cache
2026/03/12 02:05:45 DEBUG : dir/sub: Removed virtual directory entry vAddDir: "subsub"
2026/03/12 02:05:45 DEBUG : dir: Removed virtual directory entry vAddDir: "sub"
2026/03/12 02:05:54 DEBUG : forgetting directory cache
2026/03/12 02:05:54 DEBUG : Removed virtual directory entry vDel: "dir"
2026/03/12 02:05:54 DEBUG : dir: forgetting directory cache
2026/03/12 02:05:54 DEBUG : dir: Removed virtual directory entry vDel: "file1"
2026/03/12 02:05:59 DEBUG : forgetting directory cache
2026/03/12 02:05:59 DEBUG : Removed virtual directory entry vDel: "dir"
2026/03/12 02:05:59 DEBUG : dir: forgetting directory cache
2026/03/12 02:05:59 DEBUG : dir: Removed virtual directory entry vDel: "file1"
2026/03/12 02:06:03 DEBUG : forgetting directory cache
2026/03/12 02:06:03 DEBUG : dir: forgetting directory cache
2026/03/12 02:06:03 DEBUG : dir: Removed virtual directory entry vDel: "file1"
2026/03/12 02:06:08 DEBUG : forgetting directory cache
2026/03/12 02:06:08 DEBUG : dir3: forgetting directory cache
2026/03/12 02:06:08 DEBUG : dir3: Removed virtual directory entry vDel: "file1"
2026/03/12 02:06:08 DEBUG : dir3: Removed virtual directory entry vAddFile: "file3"
2026/03/12 02:06:08 DEBUG : renamed empty directory: forgetting directory cache
2026/03/12 02:06:08 DEBUG : Removed virtual directory entry vDel: "empty directory"
2026/03/12 02:06:08 DEBUG : Removed virtual directory entry vAddDir: "renamed empty directory"
2026/03/12 02:06:08 DEBUG : Removed virtual directory entry vDel: "dir"
2026/03/12 02:06:08 DEBUG : Removed virtual directory entry vAddDir: "dir2"
2026/03/12 02:06:08 DEBUG : Removed virtual directory entry vDel: "file2"
2026/03/12 02:06:24 DEBUG : forgetting directory cache
2026/03/12 02:06:24 DEBUG : dir: forgetting directory cache
2026/03/12 02:06:24 DEBUG : dir: forgetting directory cache
2026/03/12 02:06:24 DEBUG : dir/sub: forgetting directory cache
2026/03/12 02:06:24 DEBUG : dir/sub: forgetting directory cache
2026/03/12 02:06:24 DEBUG : dir/sub: forgetting directory cache
2026/03/12 02:06:24 DEBUG : dir/sub: Removed virtual directory entry vAddFile: "file0"
2026/03/12 02:06:28 DEBUG : forgetting directory cache
2026/03/12 02:06:31 DEBUG : forgetting directory cache
2026/03/12 02:06:31 DEBUG : dir: forgetting directory cache
2026/03/12 02:06:31 DEBUG : dir: Removed virtual directory entry vAddFile: "file1.metadata"
2026/03/12 02:06:31 DEBUG : Removed virtual directory entry vAddFile: "dir.metadata"
2026/03/12 02:06:35 DEBUG : forgetting directory cache
2026/03/12 02:06:35 DEBUG : dir: forgetting directory cache
2026/03/12 02:06:40 DEBUG : forgetting directory cache
2026/03/12 02:06:40 DEBUG : dir: forgetting directory cache
2026/03/12 02:06:49 DEBUG : forgetting directory cache
2026/03/12 02:06:49 DEBUG : dir: forgetting directory cache
2026/03/12 02:06:49 DEBUG : dir: Removed virtual directory entry vAddFile: "file1"
2026/03/12 02:06:56 DEBUG : forgetting directory cache
2026/03/12 02:06:56 DEBUG : dir: forgetting directory cache
2026/03/12 02:06:56 DEBUG : dir: Removed virtual directory entry vAddFile: "file1"
2026/03/12 02:07:02 DEBUG : forgetting directory cache
2026/03/12 02:07:02 DEBUG : dir: forgetting directory cache
2026/03/12 02:07:08 DEBUG : forgetting directory cache
2026/03/12 02:07:08 DEBUG : dir: forgetting directory cache
2026/03/12 02:07:13 DEBUG : forgetting directory cache
2026/03/12 02:07:13 DEBUG : dir: forgetting directory cache
2026/03/12 02:07:13 DEBUG : dir: Removed virtual directory entry vAddFile: "file1"
2026/03/12 02:07:19 DEBUG : forgetting directory cache
2026/03/12 02:07:19 DEBUG : dir: forgetting directory cache
2026/03/12 02:07:21 DEBUG : forgetting directory cache
2026/03/12 02:07:24 DEBUG : forgetting directory cache
2026/03/12 02:07:24 DEBUG : dir: forgetting directory cache
2026/03/12 02:07:24 DEBUG : dir: Removed virtual directory entry vAddFile: "file1"
2026/03/12 02:07:29 DEBUG : forgetting directory cache
2026/03/12 02:07:29 DEBUG : dir: forgetting directory cache
2026/03/12 02:07:29 DEBUG : dir: Removed virtual directory entry vDel: "file1"
2026/03/12 02:07:34 DEBUG : forgetting directory cache
2026/03/12 02:07:34 DEBUG : dir: forgetting directory cache
2026/03/12 02:07:34 DEBUG : dir: Removed virtual directory entry vDel: "file1"
2026/03/12 02:07:39 DEBUG : forgetting directory cache
2026/03/12 02:07:39 DEBUG : dir: forgetting directory cache
2026/03/12 02:07:43 DEBUG : forgetting directory cache
2026/03/12 02:07:43 DEBUG : dir: forgetting directory cache
2026/03/12 02:07:43 DEBUG : dir: Removed virtual directory entry vDel: "file1"
2026/03/12 02:07:43 DEBUG : Removed virtual directory entry vAddFile: "newLeaf"
2026/03/12 02:07:53 DEBUG : forgetting directory cache
2026/03/12 02:07:53 DEBUG : dir: forgetting directory cache
2026/03/12 02:07:53 DEBUG : dir: Removed virtual directory entry vDel: "file1"
2026/03/12 02:07:53 DEBUG : Removed virtual directory entry vAddFile: "newLeaf"
2026/03/12 02:08:01 DEBUG : forgetting directory cache
2026/03/12 02:15:22 DEBUG : forgetting directory cache
2026/03/12 02:15:22 DEBUG : dir: forgetting directory cache
2026/03/12 02:15:22 DEBUG : dir/virtualDir: forgetting directory cache
2026/03/12 02:15:22 DEBUG : dir: forgetting directory cache
2026/03/12 02:15:22 DEBUG : dir/virtualDir: forgetting directory cache
2026/03/12 02:15:54 DEBUG : forgetting directory cache
2026/03/12 02:15:59 DEBUG : forgetting directory cache
2026/03/12 02:25:22 DEBUG : dir: forgetting directory cache
2026/03/12 02:25:22 DEBUG : dir/virtualDir: forgetting directory cache
2026/03/12 02:25:22 DEBUG : forgetting directory cache
2026/03/12 02:25:22 DEBUG : dir: forgetting directory cache
2026/03/12 02:25:22 DEBUG : dir/virtualDir: forgetting directory cache
2026/03/12 02:35:22 DEBUG : forgetting directory cache
2026/03/12 02:35:22 DEBUG : dir: forgetting directory cache
2026/03/12 02:35:22 DEBUG : dir/virtualDir: forgetting directory cache
2026/03/12 02:35:22 DEBUG : dir: forgetting directory cache
2026/03/12 02:35:22 DEBUG : dir/virtualDir: forgetting directory cache
2026/03/12 02:37:33 DEBUG : OneDrive root 'rclone-test-wozehug0vego': Background refresher detected expired token but no uploads in progress - doing nothing
2026/03/12 02:45:22 DEBUG : forgetting directory cache
2026/03/12 02:45:22 DEBUG : dir: forgetting directory cache
2026/03/12 02:45:22 DEBUG : dir/virtualDir: forgetting directory cache
2026/03/12 02:45:22 DEBUG : dir: forgetting directory cache
2026/03/12 02:45:22 DEBUG : dir/virtualDir: forgetting directory cache
panic: test timed out after 1h0m0s
	running tests:
		TestFileRename (56m35s)
		TestFileRename/minimal,forceCache=true (56m14s)

goroutine 2926 [running]:
testing.(*M).startAlarm.func1()
	/usr/local/go/src/testing/testing.go:2802 +0x34b
created by time.goFunc
	/usr/local/go/src/time/sleep.go:215 +0x2d

goroutine 1 [chan receive, 56 minutes]:
testing.(*T).Run(0x10040cb99208, {0x2a1c4d7?, 0x10040cf07ae8?}, 0x2b9a298)
	/usr/local/go/src/testing/testing.go:2109 +0x4e5
testing.runTests.func1(0x10040cb99208)
	/usr/local/go/src/testing/testing.go:2585 +0x37
testing.tRunner(0x10040cb99208, 0x10040cf07c10)
	/usr/local/go/src/testing/testing.go:2036 +0xea
testing.runTests({0x2a3fac9, 0x18}, {0x2a4f895, 0x1c}, 0x10040cfdf6b0, {0x4640d40, 0x59, 0x59}, {0xc264a896031659d8, 0x3466cb96928, ...})
	/usr/local/go/src/testing/testing.go:2583 +0x505
testing.(*M).Run(0x10040cd2e460)
	/usr/local/go/src/testing/testing.go:2443 +0x6ac
github.com/rclone/rclone/fstest.TestMain(0x10040cd2e460)
	/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:74 +0xa6
github.com/rclone/rclone/vfs.TestMain(...)
	/home/rclone/go/src/github.com/rclone/rclone/vfs/vfs_test.go:36
main.main()
	_testmain.go:226 +0xa6

goroutine 24 [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 +0xa7

goroutine 23 [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.func1.1 in goroutine 1
	/usr/local/go/src/os/signal/signal.go:152 +0x1f

goroutine 25 [select, 17 minutes]:
github.com/rclone/rclone/lib/oauthutil.(*Renew).renewOnExpiry(0x10040cf200c0)
	/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 +0xe5

goroutine 57 [chan receive, 60 minutes]:
github.com/rclone/rclone/lib/atexit.Register.func1.1()
	/home/rclone/go/src/github.com/rclone/rclone/lib/atexit/atexit.go:45 +0x29
created by github.com/rclone/rclone/lib/atexit.Register.func1 in goroutine 36
	/home/rclone/go/src/github.com/rclone/rclone/lib/atexit/atexit.go:44 +0x68

goroutine 2898 [chan send, 56 minutes]:
github.com/rclone/rclone/vfs.New({0x2bfe620, 0x10040cab7080}, 0x10040ce10c40)
	/home/rclone/go/src/github.com/rclone/rclone/vfs/vfs.go:240 +0x6b8
github.com/rclone/rclone/vfs.newTestVFSOpt(0x10040d48c488, 0x10040ce10c40)
	/home/rclone/go/src/github.com/rclone/rclone/vfs/vfs_test.go:50 +0x5f
github.com/rclone/rclone/vfs.fileCreate(0x10040d48c488, 0x98?)
	/home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:25 +0xa5
github.com/rclone/rclone/vfs.testFileRename(0x10040d48c488, 0xb3?, 0x1, 0x1)
	/home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:302 +0x54
github.com/rclone/rclone/vfs.TestFileRename.func1(0x10040d48c488?)
	/home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:413 +0x1f
testing.tRunner(0x10040d48c488, 0x10040cd8f8e0)
	/usr/local/go/src/testing/testing.go:2036 +0xea
created by testing.(*T).Run in goroutine 2588
	/usr/local/go/src/testing/testing.go:2101 +0x4c5

goroutine 2588 [chan receive, 56 minutes]:
testing.(*T).Run(0x10040cd4a488, {0x10040d34f968?, 0x10040cf01f30?}, 0x10040cd8f8e0)
	/usr/local/go/src/testing/testing.go:2109 +0x4e5
github.com/rclone/rclone/vfs.TestFileRename(0x10040cd4a488)
	/home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:412 +0x119
testing.tRunner(0x10040cd4a488, 0x2b9a298)
	/usr/local/go/src/testing/testing.go:2036 +0xea
created by testing.(*T).Run in goroutine 1
	/usr/local/go/src/testing/testing.go:2101 +0x4c5
"./vfs.test -test.v -test.timeout 1h0m0s -remote TestOneDrive: -verbose" - Finished ERROR in 1h0m1.020622421s (try 1/5): exit status 2: Failed []