"./vfs.test -test.v -test.timeout 1h0m0s -remote TestSharefile: -verbose -test.run '^(TestDirCreate|TestDirForgetAll|TestDirForgetPath|TestDirHandleMethods|TestDirHandleReaddir|TestDirHandleReaddirnames|TestDirMethods|TestDirMkdir|TestDirMkdirSub|TestDirOpen|TestDirReadDirAll|TestDirRemove|TestDirRemoveAll|TestDirRemoveName|TestDirRename|TestDirSetModTime|TestDirStat|TestDirWalk|TestFileMethods|TestFileOpen|TestFileOpenRead|TestFileOpenWrite|TestFileReadAtNonZeroLength|TestFileReadAtZeroLength|TestFileRemove|TestFileRemoveAll|TestFileRename|TestFileSetModTime|TestRWFileHandleFlushRead|TestRWFileHandleMethodsRead|TestRWFileHandleMethodsWrite|TestRWFileHandleReadAt|TestRWFileHandleReleaseRead|TestRWFileHandleSeek|TestRWFileHandleSizeCreateExisting|TestRWFileHandleSizeTruncateExisting|TestRWFileHandleWriteAt|TestRWFileHandleWriteNoWrite|TestRWFileModTimeWithOpenWriters|TestRcGetVFS|TestReadFileHandleFlush|TestReadFileHandleMethods|TestReadFileHandleReadAt|TestReadFileHandleRelease|TestReadFileHandleSeek|TestVFSNew|TestVFSOpenFile|TestVFSRename|TestVFSStat|TestVFSStatParent|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleRelease|TestWriteFileHandleWriteAt|TestWriteFileModTimeWithOpenWriters)$/^(full,forceCache=false|minimal,forceCache=false|minimal,forceCache=true|off,forceCache=false|writes,forceCache=false|writes,forceCache=true)$'" - Starting (try 5/5) 2020/11/03 05:57:24 DEBUG : Creating backend with remote "TestSharefile:rclone-test-qitorax1dopocit5wihumur0" 2020/11/03 05:57:25 DEBUG : Creating backend with remote "/tmp/rclone593088746" === RUN TestDirHandleMethods run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:25 INFO : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': poll-interval is not supported by this remote run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirHandleMethods (2.28s) === RUN TestDirHandleReaddir run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:27 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:57:29 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:57:29 DEBUG : : Looking for writers 2020/11/03 05:57:29 DEBUG : >WaitForWriters: --- FAIL: TestDirHandleReaddir (2.60s) === RUN TestDirHandleReaddirnames run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:30 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirHandleReaddirnames (1.97s) === RUN TestDirMethods run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:32 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirMethods (1.02s) === RUN TestDirForgetAll run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:33 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirForgetAll (0.95s) === RUN TestDirForgetPath run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:34 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirForgetPath (1.18s) === RUN TestDirWalk run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:35 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirWalk (0.69s) === RUN TestDirSetModTime run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:36 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirSetModTime (1.22s) === RUN TestDirStat run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:37 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirStat (1.16s) === RUN TestDirReadDirAll run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:38 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:57:39 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:57:39 DEBUG : : Looking for writers 2020/11/03 05:57:39 DEBUG : >WaitForWriters: --- FAIL: TestDirReadDirAll (1.64s) === RUN TestDirOpen run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:40 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirOpen (1.66s) === RUN TestDirCreate run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:42 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirCreate (0.88s) === RUN TestDirMkdir run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:42 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirMkdir (1.80s) === RUN TestDirMkdirSub run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:44 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirMkdirSub (0.66s) === RUN TestDirRemove run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:45 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirRemove (1.12s) === RUN TestDirRemoveAll run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:46 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirRemoveAll (0.97s) === RUN TestDirRemoveName run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:47 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirRemoveName (0.77s) === RUN TestDirRename run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:48 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirRename (1.18s) === RUN TestFileMethods run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:49 INFO : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': poll-interval is not supported by this remote run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestFileMethods (0.90s) === RUN TestFileSetModTime run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:50 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestFileSetModTime (1.09s) === RUN TestFileOpenRead run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:51 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestFileOpenRead (1.12s) === RUN TestFileOpenWrite run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:52 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestFileOpenWrite (1.15s) === RUN TestFileRemove run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:53 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestFileRemove (1.35s) === RUN TestFileRemoveAll run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:55 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestFileRemoveAll (0.68s) === RUN TestFileOpen run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:55 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestFileOpen (1.20s) === RUN TestFileRename === RUN TestFileRename/off,forceCache=false run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:56 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int === RUN TestFileRename/minimal,forceCache=false run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:57:59 INFO : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': poll-interval is not supported by this remote 2020/11/03 05:57:59 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestSharefile/rclone-test-qitorax1dopocit5wihumur0" 2020/11/03 05:57:59 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestSharefile/rclone-test-qitorax1dopocit5wihumur0" 2020/11/03 05:57:59 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestSharefile/rclone-test-qitorax1dopocit5wihumur0" 2020/11/03 05:57:59 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int === RUN TestFileRename/minimal,forceCache=true run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:58:00 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int === RUN TestFileRename/writes,forceCache=false run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:58:02 INFO : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': poll-interval is not supported by this remote 2020/11/03 05:58:02 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestSharefile/rclone-test-qitorax1dopocit5wihumur0" 2020/11/03 05:58:02 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestSharefile/rclone-test-qitorax1dopocit5wihumur0" 2020/11/03 05:58:02 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int === RUN TestFileRename/writes,forceCache=true run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:58:03 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int === RUN TestFileRename/full,forceCache=false run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:58:04 INFO : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': poll-interval is not supported by this remote 2020/11/03 05:58:04 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestSharefile/rclone-test-qitorax1dopocit5wihumur0" 2020/11/03 05:58:04 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestSharefile/rclone-test-qitorax1dopocit5wihumur0" 2020/11/03 05:58:04 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestFileRename (8.86s) --- FAIL: TestFileRename/off,forceCache=false (2.38s) --- FAIL: TestFileRename/minimal,forceCache=false (1.42s) --- FAIL: TestFileRename/minimal,forceCache=true (1.46s) --- FAIL: TestFileRename/writes,forceCache=false (0.86s) --- FAIL: TestFileRename/writes,forceCache=true (1.10s) --- FAIL: TestFileRename/full,forceCache=false (1.64s) === RUN TestRcGetVFS rc_test.go:29: Error Trace: rc_test.go:29 Error: "more than one VFS active - need \"fs\" parameter" does not contain "no VFS active" Test: TestRcGetVFS run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:58:05 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache rc_test.go:36: Error Trace: rc_test.go:36 Error: Received unexpected error: more than one VFS active - need "fs" parameter github.com/rclone/rclone/vfs.getVFS /home/rclone/go/src/github.com/rclone/rclone/vfs/rc.go:36 github.com/rclone/rclone/vfs.TestRcGetVFS /home/rclone/go/src/github.com/rclone/rclone/vfs/rc_test.go:35 testing.tRunner /usr/local/go/src/testing/testing.go:1123 runtime.goexit /usr/local/go/src/runtime/asm_amd64.s:1374 Test: TestRcGetVFS 2020/11/03 05:58:05 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:58:05 DEBUG : : Looking for writers 2020/11/03 05:58:05 DEBUG : >WaitForWriters: --- FAIL: TestRcGetVFS (0.90s) === RUN TestReadFileHandleMethods run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:58:06 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestReadFileHandleMethods (3.58s) === RUN TestReadFileHandleSeek run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:58:10 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestReadFileHandleSeek (1.10s) === RUN TestReadFileHandleReadAt run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:58:11 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestReadFileHandleReadAt (1.27s) === RUN TestReadFileHandleFlush run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:58:12 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestReadFileHandleFlush (2.16s) === RUN TestReadFileHandleRelease run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:58:14 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestReadFileHandleRelease (0.86s) === RUN TestRWFileHandleMethodsRead run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:58:15 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestRWFileHandleMethodsRead (1.15s) === RUN TestRWFileHandleSeek run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:58:16 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestRWFileHandleSeek (1.29s) === RUN TestRWFileHandleReadAt run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:58:18 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestRWFileHandleReadAt (1.35s) === RUN TestRWFileHandleFlushRead run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:58:19 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestRWFileHandleFlushRead (1.32s) === RUN TestRWFileHandleReleaseRead run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:58:20 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestRWFileHandleReleaseRead (1.27s) === RUN TestRWFileHandleMethodsWrite run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:58:22 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache 2020/11/03 05:58:22 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 05:58:22 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 05:58:22 DEBUG : file1: newRWFileHandle: 2020/11/03 05:58:22 DEBUG : file1(0xc00028a900): openPending: 2020/11/03 05:58:22 DEBUG : file1: vfs cache: truncate to size=0 2020/11/03 05:58:22 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:58:22 DEBUG : file1(0xc00028a900): >openPending: err= 2020/11/03 05:58:22 DEBUG : file1: >newRWFileHandle: err= 2020/11/03 05:58:22 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:58:22 DEBUG : file1: >Open: fd=file1 (rw), err= 2020/11/03 05:58:22 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2020/11/03 05:58:22 DEBUG : file1(0xc00028a900): _writeAt: size=5, off=0 2020/11/03 05:58:22 DEBUG : file1(0xc00028a900): >_writeAt: n=5, err= 2020/11/03 05:58:22 DEBUG : file1(0xc00028a900): _writeAt: size=7, off=5 2020/11/03 05:58:22 DEBUG : file1(0xc00028a900): >_writeAt: n=7, err= 2020/11/03 05:58:22 DEBUG : file1: vfs cache: truncate to size=11 2020/11/03 05:58:22 DEBUG : file1(0xc00028a900): close: 2020/11/03 05:58:22 DEBUG : file1: vfs cache: setting modification time to 2020-11-03 05:58:22.210159744 +0000 UTC m=+57.358350038 2020/11/03 05:58:22 INFO : file1: vfs cache: queuing for upload in 100ms 2020/11/03 05:58:22 DEBUG : file1(0xc00028a900): >close: err= 2020/11/03 05:58:22 DEBUG : file1(0xc00028a900): close: 2020/11/03 05:58:22 DEBUG : file1(0xc00028a900): >close: err=file already closed dir_test.go:252: Error Trace: dir_test.go:252 read_write_test.go:339 Error: Not equal: expected: []string{"file1,11,false"} actual : []string{"dir,0,true", "file1,11,false"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) (len=1) { +([]string) (len=2) { + (string) (len=10) "dir,0,true", (string) (len=14) "file1,11,false" Test: TestRWFileHandleMethodsWrite 2020/11/03 05:58:22 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:58:22 DEBUG : dir: Looking for writers 2020/11/03 05:58:22 DEBUG : : Looking for writers 2020/11/03 05:58:22 DEBUG : file1: reading active writers 2020/11/03 05:58:22 DEBUG : dir: reading active writers 2020/11/03 05:58:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2020/11/03 05:58:22 DEBUG : dir: Looking for writers 2020/11/03 05:58:22 DEBUG : : Looking for writers 2020/11/03 05:58:22 DEBUG : dir: reading active writers 2020/11/03 05:58:22 DEBUG : file1: reading active writers 2020/11/03 05:58:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2020/11/03 05:58:22 DEBUG : dir: Looking for writers 2020/11/03 05:58:22 DEBUG : : Looking for writers 2020/11/03 05:58:22 DEBUG : file1: reading active writers 2020/11/03 05:58:22 DEBUG : dir: reading active writers 2020/11/03 05:58:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2020/11/03 05:58:22 DEBUG : dir: Looking for writers 2020/11/03 05:58:22 DEBUG : : Looking for writers 2020/11/03 05:58:22 DEBUG : dir: reading active writers 2020/11/03 05:58:22 DEBUG : file1: reading active writers 2020/11/03 05:58:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2020/11/03 05:58:22 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:58:22 DEBUG : dir: Looking for writers 2020/11/03 05:58:22 DEBUG : : Looking for writers 2020/11/03 05:58:22 DEBUG : file1: reading active writers 2020/11/03 05:58:22 DEBUG : dir: reading active writers 2020/11/03 05:58:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2020/11/03 05:58:22 DEBUG : dir: Looking for writers 2020/11/03 05:58:22 DEBUG : : Looking for writers 2020/11/03 05:58:22 DEBUG : file1: reading active writers 2020/11/03 05:58:22 DEBUG : dir: reading active writers 2020/11/03 05:58:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2020/11/03 05:58:22 DEBUG : dir: Looking for writers 2020/11/03 05:58:22 DEBUG : : Looking for writers 2020/11/03 05:58:22 DEBUG : dir: reading active writers 2020/11/03 05:58:22 DEBUG : file1: reading active writers 2020/11/03 05:58:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2020/11/03 05:58:23 DEBUG : dir: Looking for writers 2020/11/03 05:58:23 DEBUG : : Looking for writers 2020/11/03 05:58:23 DEBUG : dir: reading active writers 2020/11/03 05:58:23 DEBUG : file1: reading active writers 2020/11/03 05:58:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:23 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:23 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:23 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:58:24 DEBUG : dir: Looking for writers 2020/11/03 05:58:24 DEBUG : : Looking for writers 2020/11/03 05:58:24 DEBUG : dir: reading active writers 2020/11/03 05:58:24 DEBUG : file1: reading active writers 2020/11/03 05:58:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:25 DEBUG : dir: Looking for writers 2020/11/03 05:58:25 DEBUG : : Looking for writers 2020/11/03 05:58:25 DEBUG : dir: reading active writers 2020/11/03 05:58:25 DEBUG : file1: reading active writers 2020/11/03 05:58:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:25 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:25 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:26 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:58:26 DEBUG : dir: Looking for writers 2020/11/03 05:58:26 DEBUG : : Looking for writers 2020/11/03 05:58:26 DEBUG : dir: reading active writers 2020/11/03 05:58:26 DEBUG : file1: reading active writers 2020/11/03 05:58:26 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:27 DEBUG : dir: Looking for writers 2020/11/03 05:58:27 DEBUG : : Looking for writers 2020/11/03 05:58:27 DEBUG : dir: reading active writers 2020/11/03 05:58:27 DEBUG : file1: reading active writers 2020/11/03 05:58:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:27 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:27 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:28 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:58:28 DEBUG : dir: Looking for writers 2020/11/03 05:58:28 DEBUG : : Looking for writers 2020/11/03 05:58:28 DEBUG : dir: reading active writers 2020/11/03 05:58:28 DEBUG : file1: reading active writers 2020/11/03 05:58:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:29 DEBUG : dir: Looking for writers 2020/11/03 05:58:29 DEBUG : : Looking for writers 2020/11/03 05:58:29 DEBUG : dir: reading active writers 2020/11/03 05:58:29 DEBUG : file1: reading active writers 2020/11/03 05:58:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:29 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:29 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:30 DEBUG : dir: Looking for writers 2020/11/03 05:58:30 DEBUG : : Looking for writers 2020/11/03 05:58:30 DEBUG : dir: reading active writers 2020/11/03 05:58:30 DEBUG : file1: reading active writers 2020/11/03 05:58:30 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:31 DEBUG : dir: Looking for writers 2020/11/03 05:58:31 DEBUG : : Looking for writers 2020/11/03 05:58:31 DEBUG : dir: reading active writers 2020/11/03 05:58:31 DEBUG : file1: reading active writers 2020/11/03 05:58:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:31 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:58:32 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s Cache{ "file1": &{c:0xc0001a0d80 mu:{state:0 sema:0} cond:0xc00028a8c0 name:file1 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13826150085014505600 ext:57358350038 loc:0x266c360} ATime:{wall:13826150085014519990 ext:57358364404 loc:0x266c360} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, } 2020/11/03 05:58:32 DEBUG : >WaitForWriters: fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 2020/11/03 05:58:32 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:32 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int fstest.go:298: Flushing the directory cache fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 2020/11/03 05:58:35 DEBUG : file1: vfs cache: starting upload fstest.go:298: Flushing the directory cache fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 2020/11/03 05:58:36 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:36 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int fstest.go:298: Flushing the directory cache fstest.go:302: Error Trace: fstest.go:302 fstest.go:335 read_write_test.go:344 Error: Should be true Test: TestRWFileHandleMethodsWrite Messages: listing wrong, want file1 (11) got dir/file1 (16), file1 (11) fstest.go:188: Error Trace: fstest.go:188 fstest.go:305 fstest.go:335 read_write_test.go:344 Error: Should be true Test: TestRWFileHandleMethodsWrite Messages: Unexpected file "dir/file1" fstest.go:324: Error Trace: fstest.go:324 fstest.go:335 read_write_test.go:344 Error: Not equal: expected: []string{} actual : []string{"dir"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) { +([]string) (len=1) { + (string) (len=3) "dir" } Test: TestRWFileHandleMethodsWrite Messages: directories 2020/11/03 05:58:40 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:58:40 DEBUG : dir: Looking for writers 2020/11/03 05:58:40 DEBUG : : Looking for writers 2020/11/03 05:58:40 DEBUG : dir: reading active writers 2020/11/03 05:58:40 DEBUG : file1: reading active writers 2020/11/03 05:58:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2020/11/03 05:58:40 DEBUG : dir: Looking for writers 2020/11/03 05:58:40 DEBUG : : Looking for writers 2020/11/03 05:58:40 DEBUG : dir: reading active writers 2020/11/03 05:58:40 DEBUG : file1: reading active writers 2020/11/03 05:58:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2020/11/03 05:58:40 DEBUG : dir: Looking for writers 2020/11/03 05:58:40 DEBUG : : Looking for writers 2020/11/03 05:58:40 DEBUG : dir: reading active writers 2020/11/03 05:58:40 DEBUG : file1: reading active writers 2020/11/03 05:58:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2020/11/03 05:58:40 DEBUG : dir: Looking for writers 2020/11/03 05:58:40 DEBUG : : Looking for writers 2020/11/03 05:58:40 DEBUG : dir: reading active writers 2020/11/03 05:58:40 DEBUG : file1: reading active writers 2020/11/03 05:58:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2020/11/03 05:58:40 DEBUG : dir: Looking for writers 2020/11/03 05:58:40 DEBUG : : Looking for writers 2020/11/03 05:58:40 DEBUG : dir: reading active writers 2020/11/03 05:58:40 DEBUG : file1: reading active writers 2020/11/03 05:58:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2020/11/03 05:58:40 DEBUG : dir: Looking for writers 2020/11/03 05:58:40 DEBUG : : Looking for writers 2020/11/03 05:58:40 DEBUG : dir: reading active writers 2020/11/03 05:58:40 DEBUG : file1: reading active writers 2020/11/03 05:58:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2020/11/03 05:58:40 DEBUG : dir: Looking for writers 2020/11/03 05:58:40 DEBUG : : Looking for writers 2020/11/03 05:58:40 DEBUG : dir: reading active writers 2020/11/03 05:58:40 DEBUG : file1: reading active writers 2020/11/03 05:58:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2020/11/03 05:58:41 DEBUG : dir: Looking for writers 2020/11/03 05:58:41 DEBUG : : Looking for writers 2020/11/03 05:58:41 DEBUG : dir: reading active writers 2020/11/03 05:58:41 DEBUG : file1: reading active writers 2020/11/03 05:58:41 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:42 DEBUG : dir: Looking for writers 2020/11/03 05:58:42 DEBUG : : Looking for writers 2020/11/03 05:58:42 DEBUG : dir: reading active writers 2020/11/03 05:58:42 DEBUG : file1: reading active writers 2020/11/03 05:58:42 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:43 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:58:43 DEBUG : dir: Looking for writers 2020/11/03 05:58:43 DEBUG : : Looking for writers 2020/11/03 05:58:43 DEBUG : dir: reading active writers 2020/11/03 05:58:43 DEBUG : file1: reading active writers 2020/11/03 05:58:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:44 DEBUG : dir: Looking for writers 2020/11/03 05:58:44 DEBUG : : Looking for writers 2020/11/03 05:58:44 DEBUG : dir: reading active writers 2020/11/03 05:58:44 DEBUG : file1: reading active writers 2020/11/03 05:58:44 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:45 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:45 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:45 DEBUG : dir: Looking for writers 2020/11/03 05:58:45 DEBUG : : Looking for writers 2020/11/03 05:58:45 DEBUG : dir: reading active writers 2020/11/03 05:58:45 DEBUG : file1: reading active writers 2020/11/03 05:58:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:46 DEBUG : dir: Looking for writers 2020/11/03 05:58:46 DEBUG : : Looking for writers 2020/11/03 05:58:46 DEBUG : dir: reading active writers 2020/11/03 05:58:46 DEBUG : file1: reading active writers 2020/11/03 05:58:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:47 DEBUG : dir: Looking for writers 2020/11/03 05:58:47 DEBUG : : Looking for writers 2020/11/03 05:58:47 DEBUG : dir: reading active writers 2020/11/03 05:58:47 DEBUG : file1: reading active writers 2020/11/03 05:58:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:48 DEBUG : dir: Looking for writers 2020/11/03 05:58:48 DEBUG : : Looking for writers 2020/11/03 05:58:48 DEBUG : file1: reading active writers 2020/11/03 05:58:48 DEBUG : dir: reading active writers 2020/11/03 05:58:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:49 DEBUG : dir: Looking for writers 2020/11/03 05:58:49 DEBUG : : Looking for writers 2020/11/03 05:58:49 DEBUG : dir: reading active writers 2020/11/03 05:58:49 DEBUG : file1: reading active writers 2020/11/03 05:58:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:50 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s Cache{ "file1": &{c:0xc0001a0d80 mu:{state:0 sema:0} cond:0xc00028a8c0 name:file1 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13826150085014505600 ext:57358350038 loc:0x266c360} ATime:{wall:13826150085014519990 ext:57358364404 loc:0x266c360} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, } 2020/11/03 05:58:50 DEBUG : >WaitForWriters: --- FAIL: TestRWFileHandleMethodsWrite (29.42s) === RUN TestRWFileHandleWriteAt run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:58:51 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache 2020/11/03 05:58:51 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 05:58:51 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 05:58:51 DEBUG : file1: newRWFileHandle: 2020/11/03 05:58:51 DEBUG : file1(0xc0003be6c0): openPending: 2020/11/03 05:58:51 ERROR : file1: vfs cache: detected external removal of cache file 2020/11/03 05:58:51 DEBUG : file1: vfs cache: truncate to size=0 2020/11/03 05:58:51 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:58:51 DEBUG : file1(0xc0003be6c0): >openPending: err= 2020/11/03 05:58:51 DEBUG : file1: vfs cache: cancelling writeback (uploading false) 0xc00028e2a0 item 1 2020/11/03 05:58:51 DEBUG : file1: >newRWFileHandle: err= 2020/11/03 05:58:51 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:58:51 DEBUG : file1: >Open: fd=file1 (rw), err= 2020/11/03 05:58:51 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2020/11/03 05:58:51 DEBUG : file1(0xc0003be6c0): _writeAt: size=7, off=0 2020/11/03 05:58:51 DEBUG : file1(0xc0003be6c0): >_writeAt: n=7, err= 2020/11/03 05:58:51 DEBUG : file1(0xc0003be6c0): _writeAt: size=6, off=5 2020/11/03 05:58:51 DEBUG : file1(0xc0003be6c0): >_writeAt: n=6, err= 2020/11/03 05:58:51 DEBUG : file1(0xc0003be6c0): close: 2020/11/03 05:58:51 DEBUG : file1: vfs cache: setting modification time to 2020-11-03 05:58:51.492102492 +0000 UTC m=+86.640292767 2020/11/03 05:58:51 INFO : file1: vfs cache: queuing for upload in 100ms 2020/11/03 05:58:51 DEBUG : file1(0xc0003be6c0): >close: err= 2020/11/03 05:58:51 DEBUG : file1(0xc0003be6c0): _writeAt: size=5, off=0 2020/11/03 05:58:51 DEBUG : file1(0xc0003be6c0): >_writeAt: n=0, err=file already closed dir_test.go:252: Error Trace: dir_test.go:252 read_write_test.go:387 Error: Not equal: expected: []string{"file1,11,false"} actual : []string{"dir,0,true", "file1,11,false"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) (len=1) { +([]string) (len=2) { + (string) (len=10) "dir,0,true", (string) (len=14) "file1,11,false" Test: TestRWFileHandleWriteAt 2020/11/03 05:58:51 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:58:51 DEBUG : dir: Looking for writers 2020/11/03 05:58:51 DEBUG : : Looking for writers 2020/11/03 05:58:51 DEBUG : dir: reading active writers 2020/11/03 05:58:51 DEBUG : file1: reading active writers 2020/11/03 05:58:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2020/11/03 05:58:51 DEBUG : dir: Looking for writers 2020/11/03 05:58:51 DEBUG : : Looking for writers 2020/11/03 05:58:51 DEBUG : dir: reading active writers 2020/11/03 05:58:51 DEBUG : file1: reading active writers 2020/11/03 05:58:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2020/11/03 05:58:51 DEBUG : dir: Looking for writers 2020/11/03 05:58:51 DEBUG : : Looking for writers 2020/11/03 05:58:51 DEBUG : dir: reading active writers 2020/11/03 05:58:51 DEBUG : file1: reading active writers 2020/11/03 05:58:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2020/11/03 05:58:51 DEBUG : dir: Looking for writers 2020/11/03 05:58:51 DEBUG : : Looking for writers 2020/11/03 05:58:51 DEBUG : dir: reading active writers 2020/11/03 05:58:51 DEBUG : file1: reading active writers 2020/11/03 05:58:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2020/11/03 05:58:51 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:58:51 DEBUG : dir: Looking for writers 2020/11/03 05:58:51 DEBUG : : Looking for writers 2020/11/03 05:58:51 DEBUG : dir: reading active writers 2020/11/03 05:58:51 DEBUG : file1: reading active writers 2020/11/03 05:58:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2020/11/03 05:58:51 DEBUG : dir: Looking for writers 2020/11/03 05:58:51 DEBUG : : Looking for writers 2020/11/03 05:58:51 DEBUG : dir: reading active writers 2020/11/03 05:58:51 DEBUG : file1: reading active writers 2020/11/03 05:58:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2020/11/03 05:58:52 DEBUG : dir: Looking for writers 2020/11/03 05:58:52 DEBUG : : Looking for writers 2020/11/03 05:58:52 DEBUG : dir: reading active writers 2020/11/03 05:58:52 DEBUG : file1: reading active writers 2020/11/03 05:58:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2020/11/03 05:58:52 DEBUG : dir: Looking for writers 2020/11/03 05:58:52 DEBUG : : Looking for writers 2020/11/03 05:58:52 DEBUG : dir: reading active writers 2020/11/03 05:58:52 DEBUG : file1: reading active writers 2020/11/03 05:58:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:53 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:53 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:53 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:58:53 DEBUG : dir: Looking for writers 2020/11/03 05:58:53 DEBUG : : Looking for writers 2020/11/03 05:58:53 DEBUG : dir: reading active writers 2020/11/03 05:58:53 DEBUG : file1: reading active writers 2020/11/03 05:58:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:54 DEBUG : dir: Looking for writers 2020/11/03 05:58:54 DEBUG : : Looking for writers 2020/11/03 05:58:54 DEBUG : dir: reading active writers 2020/11/03 05:58:54 DEBUG : file1: reading active writers 2020/11/03 05:58:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:54 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:54 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:55 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:58:55 DEBUG : dir: Looking for writers 2020/11/03 05:58:55 DEBUG : : Looking for writers 2020/11/03 05:58:55 DEBUG : dir: reading active writers 2020/11/03 05:58:55 DEBUG : file1: reading active writers 2020/11/03 05:58:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:56 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:56 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:56 DEBUG : dir: Looking for writers 2020/11/03 05:58:56 DEBUG : : Looking for writers 2020/11/03 05:58:56 DEBUG : file1: reading active writers 2020/11/03 05:58:56 DEBUG : dir: reading active writers 2020/11/03 05:58:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:57 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:58:57 DEBUG : dir: Looking for writers 2020/11/03 05:58:57 DEBUG : : Looking for writers 2020/11/03 05:58:57 DEBUG : dir: reading active writers 2020/11/03 05:58:57 DEBUG : file1: reading active writers 2020/11/03 05:58:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:58 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:58 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:58:58 DEBUG : dir: Looking for writers 2020/11/03 05:58:58 DEBUG : : Looking for writers 2020/11/03 05:58:58 DEBUG : dir: reading active writers 2020/11/03 05:58:58 DEBUG : file1: reading active writers 2020/11/03 05:58:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:58:59 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2020/11/03 05:58:59 DEBUG : dir: Looking for writers 2020/11/03 05:58:59 DEBUG : : Looking for writers 2020/11/03 05:58:59 DEBUG : dir: reading active writers 2020/11/03 05:58:59 DEBUG : file1: reading active writers 2020/11/03 05:58:59 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:00 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:59:00 DEBUG : dir: Looking for writers 2020/11/03 05:59:00 DEBUG : : Looking for writers 2020/11/03 05:59:00 DEBUG : dir: reading active writers 2020/11/03 05:59:00 DEBUG : file1: reading active writers 2020/11/03 05:59:00 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:01 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s Cache{ "file1": &{c:0xc0001a0d80 mu:{state:0 sema:0} cond:0xc00028a8c0 name:file1 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13826150116434961244 ext:86640292767 loc:0x266c360} ATime:{wall:13826150116434975257 ext:86640306773 loc:0x266c360} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, } 2020/11/03 05:59:01 DEBUG : >WaitForWriters: 2020/11/03 05:59:01 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:59:01 DEBUG : dir: Looking for writers 2020/11/03 05:59:01 DEBUG : : Looking for writers 2020/11/03 05:59:01 DEBUG : dir: reading active writers 2020/11/03 05:59:01 DEBUG : file1: reading active writers 2020/11/03 05:59:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2020/11/03 05:59:01 DEBUG : dir: Looking for writers 2020/11/03 05:59:01 DEBUG : : Looking for writers 2020/11/03 05:59:01 DEBUG : dir: reading active writers 2020/11/03 05:59:01 DEBUG : file1: reading active writers 2020/11/03 05:59:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2020/11/03 05:59:01 DEBUG : dir: Looking for writers 2020/11/03 05:59:01 DEBUG : : Looking for writers 2020/11/03 05:59:01 DEBUG : dir: reading active writers 2020/11/03 05:59:01 DEBUG : file1: reading active writers 2020/11/03 05:59:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2020/11/03 05:59:01 DEBUG : dir: Looking for writers 2020/11/03 05:59:01 DEBUG : : Looking for writers 2020/11/03 05:59:01 DEBUG : dir: reading active writers 2020/11/03 05:59:01 DEBUG : file1: reading active writers 2020/11/03 05:59:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2020/11/03 05:59:01 DEBUG : dir: Looking for writers 2020/11/03 05:59:01 DEBUG : : Looking for writers 2020/11/03 05:59:01 DEBUG : dir: reading active writers 2020/11/03 05:59:01 DEBUG : file1: reading active writers 2020/11/03 05:59:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2020/11/03 05:59:01 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:01 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:01 DEBUG : dir: Looking for writers 2020/11/03 05:59:01 DEBUG : : Looking for writers 2020/11/03 05:59:01 DEBUG : dir: reading active writers 2020/11/03 05:59:01 DEBUG : file1: reading active writers 2020/11/03 05:59:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2020/11/03 05:59:02 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2020/11/03 05:59:02 DEBUG : dir: Looking for writers 2020/11/03 05:59:02 DEBUG : : Looking for writers 2020/11/03 05:59:02 DEBUG : file1: reading active writers 2020/11/03 05:59:02 DEBUG : dir: reading active writers 2020/11/03 05:59:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2020/11/03 05:59:02 DEBUG : dir: Looking for writers 2020/11/03 05:59:02 DEBUG : : Looking for writers 2020/11/03 05:59:02 DEBUG : dir: reading active writers 2020/11/03 05:59:02 DEBUG : file1: reading active writers 2020/11/03 05:59:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:03 DEBUG : dir: Looking for writers 2020/11/03 05:59:03 DEBUG : : Looking for writers 2020/11/03 05:59:03 DEBUG : dir: reading active writers 2020/11/03 05:59:03 DEBUG : file1: reading active writers 2020/11/03 05:59:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:04 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2020/11/03 05:59:04 INFO : vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 1, uploading 0, total size 11 (was 11) 2020/11/03 05:59:04 DEBUG : dir: Looking for writers 2020/11/03 05:59:04 DEBUG : : Looking for writers 2020/11/03 05:59:04 DEBUG : dir: reading active writers 2020/11/03 05:59:04 DEBUG : file1: reading active writers 2020/11/03 05:59:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:05 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:59:05 DEBUG : dir: Looking for writers 2020/11/03 05:59:05 DEBUG : : Looking for writers 2020/11/03 05:59:05 DEBUG : dir: reading active writers 2020/11/03 05:59:05 DEBUG : file1: reading active writers 2020/11/03 05:59:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:06 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:06 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:06 DEBUG : dir: Looking for writers 2020/11/03 05:59:06 DEBUG : : Looking for writers 2020/11/03 05:59:06 DEBUG : dir: reading active writers 2020/11/03 05:59:06 DEBUG : file1: reading active writers 2020/11/03 05:59:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:07 DEBUG : dir: Looking for writers 2020/11/03 05:59:07 DEBUG : : Looking for writers 2020/11/03 05:59:07 DEBUG : dir: reading active writers 2020/11/03 05:59:07 DEBUG : file1: reading active writers 2020/11/03 05:59:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:08 DEBUG : dir: Looking for writers 2020/11/03 05:59:08 DEBUG : : Looking for writers 2020/11/03 05:59:08 DEBUG : dir: reading active writers 2020/11/03 05:59:08 DEBUG : file1: reading active writers 2020/11/03 05:59:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:09 DEBUG : dir: Looking for writers 2020/11/03 05:59:09 DEBUG : : Looking for writers 2020/11/03 05:59:09 DEBUG : dir: reading active writers 2020/11/03 05:59:09 DEBUG : file1: reading active writers 2020/11/03 05:59:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:10 DEBUG : dir: Looking for writers 2020/11/03 05:59:10 DEBUG : : Looking for writers 2020/11/03 05:59:10 DEBUG : dir: reading active writers 2020/11/03 05:59:10 DEBUG : file1: reading active writers 2020/11/03 05:59:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:11 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s Cache{ "file1": &{c:0xc0001a0d80 mu:{state:0 sema:0} cond:0xc00028a8c0 name:file1 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13826150116434961244 ext:86640292767 loc:0x266c360} ATime:{wall:13826150116434975257 ext:86640306773 loc:0x266c360} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, } 2020/11/03 05:59:11 DEBUG : >WaitForWriters: --- FAIL: TestRWFileHandleWriteAt (20.56s) === RUN TestRWFileHandleWriteNoWrite run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:59:12 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache 2020/11/03 05:59:12 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 05:59:12 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 05:59:12 DEBUG : file1: newRWFileHandle: 2020/11/03 05:59:12 DEBUG : file1(0xc00028b4c0): openPending: 2020/11/03 05:59:12 ERROR : file1: vfs cache: detected external removal of cache file 2020/11/03 05:59:12 DEBUG : file1: vfs cache: truncate to size=0 2020/11/03 05:59:12 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:59:12 DEBUG : file1(0xc00028b4c0): >openPending: err= 2020/11/03 05:59:12 DEBUG : file1: vfs cache: cancelling writeback (uploading false) 0xc00028e230 item 1 2020/11/03 05:59:12 DEBUG : file1: >newRWFileHandle: err= 2020/11/03 05:59:12 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:59:12 DEBUG : file1: >Open: fd=file1 (rw), err= 2020/11/03 05:59:12 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2020/11/03 05:59:12 DEBUG : file1(0xc00028b4c0): close: 2020/11/03 05:59:12 DEBUG : file1: vfs cache: setting modification time to 2020-11-03 05:59:12.056621564 +0000 UTC m=+107.204811849 2020/11/03 05:59:12 INFO : file1: vfs cache: queuing for upload in 100ms 2020/11/03 05:59:12 DEBUG : file1(0xc00028b4c0): >close: err= 2020/11/03 05:59:12 DEBUG : file2: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx 2020/11/03 05:59:12 DEBUG : file2: Open: flags=O_WRONLY|O_CREATE|O_TRUNC 2020/11/03 05:59:12 DEBUG : file2: newRWFileHandle: 2020/11/03 05:59:12 DEBUG : file2(0xc00028b5c0): openPending: 2020/11/03 05:59:12 DEBUG : file2: vfs cache: truncate to size=0 2020/11/03 05:59:12 DEBUG : : Added virtual directory entry vAdd: "file2" 2020/11/03 05:59:12 DEBUG : file2(0xc00028b5c0): >openPending: err= 2020/11/03 05:59:12 DEBUG : file2: >newRWFileHandle: err= 2020/11/03 05:59:12 DEBUG : : Added virtual directory entry vAdd: "file2" 2020/11/03 05:59:12 DEBUG : file2: >Open: fd=file2 (rw), err= 2020/11/03 05:59:12 DEBUG : file2: >OpenFile: fd=file2 (rw), err= 2020/11/03 05:59:12 DEBUG : file2(0xc00028b5c0): RWFileHandle.Flush 2020/11/03 05:59:12 DEBUG : file2(0xc00028b5c0): RWFileHandle.Release 2020/11/03 05:59:12 DEBUG : file2(0xc00028b5c0): close: 2020/11/03 05:59:12 DEBUG : file2: vfs cache: setting modification time to 2020-11-03 05:59:12.057403127 +0000 UTC m=+107.205593394 2020/11/03 05:59:12 INFO : file2: vfs cache: queuing for upload in 100ms 2020/11/03 05:59:12 DEBUG : file2(0xc00028b5c0): >close: err= dir_test.go:252: Error Trace: dir_test.go:252 read_write_test.go:420 Error: Not equal: expected: []string{"file1,0,false", "file2,0,false"} actual : []string{"dir,0,true", "file1,0,false", "file2,0,false"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) (len=2) { +([]string) (len=3) { + (string) (len=10) "dir,0,true", (string) (len=13) "file1,0,false", Test: TestRWFileHandleWriteNoWrite 2020/11/03 05:59:12 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:59:12 DEBUG : dir: Looking for writers 2020/11/03 05:59:12 DEBUG : : Looking for writers 2020/11/03 05:59:12 DEBUG : file1: reading active writers 2020/11/03 05:59:12 DEBUG : file2: reading active writers 2020/11/03 05:59:12 DEBUG : dir: reading active writers 2020/11/03 05:59:12 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms 2020/11/03 05:59:12 DEBUG : dir: Looking for writers 2020/11/03 05:59:12 DEBUG : : Looking for writers 2020/11/03 05:59:12 DEBUG : dir: reading active writers 2020/11/03 05:59:12 DEBUG : file1: reading active writers 2020/11/03 05:59:12 DEBUG : file2: reading active writers 2020/11/03 05:59:12 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms 2020/11/03 05:59:12 DEBUG : dir: Looking for writers 2020/11/03 05:59:12 DEBUG : : Looking for writers 2020/11/03 05:59:12 DEBUG : file2: reading active writers 2020/11/03 05:59:12 DEBUG : dir: reading active writers 2020/11/03 05:59:12 DEBUG : file1: reading active writers 2020/11/03 05:59:12 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms 2020/11/03 05:59:12 DEBUG : dir: Looking for writers 2020/11/03 05:59:12 DEBUG : : Looking for writers 2020/11/03 05:59:12 DEBUG : file1: reading active writers 2020/11/03 05:59:12 DEBUG : file2: reading active writers 2020/11/03 05:59:12 DEBUG : dir: reading active writers 2020/11/03 05:59:12 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms 2020/11/03 05:59:12 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:59:12 DEBUG : file2: vfs cache: starting upload 2020/11/03 05:59:12 DEBUG : dir: Looking for writers 2020/11/03 05:59:12 DEBUG : : Looking for writers 2020/11/03 05:59:12 DEBUG : dir: reading active writers 2020/11/03 05:59:12 DEBUG : file1: reading active writers 2020/11/03 05:59:12 DEBUG : file2: reading active writers 2020/11/03 05:59:12 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms 2020/11/03 05:59:12 DEBUG : dir: Looking for writers 2020/11/03 05:59:12 DEBUG : : Looking for writers 2020/11/03 05:59:12 DEBUG : dir: reading active writers 2020/11/03 05:59:12 DEBUG : file1: reading active writers 2020/11/03 05:59:12 DEBUG : file2: reading active writers 2020/11/03 05:59:12 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms 2020/11/03 05:59:12 DEBUG : dir: Looking for writers 2020/11/03 05:59:12 DEBUG : : Looking for writers 2020/11/03 05:59:12 DEBUG : dir: reading active writers 2020/11/03 05:59:12 DEBUG : file1: reading active writers 2020/11/03 05:59:12 DEBUG : file2: reading active writers 2020/11/03 05:59:12 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms 2020/11/03 05:59:13 DEBUG : dir: Looking for writers 2020/11/03 05:59:13 DEBUG : : Looking for writers 2020/11/03 05:59:13 DEBUG : dir: reading active writers 2020/11/03 05:59:13 DEBUG : file1: reading active writers 2020/11/03 05:59:13 DEBUG : file2: reading active writers 2020/11/03 05:59:13 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:59:13 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:13 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:13 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:59:13 ERROR : file2: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:13 ERROR : file2: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:14 DEBUG : file2: vfs cache: starting upload 2020/11/03 05:59:14 DEBUG : dir: Looking for writers 2020/11/03 05:59:14 DEBUG : : Looking for writers 2020/11/03 05:59:14 DEBUG : dir: reading active writers 2020/11/03 05:59:14 DEBUG : file1: reading active writers 2020/11/03 05:59:14 DEBUG : file2: reading active writers 2020/11/03 05:59:14 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:59:14 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:14 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:15 DEBUG : dir: Looking for writers 2020/11/03 05:59:15 DEBUG : : Looking for writers 2020/11/03 05:59:15 DEBUG : dir: reading active writers 2020/11/03 05:59:15 DEBUG : file1: reading active writers 2020/11/03 05:59:15 DEBUG : file2: reading active writers 2020/11/03 05:59:15 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:59:15 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:59:15 ERROR : file2: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:15 ERROR : file2: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:15 DEBUG : file2: vfs cache: starting upload 2020/11/03 05:59:16 DEBUG : dir: Looking for writers 2020/11/03 05:59:16 DEBUG : : Looking for writers 2020/11/03 05:59:16 DEBUG : dir: reading active writers 2020/11/03 05:59:16 DEBUG : file1: reading active writers 2020/11/03 05:59:16 DEBUG : file2: reading active writers 2020/11/03 05:59:16 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:59:16 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:16 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:17 ERROR : file2: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:17 ERROR : file2: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:17 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:59:17 DEBUG : dir: Looking for writers 2020/11/03 05:59:17 DEBUG : : Looking for writers 2020/11/03 05:59:17 DEBUG : file2: reading active writers 2020/11/03 05:59:17 DEBUG : dir: reading active writers 2020/11/03 05:59:17 DEBUG : file1: reading active writers 2020/11/03 05:59:17 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:59:17 DEBUG : file2: vfs cache: starting upload 2020/11/03 05:59:18 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:18 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:18 DEBUG : dir: Looking for writers 2020/11/03 05:59:18 DEBUG : : Looking for writers 2020/11/03 05:59:18 DEBUG : dir: reading active writers 2020/11/03 05:59:18 DEBUG : file1: reading active writers 2020/11/03 05:59:18 DEBUG : file2: reading active writers 2020/11/03 05:59:18 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:59:19 ERROR : file2: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:19 ERROR : file2: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:19 DEBUG : dir: Looking for writers 2020/11/03 05:59:19 DEBUG : : Looking for writers 2020/11/03 05:59:19 DEBUG : dir: reading active writers 2020/11/03 05:59:19 DEBUG : file1: reading active writers 2020/11/03 05:59:19 DEBUG : file2: reading active writers 2020/11/03 05:59:19 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:59:19 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:59:20 DEBUG : dir: Looking for writers 2020/11/03 05:59:20 DEBUG : : Looking for writers 2020/11/03 05:59:20 DEBUG : dir: reading active writers 2020/11/03 05:59:20 DEBUG : file1: reading active writers 2020/11/03 05:59:20 DEBUG : file2: reading active writers 2020/11/03 05:59:20 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:59:20 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:20 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:20 DEBUG : file2: vfs cache: starting upload 2020/11/03 05:59:21 DEBUG : dir: Looking for writers 2020/11/03 05:59:21 DEBUG : : Looking for writers 2020/11/03 05:59:21 DEBUG : dir: reading active writers 2020/11/03 05:59:21 DEBUG : file1: reading active writers 2020/11/03 05:59:21 DEBUG : file2: reading active writers 2020/11/03 05:59:21 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:59:21 ERROR : file2: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:21 ERROR : file2: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:22 ERROR : Exiting even though 0 writers active and 2 cache items in use after 10s Cache{ "file1": &{c:0xc0001a0d80 mu:{state:0 sema:0} cond:0xc00028a8c0 name:file1 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13826150138548058620 ext:107204811849 loc:0x266c360} ATime:{wall:13826150138548254283 ext:107205007501 loc:0x266c360} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, "file2": &{c:0xc0001a0d80 mu:{state:0 sema:0} cond:0xc00028b580 name:file2 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13826150138548840183 ext:107205593394 loc:0x266c360} ATime:{wall:13826150138548993167 ext:107205746382 loc:0x266c360} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2 pendingAccesses:0 beingReset:false}, } 2020/11/03 05:59:22 DEBUG : >WaitForWriters: 2020/11/03 05:59:22 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:59:22 DEBUG : dir: Looking for writers 2020/11/03 05:59:22 DEBUG : : Looking for writers 2020/11/03 05:59:22 DEBUG : dir: reading active writers 2020/11/03 05:59:22 DEBUG : file1: reading active writers 2020/11/03 05:59:22 DEBUG : file2: reading active writers 2020/11/03 05:59:22 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms 2020/11/03 05:59:22 DEBUG : dir: Looking for writers 2020/11/03 05:59:22 DEBUG : : Looking for writers 2020/11/03 05:59:22 DEBUG : dir: reading active writers 2020/11/03 05:59:22 DEBUG : file1: reading active writers 2020/11/03 05:59:22 DEBUG : file2: reading active writers 2020/11/03 05:59:22 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms 2020/11/03 05:59:22 DEBUG : dir: Looking for writers 2020/11/03 05:59:22 DEBUG : : Looking for writers 2020/11/03 05:59:22 DEBUG : dir: reading active writers 2020/11/03 05:59:22 DEBUG : file1: reading active writers 2020/11/03 05:59:22 DEBUG : file2: reading active writers 2020/11/03 05:59:22 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms 2020/11/03 05:59:22 DEBUG : dir: Looking for writers 2020/11/03 05:59:22 DEBUG : : Looking for writers 2020/11/03 05:59:22 DEBUG : file2: reading active writers 2020/11/03 05:59:22 DEBUG : dir: reading active writers 2020/11/03 05:59:22 DEBUG : file1: reading active writers 2020/11/03 05:59:22 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms 2020/11/03 05:59:22 DEBUG : dir: Looking for writers 2020/11/03 05:59:22 DEBUG : : Looking for writers 2020/11/03 05:59:22 DEBUG : dir: reading active writers 2020/11/03 05:59:22 DEBUG : file1: reading active writers 2020/11/03 05:59:22 DEBUG : file2: reading active writers 2020/11/03 05:59:22 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms 2020/11/03 05:59:22 DEBUG : dir: Looking for writers 2020/11/03 05:59:22 DEBUG : : Looking for writers 2020/11/03 05:59:22 DEBUG : dir: reading active writers 2020/11/03 05:59:22 DEBUG : file1: reading active writers 2020/11/03 05:59:22 DEBUG : file2: reading active writers 2020/11/03 05:59:22 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms 2020/11/03 05:59:22 DEBUG : dir: Looking for writers 2020/11/03 05:59:22 DEBUG : : Looking for writers 2020/11/03 05:59:22 DEBUG : file1: reading active writers 2020/11/03 05:59:22 DEBUG : file2: reading active writers 2020/11/03 05:59:22 DEBUG : dir: reading active writers 2020/11/03 05:59:22 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms 2020/11/03 05:59:23 DEBUG : dir: Looking for writers 2020/11/03 05:59:23 DEBUG : : Looking for writers 2020/11/03 05:59:23 DEBUG : dir: reading active writers 2020/11/03 05:59:23 DEBUG : file1: reading active writers 2020/11/03 05:59:23 DEBUG : file2: reading active writers 2020/11/03 05:59:23 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:59:23 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:59:24 DEBUG : dir: Looking for writers 2020/11/03 05:59:24 DEBUG : : Looking for writers 2020/11/03 05:59:24 DEBUG : dir: reading active writers 2020/11/03 05:59:24 DEBUG : file1: reading active writers 2020/11/03 05:59:24 DEBUG : file2: reading active writers 2020/11/03 05:59:24 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:59:24 DEBUG : file2: vfs cache: starting upload 2020/11/03 05:59:25 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:25 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:25 DEBUG : dir: Looking for writers 2020/11/03 05:59:25 DEBUG : : Looking for writers 2020/11/03 05:59:25 DEBUG : dir: reading active writers 2020/11/03 05:59:25 DEBUG : file1: reading active writers 2020/11/03 05:59:25 DEBUG : file2: reading active writers 2020/11/03 05:59:25 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:59:25 ERROR : file2: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:25 ERROR : file2: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:26 DEBUG : dir: Looking for writers 2020/11/03 05:59:26 DEBUG : : Looking for writers 2020/11/03 05:59:26 DEBUG : file1: reading active writers 2020/11/03 05:59:26 DEBUG : file2: reading active writers 2020/11/03 05:59:26 DEBUG : dir: reading active writers 2020/11/03 05:59:26 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:59:27 DEBUG : dir: Looking for writers 2020/11/03 05:59:27 DEBUG : : Looking for writers 2020/11/03 05:59:27 DEBUG : dir: reading active writers 2020/11/03 05:59:27 DEBUG : file1: reading active writers 2020/11/03 05:59:27 DEBUG : file2: reading active writers 2020/11/03 05:59:27 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:59:28 DEBUG : dir: Looking for writers 2020/11/03 05:59:28 DEBUG : : Looking for writers 2020/11/03 05:59:28 DEBUG : dir: reading active writers 2020/11/03 05:59:28 DEBUG : file1: reading active writers 2020/11/03 05:59:28 DEBUG : file2: reading active writers 2020/11/03 05:59:28 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:59:29 DEBUG : dir: Looking for writers 2020/11/03 05:59:29 DEBUG : : Looking for writers 2020/11/03 05:59:29 DEBUG : dir: reading active writers 2020/11/03 05:59:29 DEBUG : file1: reading active writers 2020/11/03 05:59:29 DEBUG : file2: reading active writers 2020/11/03 05:59:29 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:59:30 DEBUG : dir: Looking for writers 2020/11/03 05:59:30 DEBUG : : Looking for writers 2020/11/03 05:59:30 DEBUG : dir: reading active writers 2020/11/03 05:59:30 DEBUG : file1: reading active writers 2020/11/03 05:59:30 DEBUG : file2: reading active writers 2020/11/03 05:59:30 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:59:31 DEBUG : dir: Looking for writers 2020/11/03 05:59:31 DEBUG : : Looking for writers 2020/11/03 05:59:31 DEBUG : file1: reading active writers 2020/11/03 05:59:31 DEBUG : file2: reading active writers 2020/11/03 05:59:31 DEBUG : dir: reading active writers 2020/11/03 05:59:31 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:59:31 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:59:32 ERROR : Exiting even though 0 writers active and 2 cache items in use after 10s Cache{ "file2": &{c:0xc0001a0d80 mu:{state:0 sema:0} cond:0xc00028b580 name:file2 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13826150138548840183 ext:107205593394 loc:0x266c360} ATime:{wall:13826150138548993167 ext:107205746382 loc:0x266c360} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2 pendingAccesses:0 beingReset:false}, "file1": &{c:0xc0001a0d80 mu:{state:0 sema:0} cond:0xc00028a8c0 name:file1 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13826150138548058620 ext:107204811849 loc:0x266c360} ATime:{wall:13826150138548254283 ext:107205007501 loc:0x266c360} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, } 2020/11/03 05:59:32 DEBUG : >WaitForWriters: 2020/11/03 05:59:32 DEBUG : file2: vfs cache: starting upload 2020/11/03 05:59:32 ERROR : file2: vfs cache: failed to write metadata file: vfs cache item: failed to write metadata: open /home/rclone/.cache/rclone/vfsMeta/TestSharefile/rclone-test-qitorax1dopocit5wihumur0/file2: no such file or directory 2020/11/03 05:59:32 INFO : file2: vfs cache: upload succeeded try #7 2020/11/03 05:59:32 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:32 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: upload file: json: cannot unmarshal string into Go struct field .value.size of type int fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Flushing the directory cache fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:298: Flushing the directory cache fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:298: Flushing the directory cache fstest.go:302: Error Trace: fstest.go:302 fstest.go:335 run.go:169 run.go:339 vfs_test.go:54 read_write_test.go:427 Error: Should be true Test: TestRWFileHandleWriteNoWrite Messages: listing wrong, want got file1 (0) fstest.go:188: Error Trace: fstest.go:188 fstest.go:305 fstest.go:335 run.go:169 run.go:339 vfs_test.go:54 read_write_test.go:427 Error: Should be true Test: TestRWFileHandleWriteNoWrite Messages: Unexpected file "file1" --- FAIL: TestRWFileHandleWriteNoWrite (28.84s) === RUN TestRWFileHandleSizeTruncateExisting run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:59:40 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestRWFileHandleSizeTruncateExisting (2.19s) === RUN TestRWFileHandleSizeCreateExisting run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:59:43 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestRWFileHandleSizeCreateExisting (1.97s) === RUN TestRWFileModTimeWithOpenWriters run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:59:45 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache 2020/11/03 05:59:45 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 05:59:45 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 05:59:45 DEBUG : file1: newRWFileHandle: 2020/11/03 05:59:45 DEBUG : file1(0xc000403940): openPending: 2020/11/03 05:59:45 DEBUG : file1: vfs cache: truncate to size=0 2020/11/03 05:59:45 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:59:45 DEBUG : file1(0xc000403940): >openPending: err= 2020/11/03 05:59:45 DEBUG : file1: vfs cache: cancelling writeback (uploading false) 0xc0002043f0 item 1 2020/11/03 05:59:45 DEBUG : file1: >newRWFileHandle: err= 2020/11/03 05:59:45 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:59:45 DEBUG : file1: >Open: fd=file1 (rw), err= 2020/11/03 05:59:45 DEBUG : file1: >OpenFile: fd=file1 (rw), err= run.go:282: Failed to put "time_test" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:46 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:59:46 DEBUG : dir: Looking for writers 2020/11/03 05:59:46 DEBUG : : Looking for writers 2020/11/03 05:59:46 DEBUG : dir: reading active writers 2020/11/03 05:59:46 DEBUG : file1: reading active writers 2020/11/03 05:59:46 DEBUG : file1: active writers 1 2020/11/03 05:59:46 DEBUG : file2: reading active writers 2020/11/03 05:59:46 DEBUG : Still 1 writers active and 1 cache items in use, waiting 10ms 2020/11/03 05:59:46 DEBUG : dir: Looking for writers 2020/11/03 05:59:46 DEBUG : : Looking for writers 2020/11/03 05:59:46 DEBUG : dir: reading active writers 2020/11/03 05:59:46 DEBUG : file1: reading active writers 2020/11/03 05:59:46 DEBUG : file1: active writers 1 2020/11/03 05:59:46 DEBUG : file2: reading active writers 2020/11/03 05:59:46 DEBUG : Still 1 writers active and 1 cache items in use, waiting 20ms 2020/11/03 05:59:46 DEBUG : dir: Looking for writers 2020/11/03 05:59:46 DEBUG : : Looking for writers 2020/11/03 05:59:46 DEBUG : file1: reading active writers 2020/11/03 05:59:46 DEBUG : file1: active writers 1 2020/11/03 05:59:46 DEBUG : file2: reading active writers 2020/11/03 05:59:46 DEBUG : dir: reading active writers 2020/11/03 05:59:46 DEBUG : Still 1 writers active and 1 cache items in use, waiting 40ms 2020/11/03 05:59:46 DEBUG : dir: Looking for writers 2020/11/03 05:59:46 DEBUG : : Looking for writers 2020/11/03 05:59:46 DEBUG : file2: reading active writers 2020/11/03 05:59:46 DEBUG : dir: reading active writers 2020/11/03 05:59:46 DEBUG : file1: reading active writers 2020/11/03 05:59:46 DEBUG : file1: active writers 1 2020/11/03 05:59:46 DEBUG : Still 1 writers active and 1 cache items in use, waiting 80ms 2020/11/03 05:59:46 DEBUG : dir: Looking for writers 2020/11/03 05:59:46 DEBUG : : Looking for writers 2020/11/03 05:59:46 DEBUG : file1: reading active writers 2020/11/03 05:59:46 DEBUG : file1: active writers 1 2020/11/03 05:59:46 DEBUG : file2: reading active writers 2020/11/03 05:59:46 DEBUG : dir: reading active writers 2020/11/03 05:59:46 DEBUG : Still 1 writers active and 1 cache items in use, waiting 160ms 2020/11/03 05:59:46 DEBUG : dir: Looking for writers 2020/11/03 05:59:46 DEBUG : : Looking for writers 2020/11/03 05:59:46 DEBUG : file1: reading active writers 2020/11/03 05:59:46 DEBUG : file1: active writers 1 2020/11/03 05:59:46 DEBUG : file2: reading active writers 2020/11/03 05:59:46 DEBUG : dir: reading active writers 2020/11/03 05:59:46 DEBUG : Still 1 writers active and 1 cache items in use, waiting 320ms 2020/11/03 05:59:47 DEBUG : dir: Looking for writers 2020/11/03 05:59:47 DEBUG : : Looking for writers 2020/11/03 05:59:47 DEBUG : file2: reading active writers 2020/11/03 05:59:47 DEBUG : dir: reading active writers 2020/11/03 05:59:47 DEBUG : file1: reading active writers 2020/11/03 05:59:47 DEBUG : file1: active writers 1 2020/11/03 05:59:47 DEBUG : Still 1 writers active and 1 cache items in use, waiting 640ms 2020/11/03 05:59:47 DEBUG : dir: Looking for writers 2020/11/03 05:59:47 DEBUG : : Looking for writers 2020/11/03 05:59:47 DEBUG : dir: reading active writers 2020/11/03 05:59:47 DEBUG : file1: reading active writers 2020/11/03 05:59:47 DEBUG : file1: active writers 1 2020/11/03 05:59:47 DEBUG : file2: reading active writers 2020/11/03 05:59:47 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:48 DEBUG : dir: Looking for writers 2020/11/03 05:59:48 DEBUG : : Looking for writers 2020/11/03 05:59:48 DEBUG : dir: reading active writers 2020/11/03 05:59:48 DEBUG : file1: reading active writers 2020/11/03 05:59:48 DEBUG : file1: active writers 1 2020/11/03 05:59:48 DEBUG : file2: reading active writers 2020/11/03 05:59:48 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:49 DEBUG : dir: Looking for writers 2020/11/03 05:59:49 DEBUG : : Looking for writers 2020/11/03 05:59:49 DEBUG : file2: reading active writers 2020/11/03 05:59:49 DEBUG : dir: reading active writers 2020/11/03 05:59:49 DEBUG : file1: reading active writers 2020/11/03 05:59:49 DEBUG : file1: active writers 1 2020/11/03 05:59:49 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:50 DEBUG : dir: Looking for writers 2020/11/03 05:59:50 DEBUG : : Looking for writers 2020/11/03 05:59:50 DEBUG : dir: reading active writers 2020/11/03 05:59:50 DEBUG : file1: reading active writers 2020/11/03 05:59:50 DEBUG : file1: active writers 1 2020/11/03 05:59:50 DEBUG : file2: reading active writers 2020/11/03 05:59:50 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:51 DEBUG : dir: Looking for writers 2020/11/03 05:59:51 DEBUG : : Looking for writers 2020/11/03 05:59:51 DEBUG : dir: reading active writers 2020/11/03 05:59:51 DEBUG : file1: reading active writers 2020/11/03 05:59:51 DEBUG : file1: active writers 1 2020/11/03 05:59:51 DEBUG : file2: reading active writers 2020/11/03 05:59:51 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:52 DEBUG : dir: Looking for writers 2020/11/03 05:59:52 DEBUG : : Looking for writers 2020/11/03 05:59:52 DEBUG : dir: reading active writers 2020/11/03 05:59:52 DEBUG : file1: reading active writers 2020/11/03 05:59:52 DEBUG : file1: active writers 1 2020/11/03 05:59:52 DEBUG : file2: reading active writers 2020/11/03 05:59:52 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:53 DEBUG : dir: Looking for writers 2020/11/03 05:59:53 DEBUG : : Looking for writers 2020/11/03 05:59:53 DEBUG : dir: reading active writers 2020/11/03 05:59:53 DEBUG : file1: reading active writers 2020/11/03 05:59:53 DEBUG : file1: active writers 1 2020/11/03 05:59:53 DEBUG : file2: reading active writers 2020/11/03 05:59:53 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:54 DEBUG : dir: Looking for writers 2020/11/03 05:59:54 DEBUG : : Looking for writers 2020/11/03 05:59:54 DEBUG : dir: reading active writers 2020/11/03 05:59:54 DEBUG : file1: reading active writers 2020/11/03 05:59:54 DEBUG : file1: active writers 1 2020/11/03 05:59:54 DEBUG : file2: reading active writers 2020/11/03 05:59:54 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:55 DEBUG : dir: Looking for writers 2020/11/03 05:59:55 DEBUG : : Looking for writers 2020/11/03 05:59:55 DEBUG : dir: reading active writers 2020/11/03 05:59:55 DEBUG : file1: reading active writers 2020/11/03 05:59:55 DEBUG : file1: active writers 1 2020/11/03 05:59:55 DEBUG : file2: reading active writers 2020/11/03 05:59:55 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:59:56 ERROR : Exiting even though 1 writers active and 1 cache items in use after 10s Cache{ "file1": &{c:0xc0001a0d80 mu:{state:0 sema:0} cond:0xc00028a8c0 name:file1 opens:1 downloaders: o: fd:0xc000120430 metaDirty:true modified:true info:{ModTime:{wall:13826150173982065981 ext:140205339005 loc:0x266c360} ATime:{wall:13826150173982065981 ext:140205339005 loc:0x266c360} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, "file2": &{c:0xc0001a0d80 mu:{state:0 sema:0} cond:0xc00028b580 name:file2 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13826150138548840183 ext:107205593394 loc:0x266c360} ATime:{wall:13826150138548993167 ext:107205746382 loc:0x266c360} Size:0 Rs:[] Fingerprint: Dirty:false} writeBackID:2 pendingAccesses:0 beingReset:false}, } 2020/11/03 05:59:56 DEBUG : >WaitForWriters: --- FAIL: TestRWFileModTimeWithOpenWriters (12.62s) === RUN TestVFSNew vfs_test.go:134: Error Trace: vfs_test.go:134 vfs_test.go:137 Error: Not equal: expected: 0 actual : 5 Test: TestVFSNew run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:59:57 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache vfs_test.go:134: Error Trace: vfs_test.go:134 vfs_test.go:147 Error: Not equal: expected: 1 actual : 5 Test: TestVFSNew 2020/11/03 05:59:57 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache vfs_test.go:134: Error Trace: vfs_test.go:134 vfs_test.go:154 Error: Not equal: expected: 1 actual : 5 Test: TestVFSNew vfs_test.go:134: Error Trace: vfs_test.go:134 vfs_test.go:159 Error: Not equal: expected: 1 actual : 5 Test: TestVFSNew 2020/11/03 05:59:57 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:59:57 DEBUG : : Looking for writers 2020/11/03 05:59:57 DEBUG : >WaitForWriters: vfs_test.go:134: Error Trace: vfs_test.go:134 vfs_test.go:163 Error: Not equal: expected: 0 actual : 5 Test: TestVFSNew --- FAIL: TestVFSNew (0.34s) === RUN TestVFSStat run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 05:59:58 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:59:59 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:59:59 DEBUG : : Looking for writers 2020/11/03 05:59:59 DEBUG : >WaitForWriters: --- FAIL: TestVFSStat (2.33s) === RUN TestVFSStatParent run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 06:00:00 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 06:00:01 DEBUG : WaitForWriters: timeout=10s 2020/11/03 06:00:01 DEBUG : : Looking for writers 2020/11/03 06:00:01 DEBUG : >WaitForWriters: --- FAIL: TestVFSStatParent (2.22s) === RUN TestVFSOpenFile run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 06:00:02 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "file1" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 06:00:03 DEBUG : WaitForWriters: timeout=10s 2020/11/03 06:00:03 DEBUG : : Looking for writers 2020/11/03 06:00:03 DEBUG : >WaitForWriters: --- FAIL: TestVFSOpenFile (1.61s) === RUN TestVFSRename run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 06:00:04 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache run.go:282: Failed to put "dir/file2" to "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 06:00:06 DEBUG : WaitForWriters: timeout=10s 2020/11/03 06:00:06 DEBUG : : Looking for writers 2020/11/03 06:00:06 DEBUG : >WaitForWriters: --- FAIL: TestVFSRename (3.21s) === RUN TestWriteFileHandleMethods run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 06:00:07 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache 2020/11/03 06:00:07 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 06:00:07 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 06:00:07 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 06:00:07 DEBUG : file1: >Open: fd=file1 (w), err= 2020/11/03 06:00:07 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/11/03 06:00:07 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 06:00:07 ERROR : file1: WriteFileHandle: Read: Can't read and write to file without --vfs-cache-mode >= minimal 2020/11/03 06:00:07 ERROR : file1: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal 2020/11/03 06:00:07 ERROR : file1: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes 2020/11/03 06:00:07 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': File to upload is small (5 bytes), uploading instead of streaming 2020/11/03 06:00:09 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 06:00:09 ERROR : file1: WriteFileHandle.New Rcat failed: upload file: json: cannot unmarshal string into Go struct field .value.size of type int write_test.go:84: Error Trace: write_test.go:84 Error: Received unexpected error: upload file: json: cannot unmarshal string into Go struct field .value.size of type int Test: TestWriteFileHandleMethods 2020/11/03 06:00:09 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 06:00:09 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 06:00:09 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 06:00:09 DEBUG : file1: >Open: fd=file1 (w), err= 2020/11/03 06:00:09 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/11/03 06:00:09 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 06:00:09 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': File to upload is small (0 bytes), uploading instead of streaming 2020/11/03 06:00:11 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 06:00:11 ERROR : file1: WriteFileHandle.New Rcat failed: upload file: json: cannot unmarshal string into Go struct field .value.size of type int write_test.go:103: Error Trace: write_test.go:103 Error: Received unexpected error: upload file: json: cannot unmarshal string into Go struct field .value.size of type int Test: TestWriteFileHandleMethods dir_test.go:252: Error Trace: dir_test.go:252 write_test.go:104 Error: Not equal: expected: []string{"file1,5,false"} actual : []string{"file1,0,false"} Diff: --- Expected +++ Actual @@ -1,3 +1,3 @@ ([]string) (len=1) { - (string) (len=13) "file1,5,false" + (string) (len=13) "file1,0,false" } Test: TestWriteFileHandleMethods 2020/11/03 06:00:11 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 06:00:11 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 06:00:11 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 06:00:11 DEBUG : file1: >Open: fd=file1 (w), err= 2020/11/03 06:00:11 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/11/03 06:00:11 DEBUG : : Added virtual directory entry vAdd: "file1" write_test.go:111: Error Trace: write_test.go:111 Error: Not equal: expected: *errors.errorString(&errors.errorString{s:"permission denied"}) actual : () Test: TestWriteFileHandleMethods 2020/11/03 06:00:11 DEBUG : WaitForWriters: timeout=10s 2020/11/03 06:00:11 DEBUG : : Looking for writers 2020/11/03 06:00:11 DEBUG : file1: reading active writers 2020/11/03 06:00:11 DEBUG : file1: active writers 1 2020/11/03 06:00:11 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/11/03 06:00:11 DEBUG : : Looking for writers 2020/11/03 06:00:11 DEBUG : file1: reading active writers 2020/11/03 06:00:11 DEBUG : file1: active writers 1 2020/11/03 06:00:11 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/11/03 06:00:11 DEBUG : : Looking for writers 2020/11/03 06:00:11 DEBUG : file1: reading active writers 2020/11/03 06:00:11 DEBUG : file1: active writers 1 2020/11/03 06:00:11 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/11/03 06:00:11 DEBUG : : Looking for writers 2020/11/03 06:00:11 DEBUG : file1: reading active writers 2020/11/03 06:00:11 DEBUG : file1: active writers 1 2020/11/03 06:00:11 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/11/03 06:00:11 DEBUG : : Looking for writers 2020/11/03 06:00:11 DEBUG : file1: reading active writers 2020/11/03 06:00:11 DEBUG : file1: active writers 1 2020/11/03 06:00:11 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/11/03 06:00:11 DEBUG : : Looking for writers 2020/11/03 06:00:11 DEBUG : file1: reading active writers 2020/11/03 06:00:11 DEBUG : file1: active writers 1 2020/11/03 06:00:11 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/11/03 06:00:11 DEBUG : : Looking for writers 2020/11/03 06:00:11 DEBUG : file1: reading active writers 2020/11/03 06:00:11 DEBUG : file1: active writers 1 2020/11/03 06:00:11 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/11/03 06:00:12 DEBUG : : Looking for writers 2020/11/03 06:00:12 DEBUG : file1: reading active writers 2020/11/03 06:00:12 DEBUG : file1: active writers 1 2020/11/03 06:00:12 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:13 DEBUG : : Looking for writers 2020/11/03 06:00:13 DEBUG : file1: reading active writers 2020/11/03 06:00:13 DEBUG : file1: active writers 1 2020/11/03 06:00:13 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:14 DEBUG : : Looking for writers 2020/11/03 06:00:14 DEBUG : file1: reading active writers 2020/11/03 06:00:14 DEBUG : file1: active writers 1 2020/11/03 06:00:14 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:15 DEBUG : : Looking for writers 2020/11/03 06:00:15 DEBUG : file1: reading active writers 2020/11/03 06:00:15 DEBUG : file1: active writers 1 2020/11/03 06:00:15 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:16 DEBUG : : Looking for writers 2020/11/03 06:00:16 DEBUG : file1: reading active writers 2020/11/03 06:00:16 DEBUG : file1: active writers 1 2020/11/03 06:00:16 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:17 DEBUG : : Looking for writers 2020/11/03 06:00:17 DEBUG : file1: reading active writers 2020/11/03 06:00:17 DEBUG : file1: active writers 1 2020/11/03 06:00:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:18 DEBUG : : Looking for writers 2020/11/03 06:00:18 DEBUG : file1: reading active writers 2020/11/03 06:00:18 DEBUG : file1: active writers 1 2020/11/03 06:00:18 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:19 DEBUG : : Looking for writers 2020/11/03 06:00:19 DEBUG : file1: reading active writers 2020/11/03 06:00:19 DEBUG : file1: active writers 1 2020/11/03 06:00:19 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:20 DEBUG : : Looking for writers 2020/11/03 06:00:20 DEBUG : file1: reading active writers 2020/11/03 06:00:20 DEBUG : file1: active writers 1 2020/11/03 06:00:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:21 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/11/03 06:00:21 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleMethods (14.26s) === RUN TestWriteFileHandleWriteAt run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 06:00:21 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache 2020/11/03 06:00:21 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 06:00:21 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 06:00:21 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 06:00:21 DEBUG : file1: >Open: fd=file1 (w), err= 2020/11/03 06:00:21 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/11/03 06:00:21 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 06:00:21 DEBUG : file1: waiting for in-sequence write to 100 for 1s 2020/11/03 06:00:22 DEBUG : file1: aborting in-sequence write wait, off=100 2020/11/03 06:00:22 DEBUG : file1: failed to wait for in-sequence write to 100 2020/11/03 06:00:22 ERROR : file1: WriteFileHandle.Write: can't seek in file without --vfs-cache-mode >= writes 2020/11/03 06:00:22 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': File to upload is small (11 bytes), uploading instead of streaming 2020/11/03 06:00:24 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 06:00:24 ERROR : file1: WriteFileHandle.New Rcat failed: upload file: json: cannot unmarshal string into Go struct field .value.size of type int write_test.go:162: Error Trace: write_test.go:162 Error: Received unexpected error: upload file: json: cannot unmarshal string into Go struct field .value.size of type int Test: TestWriteFileHandleWriteAt 2020/11/03 06:00:24 ERROR : file1: WriteFileHandle.Write: error: Bad file descriptor 2020/11/03 06:00:24 DEBUG : WaitForWriters: timeout=10s 2020/11/03 06:00:24 DEBUG : : Looking for writers 2020/11/03 06:00:24 DEBUG : file1: reading active writers 2020/11/03 06:00:24 DEBUG : file1: active writers 1 2020/11/03 06:00:24 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/11/03 06:00:24 DEBUG : : Looking for writers 2020/11/03 06:00:24 DEBUG : file1: reading active writers 2020/11/03 06:00:24 DEBUG : file1: active writers 1 2020/11/03 06:00:24 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/11/03 06:00:24 DEBUG : : Looking for writers 2020/11/03 06:00:24 DEBUG : file1: reading active writers 2020/11/03 06:00:24 DEBUG : file1: active writers 1 2020/11/03 06:00:24 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/11/03 06:00:24 DEBUG : : Looking for writers 2020/11/03 06:00:24 DEBUG : file1: reading active writers 2020/11/03 06:00:24 DEBUG : file1: active writers 1 2020/11/03 06:00:24 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/11/03 06:00:24 DEBUG : : Looking for writers 2020/11/03 06:00:24 DEBUG : file1: reading active writers 2020/11/03 06:00:24 DEBUG : file1: active writers 1 2020/11/03 06:00:24 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/11/03 06:00:25 DEBUG : : Looking for writers 2020/11/03 06:00:25 DEBUG : file1: reading active writers 2020/11/03 06:00:25 DEBUG : file1: active writers 1 2020/11/03 06:00:25 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/11/03 06:00:25 DEBUG : : Looking for writers 2020/11/03 06:00:25 DEBUG : file1: reading active writers 2020/11/03 06:00:25 DEBUG : file1: active writers 1 2020/11/03 06:00:25 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/11/03 06:00:26 DEBUG : : Looking for writers 2020/11/03 06:00:26 DEBUG : file1: reading active writers 2020/11/03 06:00:26 DEBUG : file1: active writers 1 2020/11/03 06:00:26 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:27 DEBUG : : Looking for writers 2020/11/03 06:00:27 DEBUG : file1: reading active writers 2020/11/03 06:00:27 DEBUG : file1: active writers 1 2020/11/03 06:00:27 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:28 DEBUG : : Looking for writers 2020/11/03 06:00:28 DEBUG : file1: reading active writers 2020/11/03 06:00:28 DEBUG : file1: active writers 1 2020/11/03 06:00:28 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:29 DEBUG : : Looking for writers 2020/11/03 06:00:29 DEBUG : file1: reading active writers 2020/11/03 06:00:29 DEBUG : file1: active writers 1 2020/11/03 06:00:29 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:30 DEBUG : : Looking for writers 2020/11/03 06:00:30 DEBUG : file1: reading active writers 2020/11/03 06:00:30 DEBUG : file1: active writers 1 2020/11/03 06:00:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:31 DEBUG : : Looking for writers 2020/11/03 06:00:31 DEBUG : file1: reading active writers 2020/11/03 06:00:31 DEBUG : file1: active writers 1 2020/11/03 06:00:31 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:32 DEBUG : : Looking for writers 2020/11/03 06:00:32 DEBUG : file1: reading active writers 2020/11/03 06:00:32 DEBUG : file1: active writers 1 2020/11/03 06:00:32 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:33 DEBUG : : Looking for writers 2020/11/03 06:00:33 DEBUG : file1: reading active writers 2020/11/03 06:00:33 DEBUG : file1: active writers 1 2020/11/03 06:00:33 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:34 DEBUG : : Looking for writers 2020/11/03 06:00:34 DEBUG : file1: reading active writers 2020/11/03 06:00:34 DEBUG : file1: active writers 1 2020/11/03 06:00:34 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:34 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/11/03 06:00:34 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleWriteAt (13.56s) === RUN TestWriteFileHandleFlush run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 06:00:35 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache 2020/11/03 06:00:35 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 06:00:35 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 06:00:35 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 06:00:35 DEBUG : file1: >Open: fd=file1 (w), err= 2020/11/03 06:00:35 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/11/03 06:00:35 DEBUG : file1: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions 2020/11/03 06:00:35 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 06:00:35 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': File to upload is small (5 bytes), uploading instead of streaming 2020/11/03 06:00:36 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 06:00:36 ERROR : file1: WriteFileHandle.New Rcat failed: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 06:00:36 ERROR : file1: WriteFileHandle.Flush error: upload file: json: cannot unmarshal string into Go struct field .value.size of type int write_test.go:198: Error Trace: write_test.go:198 Error: Received unexpected error: upload file: json: cannot unmarshal string into Go struct field .value.size of type int Test: TestWriteFileHandleFlush 2020/11/03 06:00:36 DEBUG : file1: WriteFileHandle.Flush nothing to do 2020/11/03 06:00:36 DEBUG : WaitForWriters: timeout=10s 2020/11/03 06:00:36 DEBUG : : Looking for writers 2020/11/03 06:00:36 DEBUG : file1: reading active writers 2020/11/03 06:00:36 DEBUG : file1: active writers 1 2020/11/03 06:00:36 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/11/03 06:00:36 DEBUG : : Looking for writers 2020/11/03 06:00:36 DEBUG : file1: reading active writers 2020/11/03 06:00:36 DEBUG : file1: active writers 1 2020/11/03 06:00:36 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/11/03 06:00:36 DEBUG : : Looking for writers 2020/11/03 06:00:36 DEBUG : file1: reading active writers 2020/11/03 06:00:36 DEBUG : file1: active writers 1 2020/11/03 06:00:36 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/11/03 06:00:36 DEBUG : : Looking for writers 2020/11/03 06:00:36 DEBUG : file1: reading active writers 2020/11/03 06:00:36 DEBUG : file1: active writers 1 2020/11/03 06:00:36 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/11/03 06:00:36 DEBUG : : Looking for writers 2020/11/03 06:00:36 DEBUG : file1: reading active writers 2020/11/03 06:00:36 DEBUG : file1: active writers 1 2020/11/03 06:00:36 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/11/03 06:00:36 DEBUG : : Looking for writers 2020/11/03 06:00:36 DEBUG : file1: reading active writers 2020/11/03 06:00:36 DEBUG : file1: active writers 1 2020/11/03 06:00:36 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/11/03 06:00:37 DEBUG : : Looking for writers 2020/11/03 06:00:37 DEBUG : file1: reading active writers 2020/11/03 06:00:37 DEBUG : file1: active writers 1 2020/11/03 06:00:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/11/03 06:00:37 DEBUG : : Looking for writers 2020/11/03 06:00:37 DEBUG : file1: reading active writers 2020/11/03 06:00:37 DEBUG : file1: active writers 1 2020/11/03 06:00:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:38 DEBUG : : Looking for writers 2020/11/03 06:00:38 DEBUG : file1: reading active writers 2020/11/03 06:00:38 DEBUG : file1: active writers 1 2020/11/03 06:00:38 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:39 DEBUG : : Looking for writers 2020/11/03 06:00:39 DEBUG : file1: reading active writers 2020/11/03 06:00:39 DEBUG : file1: active writers 1 2020/11/03 06:00:39 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:40 DEBUG : : Looking for writers 2020/11/03 06:00:40 DEBUG : file1: reading active writers 2020/11/03 06:00:40 DEBUG : file1: active writers 1 2020/11/03 06:00:40 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:41 DEBUG : : Looking for writers 2020/11/03 06:00:41 DEBUG : file1: reading active writers 2020/11/03 06:00:41 DEBUG : file1: active writers 1 2020/11/03 06:00:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:42 DEBUG : : Looking for writers 2020/11/03 06:00:42 DEBUG : file1: reading active writers 2020/11/03 06:00:42 DEBUG : file1: active writers 1 2020/11/03 06:00:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:43 DEBUG : : Looking for writers 2020/11/03 06:00:43 DEBUG : file1: reading active writers 2020/11/03 06:00:43 DEBUG : file1: active writers 1 2020/11/03 06:00:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:44 DEBUG : : Looking for writers 2020/11/03 06:00:44 DEBUG : file1: reading active writers 2020/11/03 06:00:44 DEBUG : file1: active writers 1 2020/11/03 06:00:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:45 DEBUG : : Looking for writers 2020/11/03 06:00:45 DEBUG : file1: reading active writers 2020/11/03 06:00:45 DEBUG : file1: active writers 1 2020/11/03 06:00:45 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:46 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/11/03 06:00:46 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleFlush (11.73s) === RUN TestWriteFileHandleRelease run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 06:00:46 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache 2020/11/03 06:00:46 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 06:00:46 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 06:00:46 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 06:00:46 DEBUG : file1: >Open: fd=file1 (w), err= 2020/11/03 06:00:46 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/11/03 06:00:46 DEBUG : file1: WriteFileHandle.Release closing 2020/11/03 06:00:46 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 06:00:46 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': File to upload is small (0 bytes), uploading instead of streaming 2020/11/03 06:00:48 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 06:00:48 ERROR : file1: WriteFileHandle.New Rcat failed: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 06:00:48 ERROR : file1: WriteFileHandle.Release error: upload file: json: cannot unmarshal string into Go struct field .value.size of type int write_test.go:222: Error Trace: write_test.go:222 Error: Received unexpected error: upload file: json: cannot unmarshal string into Go struct field .value.size of type int Test: TestWriteFileHandleRelease 2020/11/03 06:00:48 DEBUG : file1: WriteFileHandle.Release nothing to do 2020/11/03 06:00:48 DEBUG : WaitForWriters: timeout=10s 2020/11/03 06:00:48 DEBUG : : Looking for writers 2020/11/03 06:00:48 DEBUG : file1: reading active writers 2020/11/03 06:00:48 DEBUG : file1: active writers 1 2020/11/03 06:00:48 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/11/03 06:00:48 DEBUG : : Looking for writers 2020/11/03 06:00:48 DEBUG : file1: reading active writers 2020/11/03 06:00:48 DEBUG : file1: active writers 1 2020/11/03 06:00:48 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/11/03 06:00:48 DEBUG : : Looking for writers 2020/11/03 06:00:48 DEBUG : file1: reading active writers 2020/11/03 06:00:48 DEBUG : file1: active writers 1 2020/11/03 06:00:48 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/11/03 06:00:48 DEBUG : : Looking for writers 2020/11/03 06:00:48 DEBUG : file1: reading active writers 2020/11/03 06:00:48 DEBUG : file1: active writers 1 2020/11/03 06:00:48 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/11/03 06:00:48 DEBUG : : Looking for writers 2020/11/03 06:00:48 DEBUG : file1: reading active writers 2020/11/03 06:00:48 DEBUG : file1: active writers 1 2020/11/03 06:00:48 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/11/03 06:00:49 DEBUG : : Looking for writers 2020/11/03 06:00:49 DEBUG : file1: reading active writers 2020/11/03 06:00:49 DEBUG : file1: active writers 1 2020/11/03 06:00:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/11/03 06:00:49 DEBUG : : Looking for writers 2020/11/03 06:00:49 DEBUG : file1: reading active writers 2020/11/03 06:00:49 DEBUG : file1: active writers 1 2020/11/03 06:00:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/11/03 06:00:50 DEBUG : : Looking for writers 2020/11/03 06:00:50 DEBUG : file1: reading active writers 2020/11/03 06:00:50 DEBUG : file1: active writers 1 2020/11/03 06:00:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:51 DEBUG : : Looking for writers 2020/11/03 06:00:51 DEBUG : file1: reading active writers 2020/11/03 06:00:51 DEBUG : file1: active writers 1 2020/11/03 06:00:51 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:52 DEBUG : : Looking for writers 2020/11/03 06:00:52 DEBUG : file1: reading active writers 2020/11/03 06:00:52 DEBUG : file1: active writers 1 2020/11/03 06:00:52 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:53 DEBUG : : Looking for writers 2020/11/03 06:00:53 DEBUG : file1: reading active writers 2020/11/03 06:00:53 DEBUG : file1: active writers 1 2020/11/03 06:00:53 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:54 DEBUG : : Looking for writers 2020/11/03 06:00:54 DEBUG : file1: reading active writers 2020/11/03 06:00:54 DEBUG : file1: active writers 1 2020/11/03 06:00:54 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:55 DEBUG : : Looking for writers 2020/11/03 06:00:55 DEBUG : file1: reading active writers 2020/11/03 06:00:55 DEBUG : file1: active writers 1 2020/11/03 06:00:55 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:56 DEBUG : : Looking for writers 2020/11/03 06:00:56 DEBUG : file1: reading active writers 2020/11/03 06:00:56 DEBUG : file1: active writers 1 2020/11/03 06:00:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:57 DEBUG : : Looking for writers 2020/11/03 06:00:57 DEBUG : file1: reading active writers 2020/11/03 06:00:57 DEBUG : file1: active writers 1 2020/11/03 06:00:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:58 DEBUG : : Looking for writers 2020/11/03 06:00:58 DEBUG : file1: reading active writers 2020/11/03 06:00:58 DEBUG : file1: active writers 1 2020/11/03 06:00:58 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:00:58 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/11/03 06:00:58 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleRelease (12.28s) === RUN TestWriteFileModTimeWithOpenWriters run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 06:00:59 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache 2020/11/03 06:00:59 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 06:00:59 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 06:00:59 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 06:00:59 DEBUG : file1: >Open: fd=file1 (w), err= 2020/11/03 06:00:59 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/11/03 06:00:59 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 06:00:59 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': File to upload is small (2 bytes), uploading instead of streaming 2020/11/03 06:01:00 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 06:01:00 ERROR : file1: WriteFileHandle.New Rcat failed: upload file: json: cannot unmarshal string into Go struct field .value.size of type int write_test.go:277: Error Trace: write_test.go:277 Error: Received unexpected error: upload file: json: cannot unmarshal string into Go struct field .value.size of type int Test: TestWriteFileModTimeWithOpenWriters 2020/11/03 06:01:00 DEBUG : WaitForWriters: timeout=10s 2020/11/03 06:01:00 DEBUG : : Looking for writers 2020/11/03 06:01:00 DEBUG : file1: reading active writers 2020/11/03 06:01:00 DEBUG : file1: active writers 1 2020/11/03 06:01:00 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/11/03 06:01:00 DEBUG : : Looking for writers 2020/11/03 06:01:00 DEBUG : file1: reading active writers 2020/11/03 06:01:00 DEBUG : file1: active writers 1 2020/11/03 06:01:00 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/11/03 06:01:00 DEBUG : : Looking for writers 2020/11/03 06:01:00 DEBUG : file1: reading active writers 2020/11/03 06:01:00 DEBUG : file1: active writers 1 2020/11/03 06:01:00 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/11/03 06:01:00 DEBUG : : Looking for writers 2020/11/03 06:01:00 DEBUG : file1: reading active writers 2020/11/03 06:01:00 DEBUG : file1: active writers 1 2020/11/03 06:01:00 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/11/03 06:01:00 DEBUG : : Looking for writers 2020/11/03 06:01:00 DEBUG : file1: reading active writers 2020/11/03 06:01:00 DEBUG : file1: active writers 1 2020/11/03 06:01:00 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/11/03 06:01:01 DEBUG : : Looking for writers 2020/11/03 06:01:01 DEBUG : file1: reading active writers 2020/11/03 06:01:01 DEBUG : file1: active writers 1 2020/11/03 06:01:01 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/11/03 06:01:01 DEBUG : : Looking for writers 2020/11/03 06:01:01 DEBUG : file1: reading active writers 2020/11/03 06:01:01 DEBUG : file1: active writers 1 2020/11/03 06:01:01 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/11/03 06:01:01 DEBUG : : Looking for writers 2020/11/03 06:01:01 DEBUG : file1: reading active writers 2020/11/03 06:01:01 DEBUG : file1: active writers 1 2020/11/03 06:01:01 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:02 DEBUG : : Looking for writers 2020/11/03 06:01:02 DEBUG : file1: reading active writers 2020/11/03 06:01:02 DEBUG : file1: active writers 1 2020/11/03 06:01:02 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:03 DEBUG : : Looking for writers 2020/11/03 06:01:03 DEBUG : file1: reading active writers 2020/11/03 06:01:03 DEBUG : file1: active writers 1 2020/11/03 06:01:03 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:04 DEBUG : : Looking for writers 2020/11/03 06:01:04 DEBUG : file1: reading active writers 2020/11/03 06:01:04 DEBUG : file1: active writers 1 2020/11/03 06:01:04 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:05 DEBUG : : Looking for writers 2020/11/03 06:01:05 DEBUG : file1: reading active writers 2020/11/03 06:01:05 DEBUG : file1: active writers 1 2020/11/03 06:01:05 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:06 DEBUG : : Looking for writers 2020/11/03 06:01:06 DEBUG : file1: reading active writers 2020/11/03 06:01:06 DEBUG : file1: active writers 1 2020/11/03 06:01:06 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:07 DEBUG : : Looking for writers 2020/11/03 06:01:07 DEBUG : file1: reading active writers 2020/11/03 06:01:07 DEBUG : file1: active writers 1 2020/11/03 06:01:07 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:08 DEBUG : : Looking for writers 2020/11/03 06:01:08 DEBUG : file1: reading active writers 2020/11/03 06:01:08 DEBUG : file1: active writers 1 2020/11/03 06:01:08 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:09 DEBUG : : Looking for writers 2020/11/03 06:01:09 DEBUG : file1: reading active writers 2020/11/03 06:01:09 DEBUG : file1: active writers 1 2020/11/03 06:01:09 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:10 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/11/03 06:01:10 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileModTimeWithOpenWriters (11.89s) === RUN TestFileReadAtZeroLength run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 06:01:11 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache 2020/11/03 06:01:11 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 06:01:11 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 06:01:11 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 06:01:11 DEBUG : file1: >Open: fd=file1 (w), err= 2020/11/03 06:01:11 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/11/03 06:01:11 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 06:01:11 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': File to upload is small (0 bytes), uploading instead of streaming 2020/11/03 06:01:12 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 06:01:12 ERROR : file1: WriteFileHandle.New Rcat failed: upload file: json: cannot unmarshal string into Go struct field .value.size of type int write_test.go:305: Error Trace: write_test.go:305 write_test.go:325 Error: Received unexpected error: upload file: json: cannot unmarshal string into Go struct field .value.size of type int Test: TestFileReadAtZeroLength 2020/11/03 06:01:12 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2020/11/03 06:01:12 DEBUG : file1: Open: flags=O_RDONLY 2020/11/03 06:01:17 DEBUG : file1: >Open: fd=, err=file does not exist 2020/11/03 06:01:17 DEBUG : file1: >OpenFile: fd=, err=file does not exist write_test.go:310: Error Trace: write_test.go:310 write_test.go:325 Error: Received unexpected error: file does not exist Test: TestFileReadAtZeroLength 2020/11/03 06:01:17 DEBUG : WaitForWriters: timeout=10s 2020/11/03 06:01:17 DEBUG : : Looking for writers 2020/11/03 06:01:17 DEBUG : file1: reading active writers 2020/11/03 06:01:17 DEBUG : file1: active writers 1 2020/11/03 06:01:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/11/03 06:01:17 DEBUG : : Looking for writers 2020/11/03 06:01:17 DEBUG : file1: reading active writers 2020/11/03 06:01:17 DEBUG : file1: active writers 1 2020/11/03 06:01:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/11/03 06:01:17 DEBUG : : Looking for writers 2020/11/03 06:01:17 DEBUG : file1: reading active writers 2020/11/03 06:01:17 DEBUG : file1: active writers 1 2020/11/03 06:01:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/11/03 06:01:17 DEBUG : : Looking for writers 2020/11/03 06:01:17 DEBUG : file1: reading active writers 2020/11/03 06:01:17 DEBUG : file1: active writers 1 2020/11/03 06:01:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/11/03 06:01:17 DEBUG : : Looking for writers 2020/11/03 06:01:17 DEBUG : file1: reading active writers 2020/11/03 06:01:17 DEBUG : file1: active writers 1 2020/11/03 06:01:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/11/03 06:01:17 DEBUG : : Looking for writers 2020/11/03 06:01:17 DEBUG : file1: reading active writers 2020/11/03 06:01:17 DEBUG : file1: active writers 1 2020/11/03 06:01:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/11/03 06:01:18 DEBUG : : Looking for writers 2020/11/03 06:01:18 DEBUG : file1: reading active writers 2020/11/03 06:01:18 DEBUG : file1: active writers 1 2020/11/03 06:01:18 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/11/03 06:01:18 DEBUG : : Looking for writers 2020/11/03 06:01:18 DEBUG : file1: reading active writers 2020/11/03 06:01:18 DEBUG : file1: active writers 1 2020/11/03 06:01:18 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:19 DEBUG : : Looking for writers 2020/11/03 06:01:19 DEBUG : file1: reading active writers 2020/11/03 06:01:19 DEBUG : file1: active writers 1 2020/11/03 06:01:19 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:20 DEBUG : : Looking for writers 2020/11/03 06:01:20 DEBUG : file1: reading active writers 2020/11/03 06:01:20 DEBUG : file1: active writers 1 2020/11/03 06:01:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:21 DEBUG : : Looking for writers 2020/11/03 06:01:21 DEBUG : file1: reading active writers 2020/11/03 06:01:21 DEBUG : file1: active writers 1 2020/11/03 06:01:21 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:22 DEBUG : : Looking for writers 2020/11/03 06:01:22 DEBUG : file1: reading active writers 2020/11/03 06:01:22 DEBUG : file1: active writers 1 2020/11/03 06:01:22 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:23 DEBUG : : Looking for writers 2020/11/03 06:01:23 DEBUG : file1: reading active writers 2020/11/03 06:01:23 DEBUG : file1: active writers 1 2020/11/03 06:01:23 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:24 DEBUG : : Looking for writers 2020/11/03 06:01:24 DEBUG : file1: reading active writers 2020/11/03 06:01:24 DEBUG : file1: active writers 1 2020/11/03 06:01:24 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:25 DEBUG : : Looking for writers 2020/11/03 06:01:25 DEBUG : file1: reading active writers 2020/11/03 06:01:25 DEBUG : file1: active writers 1 2020/11/03 06:01:25 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:26 DEBUG : : Looking for writers 2020/11/03 06:01:26 DEBUG : file1: reading active writers 2020/11/03 06:01:26 DEBUG : file1: active writers 1 2020/11/03 06:01:26 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:27 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/11/03 06:01:27 DEBUG : >WaitForWriters: --- FAIL: TestFileReadAtZeroLength (17.22s) === RUN TestFileReadAtNonZeroLength run.go:176: Remote "sharefile root 'rclone-test-qitorax1dopocit5wihumur0'", Local "Local file system at /tmp/rclone593088746", Modify Window "1s" 2020/11/03 06:01:28 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Re-using VFS from active cache 2020/11/03 06:01:28 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 06:01:28 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 06:01:28 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 06:01:28 DEBUG : file1: >Open: fd=file1 (w), err= 2020/11/03 06:01:28 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/11/03 06:01:28 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 06:01:28 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': File to upload is small (100 bytes), uploading instead of streaming 2020/11/03 06:01:30 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 06:01:30 ERROR : file1: WriteFileHandle.New Rcat failed: upload file: json: cannot unmarshal string into Go struct field .value.size of type int write_test.go:305: Error Trace: write_test.go:305 write_test.go:329 Error: Received unexpected error: upload file: json: cannot unmarshal string into Go struct field .value.size of type int Test: TestFileReadAtNonZeroLength 2020/11/03 06:01:30 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2020/11/03 06:01:30 DEBUG : file1: Open: flags=O_RDONLY 2020/11/03 06:01:35 DEBUG : file1: >Open: fd=, err=file does not exist 2020/11/03 06:01:35 DEBUG : file1: >OpenFile: fd=, err=file does not exist write_test.go:310: Error Trace: write_test.go:310 write_test.go:329 Error: Received unexpected error: file does not exist Test: TestFileReadAtNonZeroLength 2020/11/03 06:01:35 DEBUG : WaitForWriters: timeout=10s 2020/11/03 06:01:35 DEBUG : : Looking for writers 2020/11/03 06:01:35 DEBUG : file1: reading active writers 2020/11/03 06:01:35 DEBUG : file1: active writers 1 2020/11/03 06:01:35 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/11/03 06:01:35 DEBUG : : Looking for writers 2020/11/03 06:01:35 DEBUG : file1: reading active writers 2020/11/03 06:01:35 DEBUG : file1: active writers 1 2020/11/03 06:01:35 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/11/03 06:01:35 DEBUG : : Looking for writers 2020/11/03 06:01:35 DEBUG : file1: reading active writers 2020/11/03 06:01:35 DEBUG : file1: active writers 1 2020/11/03 06:01:35 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/11/03 06:01:35 DEBUG : : Looking for writers 2020/11/03 06:01:35 DEBUG : file1: reading active writers 2020/11/03 06:01:35 DEBUG : file1: active writers 1 2020/11/03 06:01:35 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/11/03 06:01:35 DEBUG : : Looking for writers 2020/11/03 06:01:35 DEBUG : file1: reading active writers 2020/11/03 06:01:35 DEBUG : file1: active writers 1 2020/11/03 06:01:35 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/11/03 06:01:35 DEBUG : : Looking for writers 2020/11/03 06:01:35 DEBUG : file1: reading active writers 2020/11/03 06:01:35 DEBUG : file1: active writers 1 2020/11/03 06:01:35 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/11/03 06:01:35 DEBUG : : Looking for writers 2020/11/03 06:01:35 DEBUG : file1: reading active writers 2020/11/03 06:01:35 DEBUG : file1: active writers 1 2020/11/03 06:01:35 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/11/03 06:01:36 DEBUG : : Looking for writers 2020/11/03 06:01:36 DEBUG : file1: reading active writers 2020/11/03 06:01:36 DEBUG : file1: active writers 1 2020/11/03 06:01:36 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:37 DEBUG : : Looking for writers 2020/11/03 06:01:37 DEBUG : file1: reading active writers 2020/11/03 06:01:37 DEBUG : file1: active writers 1 2020/11/03 06:01:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:38 DEBUG : : Looking for writers 2020/11/03 06:01:38 DEBUG : file1: reading active writers 2020/11/03 06:01:38 DEBUG : file1: active writers 1 2020/11/03 06:01:38 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:39 DEBUG : : Looking for writers 2020/11/03 06:01:39 DEBUG : file1: reading active writers 2020/11/03 06:01:39 DEBUG : file1: active writers 1 2020/11/03 06:01:39 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:40 DEBUG : : Looking for writers 2020/11/03 06:01:40 DEBUG : file1: reading active writers 2020/11/03 06:01:40 DEBUG : file1: active writers 1 2020/11/03 06:01:40 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:41 DEBUG : : Looking for writers 2020/11/03 06:01:41 DEBUG : file1: reading active writers 2020/11/03 06:01:41 DEBUG : file1: active writers 1 2020/11/03 06:01:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:42 DEBUG : : Looking for writers 2020/11/03 06:01:42 DEBUG : file1: reading active writers 2020/11/03 06:01:42 DEBUG : file1: active writers 1 2020/11/03 06:01:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:43 DEBUG : : Looking for writers 2020/11/03 06:01:43 DEBUG : file1: reading active writers 2020/11/03 06:01:43 DEBUG : file1: active writers 1 2020/11/03 06:01:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:44 DEBUG : : Looking for writers 2020/11/03 06:01:44 DEBUG : file1: reading active writers 2020/11/03 06:01:44 DEBUG : file1: active writers 1 2020/11/03 06:01:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 06:01:45 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/11/03 06:01:45 DEBUG : >WaitForWriters: --- FAIL: TestFileReadAtNonZeroLength (17.52s) FAIL 2020/11/03 06:01:45 DEBUG : sharefile root 'rclone-test-qitorax1dopocit5wihumur0': Purge remote "./vfs.test -test.v -test.timeout 1h0m0s -remote TestSharefile: -verbose -test.run '^(TestDirCreate|TestDirForgetAll|TestDirForgetPath|TestDirHandleMethods|TestDirHandleReaddir|TestDirHandleReaddirnames|TestDirMethods|TestDirMkdir|TestDirMkdirSub|TestDirOpen|TestDirReadDirAll|TestDirRemove|TestDirRemoveAll|TestDirRemoveName|TestDirRename|TestDirSetModTime|TestDirStat|TestDirWalk|TestFileMethods|TestFileOpen|TestFileOpenRead|TestFileOpenWrite|TestFileReadAtNonZeroLength|TestFileReadAtZeroLength|TestFileRemove|TestFileRemoveAll|TestFileRename|TestFileSetModTime|TestRWFileHandleFlushRead|TestRWFileHandleMethodsRead|TestRWFileHandleMethodsWrite|TestRWFileHandleReadAt|TestRWFileHandleReleaseRead|TestRWFileHandleSeek|TestRWFileHandleSizeCreateExisting|TestRWFileHandleSizeTruncateExisting|TestRWFileHandleWriteAt|TestRWFileHandleWriteNoWrite|TestRWFileModTimeWithOpenWriters|TestRcGetVFS|TestReadFileHandleFlush|TestReadFileHandleMethods|TestReadFileHandleReadAt|TestReadFileHandleRelease|TestReadFileHandleSeek|TestVFSNew|TestVFSOpenFile|TestVFSRename|TestVFSStat|TestVFSStatParent|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleRelease|TestWriteFileHandleWriteAt|TestWriteFileModTimeWithOpenWriters)$/^(full,forceCache=false|minimal,forceCache=false|minimal,forceCache=true|off,forceCache=false|writes,forceCache=false|writes,forceCache=true)$'" - Finished ERROR in 4m21.160438331s (try 5/5): exit status 1: Failed [TestDirHandleMethods TestDirHandleReaddir TestDirHandleReaddirnames TestDirMethods TestDirForgetAll TestDirForgetPath TestDirWalk TestDirSetModTime TestDirStat TestDirReadDirAll TestDirOpen TestDirCreate TestDirMkdir TestDirMkdirSub TestDirRemove TestDirRemoveAll TestDirRemoveName TestDirRename TestFileMethods TestFileSetModTime TestFileOpenRead TestFileOpenWrite TestFileRemove TestFileRemoveAll TestFileOpen TestFileRename/off,forceCache=false TestFileRename/minimal,forceCache=false TestFileRename/minimal,forceCache=true TestFileRename/writes,forceCache=false TestFileRename/writes,forceCache=true TestFileRename/full,forceCache=false TestRcGetVFS TestReadFileHandleMethods TestReadFileHandleSeek TestReadFileHandleReadAt TestReadFileHandleFlush TestReadFileHandleRelease TestRWFileHandleMethodsRead TestRWFileHandleSeek TestRWFileHandleReadAt TestRWFileHandleFlushRead TestRWFileHandleReleaseRead TestRWFileHandleMethodsWrite TestRWFileHandleWriteAt TestRWFileHandleWriteNoWrite TestRWFileHandleSizeTruncateExisting TestRWFileHandleSizeCreateExisting TestRWFileModTimeWithOpenWriters TestVFSNew TestVFSStat TestVFSStatParent TestVFSOpenFile TestVFSRename TestWriteFileHandleMethods TestWriteFileHandleWriteAt TestWriteFileHandleFlush TestWriteFileHandleRelease TestWriteFileModTimeWithOpenWriters TestFileReadAtZeroLength TestFileReadAtNonZeroLength]