"./vfs.test -test.v -test.timeout 2h0m0s -remote TestDrime: -verbose" - Starting (try 1/5) 2026/03/08 05:12:03 DEBUG : Creating backend with remote "TestDrime:rclone-test-koximur2goxi" 2026/03/08 05:12:03 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/03/08 05:12:04 DEBUG : Creating backend with remote "/tmp/rclone1125122348" === RUN TestDirHandleMethods run.go:185: Remote "drime root 'rclone-test-koximur2goxi'", Local "Local file system at /tmp/rclone1125122348", Modify Window "876000h0m0s" 2026/03/08 05:12:04 INFO : drime root 'rclone-test-koximur2goxi': poll-interval is not supported by this remote 2026/03/08 05:12:08 DEBUG : WaitForWriters: timeout=30s 2026/03/08 05:12:08 DEBUG : dir: Looking for writers 2026/03/08 05:12:08 DEBUG : Looking for writers 2026/03/08 05:12:08 DEBUG : dir: reading active writers 2026/03/08 05:12:08 DEBUG : >WaitForWriters: --- PASS: TestDirHandleMethods (5.92s) === RUN TestDirHandleReaddir run.go:185: Remote "drime root 'rclone-test-koximur2goxi'", Local "Local file system at /tmp/rclone1125122348", Modify Window "876000h0m0s" 2026/03/08 05:12:10 INFO : drime root 'rclone-test-koximur2goxi': poll-interval is not supported by this remote 2026/03/08 05:12:16 DEBUG : WaitForWriters: timeout=30s 2026/03/08 05:12:16 DEBUG : dir/subdir: Looking for writers 2026/03/08 05:12:16 DEBUG : dir: Looking for writers 2026/03/08 05:12:16 DEBUG : file1: reading active writers 2026/03/08 05:12:16 DEBUG : file2: reading active writers 2026/03/08 05:12:16 DEBUG : subdir: reading active writers 2026/03/08 05:12:16 DEBUG : Looking for writers 2026/03/08 05:12:16 DEBUG : dir: reading active writers 2026/03/08 05:12:16 DEBUG : >WaitForWriters: run.go:130: removing dir "dir/subdir" failed - try 1/3: directory not empty --- PASS: TestDirHandleReaddir (10.06s) === RUN TestDirHandleReaddirnames run.go:185: Remote "drime root 'rclone-test-koximur2goxi'", Local "Local file system at /tmp/rclone1125122348", Modify Window "876000h0m0s" 2026/03/08 05:12:20 INFO : drime root 'rclone-test-koximur2goxi': poll-interval is not supported by this remote 2026/03/08 05:12:24 DEBUG : WaitForWriters: timeout=30s 2026/03/08 05:12:24 DEBUG : dir: Looking for writers 2026/03/08 05:12:24 DEBUG : file1: reading active writers 2026/03/08 05:12:24 DEBUG : Looking for writers 2026/03/08 05:12:24 DEBUG : dir: reading active writers 2026/03/08 05:12:24 DEBUG : >WaitForWriters: --- PASS: TestDirHandleReaddirnames (5.66s) === RUN TestDirMethods run.go:185: Remote "drime root 'rclone-test-koximur2goxi'", Local "Local file system at /tmp/rclone1125122348", Modify Window "876000h0m0s" 2026/03/08 05:12:26 INFO : drime root 'rclone-test-koximur2goxi': poll-interval is not supported by this remote 2026/03/08 05:12:29 DEBUG : WaitForWriters: timeout=30s 2026/03/08 05:12:29 DEBUG : dir: Looking for writers 2026/03/08 05:12:29 DEBUG : Looking for writers 2026/03/08 05:12:29 DEBUG : dir: reading active writers 2026/03/08 05:12:29 DEBUG : >WaitForWriters: --- PASS: TestDirMethods (5.02s) === RUN TestDirForgetAll run.go:185: Remote "drime root 'rclone-test-koximur2goxi'", Local "Local file system at /tmp/rclone1125122348", Modify Window "876000h0m0s" 2026/03/08 05:12:31 INFO : drime root 'rclone-test-koximur2goxi': poll-interval is not supported by this remote 2026/03/08 05:12:34 DEBUG : dir: forgetting directory cache 2026/03/08 05:12:34 DEBUG : forgetting directory cache 2026/03/08 05:12:34 DEBUG : dir: forgetting directory cache 2026/03/08 05:12:34 DEBUG : WaitForWriters: timeout=30s 2026/03/08 05:12:34 DEBUG : Looking for writers 2026/03/08 05:12:34 DEBUG : >WaitForWriters: run.go:130: removing dir "dir" failed - try 1/3: directory not empty --- PASS: TestDirForgetAll (6.43s) === RUN TestDirForgetPath run.go:185: Remote "drime root 'rclone-test-koximur2goxi'", Local "Local file system at /tmp/rclone1125122348", Modify Window "876000h0m0s" 2026/03/08 05:12:37 INFO : drime root 'rclone-test-koximur2goxi': poll-interval is not supported by this remote 2026/03/08 05:12:40 DEBUG : ForgetPath: relativePath="dir/notfound", type=1 2026/03/08 05:12:40 DEBUG : dir: invalidating directory cache 2026/03/08 05:12:40 DEBUG : >ForgetPath: 2026/03/08 05:12:40 DEBUG : ForgetPath: relativePath="dir", type=0 2026/03/08 05:12:40 DEBUG : invalidating directory cache 2026/03/08 05:12:40 DEBUG : dir: forgetting directory cache 2026/03/08 05:12:40 DEBUG : >ForgetPath: 2026/03/08 05:12:40 DEBUG : ForgetPath: relativePath="not/in/cache", type=0 2026/03/08 05:12:40 DEBUG : >ForgetPath: 2026/03/08 05:12:40 DEBUG : WaitForWriters: timeout=30s 2026/03/08 05:12:40 DEBUG : dir: Looking for writers 2026/03/08 05:12:40 DEBUG : Looking for writers 2026/03/08 05:12:40 DEBUG : dir: reading active writers 2026/03/08 05:12:40 DEBUG : >WaitForWriters: --- PASS: TestDirForgetPath (4.49s) === RUN TestDirWalk run.go:185: Remote "drime root 'rclone-test-koximur2goxi'", Local "Local file system at /tmp/rclone1125122348", Modify Window "876000h0m0s" 2026/03/08 05:12:42 INFO : drime root 'rclone-test-koximur2goxi': poll-interval is not supported by this remote 2026/03/08 05:12:48 DEBUG : forgetting directory cache 2026/03/08 05:12:48 DEBUG : dir: forgetting directory cache 2026/03/08 05:12:49 DEBUG : WaitForWriters: timeout=30s 2026/03/08 05:12:49 DEBUG : dir: Looking for writers 2026/03/08 05:12:49 DEBUG : fil/a/b: Looking for writers 2026/03/08 05:12:49 DEBUG : fil/a: Looking for writers 2026/03/08 05:12:49 DEBUG : b: reading active writers 2026/03/08 05:12:49 DEBUG : fil: Looking for writers 2026/03/08 05:12:49 DEBUG : a: reading active writers 2026/03/08 05:12:49 DEBUG : Looking for writers 2026/03/08 05:12:49 DEBUG : dir: reading active writers 2026/03/08 05:12:49 DEBUG : fil: reading active writers 2026/03/08 05:12:49 DEBUG : >WaitForWriters: run.go:130: removing dir "fil/a/b" failed - try 1/3: directory not empty --- PASS: TestDirWalk (12.62s) === RUN TestDirSetModTime run.go:185: Remote "drime root 'rclone-test-koximur2goxi'", Local "Local file system at /tmp/rclone1125122348", Modify Window "876000h0m0s" 2026/03/08 05:12:55 INFO : drime root 'rclone-test-koximur2goxi': poll-interval is not supported by this remote 2026/03/08 05:12:57 DEBUG : WaitForWriters: timeout=30s 2026/03/08 05:12:57 DEBUG : dir: Looking for writers 2026/03/08 05:12:57 DEBUG : Looking for writers 2026/03/08 05:12:57 DEBUG : dir: reading active writers 2026/03/08 05:12:57 DEBUG : >WaitForWriters: --- PASS: TestDirSetModTime (3.99s) === RUN TestDirStat run.go:185: Remote "drime root 'rclone-test-koximur2goxi'", Local "Local file system at /tmp/rclone1125122348", Modify Window "876000h0m0s" 2026/03/08 05:12:59 INFO : drime root 'rclone-test-koximur2goxi': poll-interval is not supported by this remote 2026/03/08 05:13:01 DEBUG : WaitForWriters: timeout=30s 2026/03/08 05:13:01 DEBUG : dir: Looking for writers 2026/03/08 05:13:01 DEBUG : file1: reading active writers 2026/03/08 05:13:01 DEBUG : Looking for writers 2026/03/08 05:13:01 DEBUG : dir: reading active writers 2026/03/08 05:13:01 DEBUG : >WaitForWriters: run.go:130: removing dir "dir" failed - try 1/3: directory not empty --- PASS: TestDirStat (6.88s) === RUN TestDirReadDirAll run.go:185: Remote "drime root 'rclone-test-koximur2goxi'", Local "Local file system at /tmp/rclone1125122348", Modify Window "876000h0m0s" 2026/03/08 05:13:05 INFO : drime root 'rclone-test-koximur2goxi': poll-interval is not supported by this remote === RUN TestDirReadDirAll/Virtual 2026/03/08 05:13:12 DEBUG : dir: Added virtual directory entry vAddFile: "virtualFile" 2026/03/08 05:13:12 DEBUG : dir: Added virtual directory entry vAddDir: "virtualDir" 2026/03/08 05:13:12 DEBUG : dir: Added virtual directory entry vDel: "file2" 2026/03/08 05:13:12 DEBUG : dir: Added virtual directory entry vDel: "subdir" 2026/03/08 05:13:15 DEBUG : dir: invalidating directory cache 2026/03/08 05:13:16 DEBUG : dir: Removed virtual directory entry vAddDir: "virtualDir" 2026/03/08 05:13:16 DEBUG : dir: Removed virtual directory entry vDel: "file2" 2026/03/08 05:13:16 DEBUG : dir: Removed virtual directory entry vDel: "subdir" 2026/03/08 05:13:16 DEBUG : dir/file1: Reset virtual modtime 2026/03/08 05:13:16 DEBUG : dir: Removed virtual directory entry vAddFile: "virtualFile" 2026/03/08 05:13:16 DEBUG : dir/virtualFile: Reset virtual modtime dir_test.go:250: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:250 /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:300 Error: Not equal: expected: []string{"file1,14,false", "virtualDir,0,true", "virtualFile,20,false"} actual : []string{"file1,14,false", "file2,15,false", "subdir,0,true", "virtualDir,0,true", "virtualFile,20,false"} Diff: --- Expected +++ Actual @@ -1,3 +1,5 @@ -([]string) (len=3) { +([]string) (len=5) { (string) (len=14) "file1,14,false", + (string) (len=14) "file2,15,false", + (string) (len=13) "subdir,0,true", (string) (len=17) "virtualDir,0,true", Test: TestDirReadDirAll/Virtual 2026/03/08 05:13:16 DEBUG : dir: Added virtual directory entry vAddFile: "virtualFile2" 2026/03/08 05:13:16 DEBUG : dir: Added virtual directory entry vAddDir: "virtualDir2" 2026/03/08 05:13:16 DEBUG : dir: Added virtual directory entry vDel: "file1" dir_test.go:250: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:250 /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:313 Error: Not equal: expected: []string{"virtualDir,0,true", "virtualDir2,0,true", "virtualFile,20,false", "virtualFile2,100,false"} actual : []string{"file2,15,false", "subdir,0,true", "virtualDir,0,true", "virtualDir2,0,true", "virtualFile,20,false", "virtualFile2,100,false"} Diff: --- Expected +++ Actual @@ -1,2 +1,4 @@ -([]string) (len=4) { +([]string) (len=6) { + (string) (len=14) "file2,15,false", + (string) (len=13) "subdir,0,true", (string) (len=17) "virtualDir,0,true", Test: TestDirReadDirAll/Virtual 2026/03/08 05:13:16 DEBUG : dir: invalidating directory cache 2026/03/08 05:13:16 DEBUG : dir: Removed virtual directory entry vAddDir: "virtualDir2" 2026/03/08 05:13:16 DEBUG : dir: Removed virtual directory entry vDel: "file1" 2026/03/08 05:13:16 DEBUG : dir/virtualFile: Reset virtual modtime 2026/03/08 05:13:16 DEBUG : forgetting directory cache 2026/03/08 05:13:16 DEBUG : dir: forgetting directory cache 2026/03/08 05:13:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 05:13:16 DEBUG : WaitForWriters: timeout=30s 2026/03/08 05:13:16 DEBUG : dir/virtualDir: Looking for writers 2026/03/08 05:13:16 DEBUG : dir: Looking for writers 2026/03/08 05:13:16 DEBUG : file1: reading active writers 2026/03/08 05:13:16 DEBUG : virtualFile: reading active writers 2026/03/08 05:13:16 DEBUG : virtualDir: reading active writers 2026/03/08 05:13:16 DEBUG : virtualFile2: reading active writers 2026/03/08 05:13:16 DEBUG : Looking for writers 2026/03/08 05:13:16 DEBUG : dir: reading active writers 2026/03/08 05:13:16 DEBUG : >WaitForWriters: === NAME TestDirReadDirAll run.go:130: removing dir "dir/virtualDir" failed - try 1/3: directory not empty --- FAIL: TestDirReadDirAll (16.19s) --- FAIL: TestDirReadDirAll/Virtual (3.48s) === RUN TestDirOpen run.go:185: Remote "drime root 'rclone-test-koximur2goxi'", Local "Local file system at /tmp/rclone1125122348", Modify Window "876000h0m0s" 2026/03/08 05:13:22 INFO : drime root 'rclone-test-koximur2goxi': poll-interval is not supported by this remote 2026/03/08 05:13:24 ERROR : dir/: Can only open directories read only 2026/03/08 05:13:24 DEBUG : WaitForWriters: timeout=30s 2026/03/08 05:13:24 DEBUG : dir: Looking for writers 2026/03/08 05:13:24 DEBUG : Looking for writers 2026/03/08 05:13:24 DEBUG : dir: reading active writers 2026/03/08 05:13:24 DEBUG : >WaitForWriters: run.go:130: removing dir "dir" failed - try 1/3: directory not empty --- PASS: TestDirOpen (6.92s) === RUN TestDirCreate run.go:185: Remote "drime root 'rclone-test-koximur2goxi'", Local "Local file system at /tmp/rclone1125122348", Modify Window "876000h0m0s" 2026/03/08 05:13:29 INFO : drime root 'rclone-test-koximur2goxi': poll-interval is not supported by this remote 2026/03/08 05:13:31 DEBUG : dir/potato: Open: flags=O_WRONLY|O_CREATE 2026/03/08 05:13:31 DEBUG : dir: Added virtual directory entry vAddFile: "potato" 2026/03/08 05:13:31 DEBUG : dir/potato: >Open: fd=dir/potato (w), err= 2026/03/08 05:13:31 DEBUG : dir: Added virtual directory entry vAddFile: "potato" 2026/03/08 05:13:31 DEBUG : drime root 'rclone-test-koximur2goxi': File to upload is small (5 bytes), uploading instead of streaming 2026/03/08 05:13:33 DEBUG : dir/potato: size = 5 OK 2026/03/08 05:13:33 NOTICE: drime root 'rclone-test-koximur2goxi': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2026/03/08 05:13:33 DEBUG : dir/potato: Size of src and dst objects identical 2026/03/08 05:13:33 DEBUG : dir: Added virtual directory entry vAddFile: "potato" 2026/03/08 05:13:33 DEBUG : WaitForWriters: timeout=30s 2026/03/08 05:13:33 DEBUG : dir: Looking for writers 2026/03/08 05:13:33 DEBUG : file1: reading active writers 2026/03/08 05:13:33 DEBUG : potato: reading active writers 2026/03/08 05:13:33 DEBUG : Looking for writers 2026/03/08 05:13:33 DEBUG : dir: reading active writers 2026/03/08 05:13:33 DEBUG : >WaitForWriters: --- PASS: TestDirCreate (6.17s) === RUN TestDirMkdir run.go:185: Remote "drime root 'rclone-test-koximur2goxi'", Local "Local file system at /tmp/rclone1125122348", Modify Window "876000h0m0s" 2026/03/08 05:13:35 INFO : drime root 'rclone-test-koximur2goxi': poll-interval is not supported by this remote 2026/03/08 05:13:38 DEBUG : dir: Added virtual directory entry vAddDir: "sub" 2026/03/08 05:13:39 DEBUG : WaitForWriters: timeout=30s 2026/03/08 05:13:39 DEBUG : dir/sub: Looking for writers 2026/03/08 05:13:39 DEBUG : dir: Looking for writers 2026/03/08 05:13:39 DEBUG : sub: reading active writers 2026/03/08 05:13:39 DEBUG : file1: reading active writers 2026/03/08 05:13:39 DEBUG : Looking for writers 2026/03/08 05:13:39 DEBUG : dir: reading active writers 2026/03/08 05:13:39 DEBUG : >WaitForWriters: --- PASS: TestDirMkdir (6.78s) === RUN TestDirMkdirSub run.go:185: Remote "drime root 'rclone-test-koximur2goxi'", Local "Local file system at /tmp/rclone1125122348", Modify Window "876000h0m0s" 2026/03/08 05:13:41 INFO : drime root 'rclone-test-koximur2goxi': poll-interval is not supported by this remote 2026/03/08 05:13:44 DEBUG : dir: Added virtual directory entry vAddDir: "sub" 2026/03/08 05:13:45 DEBUG : dir/sub: Added virtual directory entry vAddDir: "subsub" 2026/03/08 05:13:47 DEBUG : WaitForWriters: timeout=30s 2026/03/08 05:13:47 DEBUG : dir/sub/subsub: Looking for writers 2026/03/08 05:13:47 DEBUG : dir/sub: Looking for writers 2026/03/08 05:13:47 DEBUG : subsub: reading active writers 2026/03/08 05:13:47 DEBUG : dir: Looking for writers 2026/03/08 05:13:47 DEBUG : file1: reading active writers 2026/03/08 05:13:47 DEBUG : sub: reading active writers 2026/03/08 05:13:47 DEBUG : Looking for writers 2026/03/08 05:13:47 DEBUG : dir: reading active writers 2026/03/08 05:13:47 DEBUG : >WaitForWriters: --- PASS: TestDirMkdirSub (8.96s) === RUN TestDirRemove run.go:185: Remote "drime root 'rclone-test-koximur2goxi'", Local "Local file system at /tmp/rclone1125122348", Modify Window "876000h0m0s" 2026/03/08 05:13:50 INFO : drime root 'rclone-test-koximur2goxi': poll-interval is not supported by this remote 2026/03/08 05:13:54 ERROR : dir/: Dir.Remove not empty 2026/03/08 05:13:54 DEBUG : dir/file1: Remove: 2026/03/08 05:13:54 DEBUG : dir: Added virtual directory entry vDel: "file1" 2026/03/08 05:13:54 DEBUG : dir/file1: >Remove: err= 2026/03/08 05:13:54 ERROR : dir/: Dir.Remove failed to remove directory: directory not empty dir_test.go:456: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:456 Error: Received unexpected error: directory not empty Test: TestDirRemove 2026/03/08 05:13:54 DEBUG : WaitForWriters: timeout=30s 2026/03/08 05:13:54 DEBUG : dir: Looking for writers 2026/03/08 05:13:54 DEBUG : Looking for writers 2026/03/08 05:13:54 DEBUG : dir: reading active writers 2026/03/08 05:13:54 DEBUG : >WaitForWriters: --- FAIL: TestDirRemove (5.83s) === RUN TestDirRemoveAll run.go:185: Remote "drime root 'rclone-test-koximur2goxi'", Local "Local file system at /tmp/rclone1125122348", Modify Window "876000h0m0s" 2026/03/08 05:13:56 INFO : drime root 'rclone-test-koximur2goxi': poll-interval is not supported by this remote 2026/03/08 05:13:59 DEBUG : dir/file1: Remove: 2026/03/08 05:13:59 DEBUG : dir: Added virtual directory entry vDel: "file1" 2026/03/08 05:13:59 DEBUG : dir/file1: >Remove: err= 2026/03/08 05:13:59 ERROR : dir/: Dir.Remove failed to remove directory: directory not empty dir_test.go:481: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:481 Error: Received unexpected error: directory not empty Test: TestDirRemoveAll 2026/03/08 05:13:59 DEBUG : WaitForWriters: timeout=30s 2026/03/08 05:13:59 DEBUG : dir: Looking for writers 2026/03/08 05:13:59 DEBUG : Looking for writers 2026/03/08 05:13:59 DEBUG : dir: reading active writers 2026/03/08 05:13:59 DEBUG : >WaitForWriters: --- FAIL: TestDirRemoveAll (5.66s) === RUN TestDirRemoveName run.go:185: Remote "drime root 'rclone-test-koximur2goxi'", Local "Local file system at /tmp/rclone1125122348", Modify Window "876000h0m0s" 2026/03/08 05:14:02 INFO : drime root 'rclone-test-koximur2goxi': poll-interval is not supported by this remote 2026/03/08 05:14:05 DEBUG : dir/file1: Remove: 2026/03/08 05:14:05 DEBUG : dir: Added virtual directory entry vDel: "file1" 2026/03/08 05:14:05 DEBUG : dir/file1: >Remove: err= 2026/03/08 05:14:06 DEBUG : WaitForWriters: timeout=30s 2026/03/08 05:14:06 DEBUG : dir: Looking for writers 2026/03/08 05:14:06 DEBUG : Looking for writers 2026/03/08 05:14:06 DEBUG : dir: reading active writers 2026/03/08 05:14:06 DEBUG : >WaitForWriters: --- PASS: TestDirRemoveName (5.30s) === RUN TestDirRename run.go:185: Remote "drime root 'rclone-test-koximur2goxi'", Local "Local file system at /tmp/rclone1125122348", Modify Window "876000h0m0s" 2026/03/08 05:14:07 INFO : drime root 'rclone-test-koximur2goxi': poll-interval is not supported by this remote 2026/03/08 05:14:13 ERROR : dir/not found: Dir.Rename error: file does not exist 2026/03/08 05:22:08 DEBUG : forgetting directory cache 2026/03/08 05:22:08 DEBUG : dir: forgetting directory cache 2026/03/08 05:22:08 DEBUG : dir: forgetting directory cache 2026/03/08 05:22:15 DEBUG : forgetting directory cache 2026/03/08 05:22:15 DEBUG : dir: forgetting directory cache 2026/03/08 05:22:15 DEBUG : dir/subdir: forgetting directory cache 2026/03/08 05:22:23 DEBUG : forgetting directory cache 2026/03/08 05:22:23 DEBUG : dir: forgetting directory cache 2026/03/08 05:22:29 DEBUG : forgetting directory cache 2026/03/08 05:22:29 DEBUG : dir: forgetting directory cache 2026/03/08 05:22:29 DEBUG : dir: forgetting directory cache 2026/03/08 05:22:40 DEBUG : forgetting directory cache 2026/03/08 05:22:40 DEBUG : dir: forgetting directory cache 2026/03/08 05:22:48 DEBUG : forgetting directory cache 2026/03/08 05:22:48 DEBUG : dir: forgetting directory cache 2026/03/08 05:22:48 DEBUG : dir: forgetting directory cache 2026/03/08 05:22:48 DEBUG : fil: forgetting directory cache 2026/03/08 05:22:48 DEBUG : fil/a: forgetting directory cache 2026/03/08 05:22:48 DEBUG : fil/a/b: forgetting directory cache 2026/03/08 05:22:57 DEBUG : dir: forgetting directory cache 2026/03/08 05:22:57 DEBUG : forgetting directory cache 2026/03/08 05:22:57 DEBUG : dir: forgetting directory cache 2026/03/08 05:23:01 DEBUG : forgetting directory cache 2026/03/08 05:23:01 DEBUG : dir: forgetting directory cache 2026/03/08 05:23:12 DEBUG : dir/subdir: forgetting directory cache 2026/03/08 05:23:16 DEBUG : dir/virtualDir2: forgetting directory cache 2026/03/08 05:23:16 DEBUG : dir/subdir: forgetting directory cache 2026/03/08 05:23:16 DEBUG : dir: forgetting directory cache 2026/03/08 05:23:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 05:23:16 DEBUG : forgetting directory cache 2026/03/08 05:23:16 DEBUG : dir: forgetting directory cache 2026/03/08 05:23:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 05:23:24 DEBUG : dir: forgetting directory cache 2026/03/08 05:23:24 DEBUG : forgetting directory cache 2026/03/08 05:23:24 DEBUG : dir: forgetting directory cache 2026/03/08 05:23:31 DEBUG : forgetting directory cache 2026/03/08 05:23:31 DEBUG : dir: forgetting directory cache 2026/03/08 05:23:31 DEBUG : dir: Removed virtual directory entry vAddFile: "potato" 2026/03/08 05:23:37 DEBUG : forgetting directory cache 2026/03/08 05:23:37 DEBUG : dir: forgetting directory cache 2026/03/08 05:23:37 DEBUG : dir/sub: forgetting directory cache 2026/03/08 05:23:37 DEBUG : dir: Removed virtual directory entry vAddDir: "sub" 2026/03/08 05:23:44 DEBUG : forgetting directory cache 2026/03/08 05:23:44 DEBUG : dir: forgetting directory cache 2026/03/08 05:23:44 DEBUG : dir/sub: forgetting directory cache 2026/03/08 05:23:44 DEBUG : dir/sub/subsub: forgetting directory cache 2026/03/08 05:23:44 DEBUG : dir/sub: Removed virtual directory entry vAddDir: "subsub" 2026/03/08 05:23:44 DEBUG : dir: Removed virtual directory entry vAddDir: "sub" 2026/03/08 05:23:53 DEBUG : forgetting directory cache 2026/03/08 05:23:53 DEBUG : dir: forgetting directory cache 2026/03/08 05:23:53 DEBUG : dir: Removed virtual directory entry vDel: "file1" 2026/03/08 05:23:59 DEBUG : forgetting directory cache 2026/03/08 05:23:59 DEBUG : dir: forgetting directory cache 2026/03/08 05:23:59 DEBUG : dir: Removed virtual directory entry vDel: "file1" 2026/03/08 05:24:04 DEBUG : forgetting directory cache 2026/03/08 05:24:04 DEBUG : dir: forgetting directory cache 2026/03/08 05:24:04 DEBUG : dir: Removed virtual directory entry vDel: "file1" 2026/03/08 05:24:10 DEBUG : forgetting directory cache 2026/03/08 05:24:10 DEBUG : dir: forgetting directory cache 2026/03/08 05:33:16 DEBUG : forgetting directory cache 2026/03/08 05:33:16 DEBUG : dir: forgetting directory cache 2026/03/08 05:33:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 05:33:16 DEBUG : dir: forgetting directory cache 2026/03/08 05:33:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 05:43:16 DEBUG : forgetting directory cache 2026/03/08 05:43:16 DEBUG : dir: forgetting directory cache 2026/03/08 05:43:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 05:43:16 DEBUG : dir: forgetting directory cache 2026/03/08 05:43:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 05:53:16 DEBUG : dir: forgetting directory cache 2026/03/08 05:53:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 05:53:16 DEBUG : forgetting directory cache 2026/03/08 05:53:16 DEBUG : dir: forgetting directory cache 2026/03/08 05:53:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 06:03:16 DEBUG : forgetting directory cache 2026/03/08 06:03:16 DEBUG : dir: forgetting directory cache 2026/03/08 06:03:16 DEBUG : dir: forgetting directory cache 2026/03/08 06:03:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 06:03:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 06:13:16 DEBUG : forgetting directory cache 2026/03/08 06:13:16 DEBUG : dir: forgetting directory cache 2026/03/08 06:13:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 06:13:16 DEBUG : dir: forgetting directory cache 2026/03/08 06:13:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 06:23:16 DEBUG : dir: forgetting directory cache 2026/03/08 06:23:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 06:23:16 DEBUG : forgetting directory cache 2026/03/08 06:23:16 DEBUG : dir: forgetting directory cache 2026/03/08 06:23:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 06:33:16 DEBUG : forgetting directory cache 2026/03/08 06:33:16 DEBUG : dir: forgetting directory cache 2026/03/08 06:33:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 06:33:16 DEBUG : dir: forgetting directory cache 2026/03/08 06:33:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 06:43:16 DEBUG : forgetting directory cache 2026/03/08 06:43:16 DEBUG : dir: forgetting directory cache 2026/03/08 06:43:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 06:43:16 DEBUG : dir: forgetting directory cache 2026/03/08 06:43:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 06:53:16 DEBUG : forgetting directory cache 2026/03/08 06:53:16 DEBUG : dir: forgetting directory cache 2026/03/08 06:53:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 06:53:16 DEBUG : dir: forgetting directory cache 2026/03/08 06:53:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 07:03:16 DEBUG : dir: forgetting directory cache 2026/03/08 07:03:16 DEBUG : dir/virtualDir: forgetting directory cache 2026/03/08 07:03:16 DEBUG : forgetting directory cache 2026/03/08 07:03:16 DEBUG : dir: forgetting directory cache 2026/03/08 07:03:16 DEBUG : dir/virtualDir: forgetting directory cache panic: test timed out after 2h0m0s running tests: TestDirRename (1h57m57s) goroutine 814222 [running]: testing.(*M).startAlarm.func1() /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/testing/testing.go:2682 +0x345 created by time.goFunc /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/time/sleep.go:215 +0x2d goroutine 1 [chan receive, 118 minutes]: testing.(*T).Run(0xc0000c8380, {0x29d314c?, 0xc00006bae8?}, 0x2b54158) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/testing/testing.go:2005 +0x485 testing.runTests.func1(0xc0000c8380) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/testing/testing.go:2477 +0x37 testing.tRunner(0xc0000c8380, 0xc00006bc28) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/testing/testing.go:1934 +0xea testing.runTests(0xc000a83f20, {0x456c060, 0x59, 0x59}, {0x856a80?, 0x45ae630?, 0x458a4e0?}) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/testing/testing.go:2475 +0x4b4 testing.(*M).Run(0xc0008575e0) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/testing/testing.go:2337 +0x63a github.com/rclone/rclone/fstest.TestMain(0xc0008575e0) /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:225 +0xa6 goroutine 52 [chan receive, 120 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 51 [syscall, 120 minutes]: os/signal.signal_recv() /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/runtime/sigqueue.go:152 +0x29 os/signal.loop() /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/os/signal/signal_unix.go:23 +0x13 created by os/signal.Notify.func1.1 in goroutine 1 /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/os/signal/signal.go:152 +0x1f goroutine 1346 [select]: net/http.(*Transport).getConn(0xc0005121a0, 0xc000ad2960, {{}, 0x0, {0xc0007c3fc0, 0x5}, {0xc000803320, 0x13}, 0x0}) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/http/transport.go:1520 +0x4ad net/http.(*Transport).roundTrip(0xc0005121a0, 0xc0007b5cc0) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/http/transport.go:685 +0xa54 net/http.(*Transport).RoundTrip(...) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/http/roundtrip.go:33 github.com/rclone/rclone/fs/fshttp.(*Transport).RoundTrip(0xc0004464e0, 0xc0007b5cc0) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:496 +0x34a net/http.send(0xc0007b5cc0, {0x2ec2a40, 0xc0004464e0}, {0xc00006ab01?, 0x708910?, 0x0?}) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/http/client.go:259 +0x5e2 net/http.(*Client).send(0xc0002854a0, 0xc0007b5cc0, {0x41ecf4?, 0x1e?, 0x0?}) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/http/client.go:180 +0x91 net/http.(*Client).do(0xc0002854a0, 0xc0007b5cc0) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/http/client.go:729 +0x9c9 net/http.(*Client).Do(...) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/http/client.go:587 github.com/rclone/rclone/lib/rest.(*Client).Call(0xc0004a8000, {0x2eec1a8, 0x45ae040}, 0xc00006b260) /home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:371 +0xd87 github.com/rclone/rclone/lib/rest.(*Client).callCodec(0xc0004a8000, {0x2eec1a8, 0x45ae040}, 0xc000a142c0?, {0x22f8720?, 0xc00011f200?}, {0x22f8760, 0xc000a10600}, 0x3?, 0x2b55bb0, ...) /home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:579 +0x40b github.com/rclone/rclone/lib/rest.(*Client).CallJSON(...) /home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:522 github.com/rclone/rclone/backend/drime.(*Fs).patch.func1() /home/rclone/go/src/github.com/rclone/rclone/backend/drime/drime.go:794 +0x8d github.com/rclone/rclone/fs.pacerInvoker(0x1, 0xa, 0x50?) /home/rclone/go/src/github.com/rclone/rclone/fs/pacer.go:86 +0x32 github.com/rclone/rclone/lib/pacer.(*Pacer).call(0xc000446540, 0xc0001b4e60, 0xa) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:228 +0xd2 github.com/rclone/rclone/lib/pacer.(*Pacer).Call(0xc000446540, 0xc0001b4e60) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:247 +0x92 github.com/rclone/rclone/backend/drime.(*Fs).patch(0xc000546000, {0x2eec1a8, 0x45ae040}, {0xc00076c030, 0x9}, {0x29b7890, 0x4}, {0xc000b13cf4, 0x4}) /home/rclone/go/src/github.com/rclone/rclone/backend/drime/drime.go:793 +0x387 github.com/rclone/rclone/backend/drime.(*Fs).rename(0xc000546000, {0x2eec1a8, 0x45ae040}, {0xc00076c030, 0x9}, {0xc000b13cf4, 0x4}) /home/rclone/go/src/github.com/rclone/rclone/backend/drime/drime.go:805 +0x96 github.com/rclone/rclone/backend/drime.(*Fs).moveTo(0xc000546000, {0x2eec1a8, 0x45ae040}, {0xc00076c030, 0x9}, {0xc000abdee0, 0x3}, {0xc000b13cf4, 0x4}, {0xc000b125c0, ...}, ...) /home/rclone/go/src/github.com/rclone/rclone/backend/drime/drime.go:865 +0x2c9 github.com/rclone/rclone/backend/drime.(*Fs).DirMove(0xc000546000, {0x2eec1a8, 0x45ae040}, {0x2f04420?, 0xc000546000}, {0xc000abdee0, 0x3}, {0xc000b13cf4?, 0x0?}) /home/rclone/go/src/github.com/rclone/rclone/backend/drime/drime.go:943 +0x125 github.com/rclone/rclone/fs/operations.DirMove({0x2eec1a8, 0x45ae040}, {0x2f04420, 0xc000546000}, {0xc000abdee0, 0x3}, {0xc000b13cf4, 0x4}) /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations.go:2396 +0x123 github.com/rclone/rclone/vfs.(*Dir).Rename(0xc000acd1e0, {0x29b6670, 0x3}, {0x29b76b0, 0x4}, 0xc000acd1e0) /home/rclone/go/src/github.com/rclone/rclone/vfs/dir.go:1223 +0x812 github.com/rclone/rclone/vfs.TestDirRename(0xc000b15c00) /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:537 +0x493 testing.tRunner(0xc000b15c00, 0x2b54158) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/testing/testing.go:1934 +0xea created by testing.(*T).Run in goroutine 1 /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/testing/testing.go:1997 +0x465 goroutine 814237 [IO wait]: internal/poll.runtime_pollWait(0x74487048ca00, 0x77) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/runtime/netpoll.go:351 +0x85 internal/poll.(*pollDesc).wait(0xc000462880?, 0x0?, 0x0) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/internal/poll/fd_poll_runtime.go:84 +0x27 internal/poll.(*pollDesc).waitWrite(...) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/internal/poll/fd_poll_runtime.go:93 internal/poll.(*FD).WaitWrite(...) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/internal/poll/fd_unix.go:685 net.(*netFD).connect(0xc000462880, {0x2eec2c0, 0xc0006a5180}, {0x41ecf4?, 0x4ab873?}, {0x2ec1060?, 0xc0006953c0?}) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/fd_unix.go:130 +0x6b6 net.(*netFD).dial(0xc000462880, {0x2eec2c0, 0xc0006a5180}, {0x2ef4bb0?, 0x0?}, {0x2ef4bb0, 0xc00028b0b0}, 0xc000ae1228?) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/sock_posix.go:124 +0x3bc net.socket({0x2eec2c0, 0xc0006a5180}, {0x29b67ff, 0x3}, 0x2, 0x1, 0xc000ae1538?, 0x0, {0x2ef4bb0, 0x0}, ...) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/sock_posix.go:70 +0x29b net.internetSocket({0x2eec2c0, 0xc0006a5180}, {0x29b67ff, 0x3}, {0x2ef4bb0, 0x0}, {0x2ef4bb0, 0xc00028b0b0}, 0x1, 0x0, ...) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/ipsock_posix.go:167 +0xf8 net.(*sysDialer).doDialTCPProto(0xc0005dd080, {0x2eec2c0, 0xc0006a5180}, 0x0, 0xc00028b0b0, 0x0) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/tcpsock_posix.go:85 +0xe7 net.(*sysDialer).doDialTCP(...) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/tcpsock_posix.go:75 net.(*sysDialer).dialTCP(0x45111c0?, {0x2eec2c0?, 0xc0006a5180?}, 0xc000ae1580?, 0xc000ae1420?) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/tcpsock_posix.go:71 +0x69 net.(*sysDialer).dialSingle(0xc0005dd080, {0x2eec2c0, 0xc0006a5180}, {0x2ed6968, 0xc00028b0b0}) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/dial.go:721 +0x3ce net.(*sysDialer).dialSerial(0xc0005dd080, {0x2eec2c0, 0xc0006a5180}, {0xc000666850?, 0x1, 0x65f73e?}) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/dial.go:686 +0x248 net.(*sysDialer).dialParallel(0x0?, {0x2eec2c0?, 0xc0006a5180?}, {0xc000666850?, 0x254b900?, 0x29b7930?}, {0x0?, 0x29b67ff?, 0x50?}) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/dial.go:587 +0x30a net.(*Dialer).DialContext(0xc0004f8e60, {0x2eec250, 0xc000ad29b0}, {0x29b67ff, 0x3}, {0xc000803320, 0x13}) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/dial.go:578 +0x6a9 github.com/rclone/rclone/fs/fshttp.(*Dialer).DialContext(0xc0004f8e60, {0x2eec250, 0xc000ad29b0}, {0x29b67ff?, 0x74487013ac80?}, {0xc000803320, 0x13}) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:62 +0x125 github.com/rclone/rclone/fs/fshttp.NewTransportCustom.func2({0x2eec250, 0xc000ad29b0}, {0x29b67ff, 0x3}, {0xc000803320, 0x13}) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:269 +0x5c net/http.(*Transport).dial(0xc000682b40?, {0x2eec250?, 0xc000ad29b0?}, {0x29b67ff?, 0x23?}, {0xc000803320?, 0xc00071b0d0?}) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/http/transport.go:1278 +0xd2 net/http.(*Transport).dialConn(0xc0005121a0, {0x2eec250, 0xc000ad29b0}, {{}, 0x0, {0xc0007c3fc0, 0x5}, {0xc000803320, 0x13}, 0x0}) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/http/transport.go:1780 +0x7e5 net/http.(*Transport).dialConnFor(0xc0005121a0, 0xc0004d2210) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/http/transport.go:1615 +0xb8 net/http.(*Transport).startDialConnForLocked.func1() /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/http/transport.go:1597 +0x35 created by net/http.(*Transport).startDialConnForLocked in goroutine 1346 /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/http/transport.go:1596 +0x112 goroutine 1347 [select, 118 minutes]: github.com/rclone/rclone/vfs.(*VFS).signalHandler(0xc000570a00, {0x2eec250, 0xc000a9ab90}) /home/rclone/go/src/github.com/rclone/rclone/vfs/vfs.go:290 +0xc5 created by github.com/rclone/rclone/vfs.New in goroutine 1346 /home/rclone/go/src/github.com/rclone/rclone/vfs/vfs.go:266 +0x808 goroutine 814241 [select]: net.(*netFD).connect.func2() /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/fd_unix.go:107 +0x7a created by net.(*netFD).connect in goroutine 814237 /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.linux-amd64/src/net/fd_unix.go:106 +0x345 "./vfs.test -test.v -test.timeout 2h0m0s -remote TestDrime: -verbose" - Finished ERROR in 2h0m1.096923528s (try 1/5): exit status 2: Failed [TestDirReadDirAll/Virtual TestDirRemove TestDirRemoveAll]