"./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 2/5) 2020/11/03 05:44:49 DEBUG : Creating backend with remote "TestSharefile:rclone-test-veyasip2qigezit0potiyug1" 2020/11/03 05:44:50 DEBUG : Creating backend with remote "/tmp/rclone389296597" === RUN TestDirHandleMethods run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:44:50 INFO : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': poll-interval is not supported by this remote run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirHandleMethods (2.55s) === RUN TestDirHandleReaddir run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:44:53 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:44:54 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:44:54 DEBUG : : Looking for writers 2020/11/03 05:44:54 DEBUG : >WaitForWriters: --- FAIL: TestDirHandleReaddir (2.41s) === RUN TestDirHandleReaddirnames run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:44:55 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirHandleReaddirnames (2.30s) === RUN TestDirMethods run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:44:57 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirMethods (1.55s) === RUN TestDirForgetAll run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:44:59 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirForgetAll (1.20s) === RUN TestDirForgetPath run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:00 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirForgetPath (1.42s) === RUN TestDirWalk run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:01 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirWalk (1.04s) === RUN TestDirSetModTime run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:02 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirSetModTime (1.63s) === RUN TestDirStat run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:04 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirStat (1.30s) === RUN TestDirReadDirAll run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:05 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:45:07 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:45:07 DEBUG : : Looking for writers 2020/11/03 05:45:07 DEBUG : >WaitForWriters: --- FAIL: TestDirReadDirAll (2.39s) === RUN TestDirOpen run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:08 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirOpen (1.92s) === RUN TestDirCreate run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:10 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirCreate (1.30s) === RUN TestDirMkdir run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:11 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirMkdir (1.03s) === RUN TestDirMkdirSub run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:12 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirMkdirSub (1.15s) === RUN TestDirRemove run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:13 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirRemove (0.84s) === RUN TestDirRemoveAll run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:14 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirRemoveAll (1.04s) === RUN TestDirRemoveName run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:15 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirRemoveName (1.44s) === RUN TestDirRename run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:17 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestDirRename (1.21s) === RUN TestFileMethods run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:18 INFO : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': poll-interval is not supported by this remote run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestFileMethods (1.41s) === RUN TestFileSetModTime run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:19 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestFileSetModTime (2.36s) === RUN TestFileOpenRead run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:21 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestFileOpenRead (1.89s) === RUN TestFileOpenWrite run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:23 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": 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-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:25 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestFileRemove (1.11s) === RUN TestFileRemoveAll run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:26 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestFileRemoveAll (1.21s) === RUN TestFileOpen run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:27 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestFileOpen (1.37s) === RUN TestFileRename === RUN TestFileRename/off,forceCache=false run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:28 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": 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-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:29 INFO : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': poll-interval is not supported by this remote 2020/11/03 05:45:29 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestSharefile/rclone-test-veyasip2qigezit0potiyug1" 2020/11/03 05:45:29 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestSharefile/rclone-test-veyasip2qigezit0potiyug1" 2020/11/03 05:45:29 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestSharefile/rclone-test-veyasip2qigezit0potiyug1" 2020/11/03 05:45:29 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-veyasip2qigezit0potiyug1'": 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-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:31 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": 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-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:32 INFO : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': poll-interval is not supported by this remote 2020/11/03 05:45:32 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestSharefile/rclone-test-veyasip2qigezit0potiyug1" 2020/11/03 05:45:32 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestSharefile/rclone-test-veyasip2qigezit0potiyug1" 2020/11/03 05:45:32 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-veyasip2qigezit0potiyug1'": 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-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:33 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": 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-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:34 INFO : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': poll-interval is not supported by this remote 2020/11/03 05:45:34 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestSharefile/rclone-test-veyasip2qigezit0potiyug1" 2020/11/03 05:45:34 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestSharefile/rclone-test-veyasip2qigezit0potiyug1" 2020/11/03 05:45:34 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-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestFileRename (7.28s) --- FAIL: TestFileRename/off,forceCache=false (1.01s) --- FAIL: TestFileRename/minimal,forceCache=false (1.53s) --- FAIL: TestFileRename/minimal,forceCache=true (1.19s) --- FAIL: TestFileRename/writes,forceCache=false (1.11s) --- FAIL: TestFileRename/writes,forceCache=true (1.15s) --- FAIL: TestFileRename/full,forceCache=false (1.28s) === 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-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:36 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': 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:45:36 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:45:36 DEBUG : : Looking for writers 2020/11/03 05:45:36 DEBUG : >WaitForWriters: --- FAIL: TestRcGetVFS (0.94s) === RUN TestReadFileHandleMethods run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:36 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestReadFileHandleMethods (1.92s) === RUN TestReadFileHandleSeek run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:38 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestReadFileHandleSeek (1.14s) === RUN TestReadFileHandleReadAt run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:40 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestReadFileHandleReadAt (1.21s) === RUN TestReadFileHandleFlush run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:41 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestReadFileHandleFlush (1.14s) === RUN TestReadFileHandleRelease run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:42 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestReadFileHandleRelease (1.40s) === RUN TestRWFileHandleMethodsRead run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:43 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestRWFileHandleMethodsRead (2.02s) === RUN TestRWFileHandleSeek run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:45 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestRWFileHandleSeek (1.18s) === RUN TestRWFileHandleReadAt run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:46 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestRWFileHandleReadAt (1.24s) === RUN TestRWFileHandleFlushRead run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:48 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestRWFileHandleFlushRead (1.62s) === RUN TestRWFileHandleReleaseRead run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:49 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestRWFileHandleReleaseRead (1.40s) === RUN TestRWFileHandleMethodsWrite run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:45:51 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache 2020/11/03 05:45:51 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 05:45:51 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 05:45:51 DEBUG : file1: newRWFileHandle: 2020/11/03 05:45:51 DEBUG : file1(0xc0005a3300): openPending: 2020/11/03 05:45:51 DEBUG : file1: vfs cache: truncate to size=0 2020/11/03 05:45:51 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:45:51 DEBUG : file1(0xc0005a3300): >openPending: err= 2020/11/03 05:45:51 DEBUG : file1: >newRWFileHandle: err= 2020/11/03 05:45:51 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:45:51 DEBUG : file1: >Open: fd=file1 (rw), err= 2020/11/03 05:45:51 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2020/11/03 05:45:51 DEBUG : file1(0xc0005a3300): _writeAt: size=5, off=0 2020/11/03 05:45:51 DEBUG : file1(0xc0005a3300): >_writeAt: n=5, err= 2020/11/03 05:45:51 DEBUG : file1(0xc0005a3300): _writeAt: size=7, off=5 2020/11/03 05:45:51 DEBUG : file1(0xc0005a3300): >_writeAt: n=7, err= 2020/11/03 05:45:51 DEBUG : file1: vfs cache: truncate to size=11 2020/11/03 05:45:51 DEBUG : file1(0xc0005a3300): close: 2020/11/03 05:45:51 DEBUG : file1: vfs cache: setting modification time to 2020-11-03 05:45:51.339851825 +0000 UTC m=+61.605076300 2020/11/03 05:45:51 INFO : file1: vfs cache: queuing for upload in 100ms 2020/11/03 05:45:51 DEBUG : file1(0xc0005a3300): >close: err= 2020/11/03 05:45:51 DEBUG : file1(0xc0005a3300): close: 2020/11/03 05:45:51 DEBUG : file1(0xc0005a3300): >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:45:51 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:45:51 DEBUG : dir: Looking for writers 2020/11/03 05:45:51 DEBUG : : Looking for writers 2020/11/03 05:45:51 DEBUG : dir: reading active writers 2020/11/03 05:45:51 DEBUG : file1: reading active writers 2020/11/03 05:45:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2020/11/03 05:45:51 DEBUG : dir: Looking for writers 2020/11/03 05:45:51 DEBUG : : Looking for writers 2020/11/03 05:45:51 DEBUG : dir: reading active writers 2020/11/03 05:45:51 DEBUG : file1: reading active writers 2020/11/03 05:45:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2020/11/03 05:45:51 DEBUG : dir: Looking for writers 2020/11/03 05:45:51 DEBUG : : Looking for writers 2020/11/03 05:45:51 DEBUG : dir: reading active writers 2020/11/03 05:45:51 DEBUG : file1: reading active writers 2020/11/03 05:45:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2020/11/03 05:45:51 DEBUG : dir: Looking for writers 2020/11/03 05:45:51 DEBUG : : Looking for writers 2020/11/03 05:45:51 DEBUG : file1: reading active writers 2020/11/03 05:45:51 DEBUG : dir: reading active writers 2020/11/03 05:45:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2020/11/03 05:45:51 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:45:51 DEBUG : dir: Looking for writers 2020/11/03 05:45:51 DEBUG : : Looking for writers 2020/11/03 05:45:51 DEBUG : dir: reading active writers 2020/11/03 05:45:51 DEBUG : file1: reading active writers 2020/11/03 05:45:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2020/11/03 05:45:51 DEBUG : dir: Looking for writers 2020/11/03 05:45:51 DEBUG : : Looking for writers 2020/11/03 05:45:51 DEBUG : file1: reading active writers 2020/11/03 05:45:51 DEBUG : dir: reading active writers 2020/11/03 05:45:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2020/11/03 05:45:51 DEBUG : dir: Looking for writers 2020/11/03 05:45:51 DEBUG : : Looking for writers 2020/11/03 05:45:51 DEBUG : dir: reading active writers 2020/11/03 05:45:51 DEBUG : file1: reading active writers 2020/11/03 05:45:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2020/11/03 05:45:52 DEBUG : dir: Looking for writers 2020/11/03 05:45:52 DEBUG : : Looking for writers 2020/11/03 05:45:52 DEBUG : dir: reading active writers 2020/11/03 05:45:52 DEBUG : file1: reading active writers 2020/11/03 05:45:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:45:52 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:45:52 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:45:52 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:45:53 DEBUG : dir: Looking for writers 2020/11/03 05:45:53 DEBUG : : Looking for writers 2020/11/03 05:45:53 DEBUG : dir: reading active writers 2020/11/03 05:45:53 DEBUG : file1: reading active writers 2020/11/03 05:45:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:45: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:45: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:45:54 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:45:54 DEBUG : dir: Looking for writers 2020/11/03 05:45:54 DEBUG : : Looking for writers 2020/11/03 05:45:54 DEBUG : dir: reading active writers 2020/11/03 05:45:54 DEBUG : file1: reading active writers 2020/11/03 05:45:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:45:55 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:45:55 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:45:55 DEBUG : dir: Looking for writers 2020/11/03 05:45:55 DEBUG : : Looking for writers 2020/11/03 05:45:55 DEBUG : file1: reading active writers 2020/11/03 05:45:55 DEBUG : dir: reading active writers 2020/11/03 05:45:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:45:56 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:45:56 DEBUG : dir: Looking for writers 2020/11/03 05:45:56 DEBUG : : Looking for writers 2020/11/03 05:45:56 DEBUG : dir: reading active writers 2020/11/03 05:45:56 DEBUG : file1: reading active writers 2020/11/03 05:45:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:45:57 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:45:57 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:45:57 DEBUG : dir: Looking for writers 2020/11/03 05:45:57 DEBUG : : Looking for writers 2020/11/03 05:45:57 DEBUG : dir: reading active writers 2020/11/03 05:45:57 DEBUG : file1: reading active writers 2020/11/03 05:45:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:45:58 DEBUG : dir: Looking for writers 2020/11/03 05:45:58 DEBUG : : Looking for writers 2020/11/03 05:45:58 DEBUG : file1: reading active writers 2020/11/03 05:45:58 DEBUG : dir: reading active writers 2020/11/03 05:45:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:45:58 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:45:59 DEBUG : dir: Looking for writers 2020/11/03 05:45:59 DEBUG : : Looking for writers 2020/11/03 05:45:59 DEBUG : file1: reading active writers 2020/11/03 05:45:59 DEBUG : dir: reading active writers 2020/11/03 05:45:59 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:00 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:00 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:46:00 DEBUG : dir: Looking for writers 2020/11/03 05:46:00 DEBUG : : Looking for writers 2020/11/03 05:46:00 DEBUG : dir: reading active writers 2020/11/03 05:46:00 DEBUG : file1: reading active writers 2020/11/03 05:46:00 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:01 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s Cache{ "file1": &{c:0xc00024aa80 mu:{state:0 sema:0} cond:0xc0005a3280 name:file1 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13826149278764087857 ext:61605076300 loc:0x266c360} ATime:{wall:13826149278764111871 ext:61605100270 loc:0x266c360} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, } 2020/11/03 05:46:01 DEBUG : >WaitForWriters: 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 2020/11/03 05:46:03 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:46:04 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:04 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: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 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:46:09 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:46:09 DEBUG : dir: Looking for writers 2020/11/03 05:46:09 DEBUG : : Looking for writers 2020/11/03 05:46:09 DEBUG : dir: reading active writers 2020/11/03 05:46:09 DEBUG : file1: reading active writers 2020/11/03 05:46:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2020/11/03 05:46:09 DEBUG : dir: Looking for writers 2020/11/03 05:46:09 DEBUG : : Looking for writers 2020/11/03 05:46:09 DEBUG : dir: reading active writers 2020/11/03 05:46:09 DEBUG : file1: reading active writers 2020/11/03 05:46:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2020/11/03 05:46:09 DEBUG : dir: Looking for writers 2020/11/03 05:46:09 DEBUG : : Looking for writers 2020/11/03 05:46:09 DEBUG : dir: reading active writers 2020/11/03 05:46:09 DEBUG : file1: reading active writers 2020/11/03 05:46:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2020/11/03 05:46:09 DEBUG : dir: Looking for writers 2020/11/03 05:46:09 DEBUG : : Looking for writers 2020/11/03 05:46:09 DEBUG : dir: reading active writers 2020/11/03 05:46:09 DEBUG : file1: reading active writers 2020/11/03 05:46:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2020/11/03 05:46:09 DEBUG : dir: Looking for writers 2020/11/03 05:46:09 DEBUG : : Looking for writers 2020/11/03 05:46:09 DEBUG : dir: reading active writers 2020/11/03 05:46:09 DEBUG : file1: reading active writers 2020/11/03 05:46:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2020/11/03 05:46:09 DEBUG : dir: Looking for writers 2020/11/03 05:46:09 DEBUG : : Looking for writers 2020/11/03 05:46:09 DEBUG : dir: reading active writers 2020/11/03 05:46:09 DEBUG : file1: reading active writers 2020/11/03 05:46:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2020/11/03 05:46:10 DEBUG : dir: Looking for writers 2020/11/03 05:46:10 DEBUG : : Looking for writers 2020/11/03 05:46:10 DEBUG : dir: reading active writers 2020/11/03 05:46:10 DEBUG : file1: reading active writers 2020/11/03 05:46:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2020/11/03 05:46:10 DEBUG : dir: Looking for writers 2020/11/03 05:46:10 DEBUG : : Looking for writers 2020/11/03 05:46:10 DEBUG : dir: reading active writers 2020/11/03 05:46:10 DEBUG : file1: reading active writers 2020/11/03 05:46:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:11 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:46:11 DEBUG : dir: Looking for writers 2020/11/03 05:46:11 DEBUG : : Looking for writers 2020/11/03 05:46:11 DEBUG : dir: reading active writers 2020/11/03 05:46:11 DEBUG : file1: reading active writers 2020/11/03 05:46:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:12 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:12 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:46:12 DEBUG : dir: Looking for writers 2020/11/03 05:46:12 DEBUG : : Looking for writers 2020/11/03 05:46:12 DEBUG : dir: reading active writers 2020/11/03 05:46:12 DEBUG : file1: reading active writers 2020/11/03 05:46:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:13 DEBUG : dir: Looking for writers 2020/11/03 05:46:13 DEBUG : : Looking for writers 2020/11/03 05:46:13 DEBUG : dir: reading active writers 2020/11/03 05:46:13 DEBUG : file1: reading active writers 2020/11/03 05:46:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:14 DEBUG : dir: Looking for writers 2020/11/03 05:46:14 DEBUG : : Looking for writers 2020/11/03 05:46:14 DEBUG : file1: reading active writers 2020/11/03 05:46:14 DEBUG : dir: reading active writers 2020/11/03 05:46:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:15 DEBUG : dir: Looking for writers 2020/11/03 05:46:15 DEBUG : : Looking for writers 2020/11/03 05:46:15 DEBUG : dir: reading active writers 2020/11/03 05:46:15 DEBUG : file1: reading active writers 2020/11/03 05:46:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:16 DEBUG : dir: Looking for writers 2020/11/03 05:46:16 DEBUG : : Looking for writers 2020/11/03 05:46:16 DEBUG : dir: reading active writers 2020/11/03 05:46:16 DEBUG : file1: reading active writers 2020/11/03 05:46:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:17 DEBUG : dir: Looking for writers 2020/11/03 05:46:17 DEBUG : : Looking for writers 2020/11/03 05:46:17 DEBUG : dir: reading active writers 2020/11/03 05:46:17 DEBUG : file1: reading active writers 2020/11/03 05:46:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:18 DEBUG : dir: Looking for writers 2020/11/03 05:46:18 DEBUG : : Looking for writers 2020/11/03 05:46:18 DEBUG : dir: reading active writers 2020/11/03 05:46:18 DEBUG : file1: reading active writers 2020/11/03 05:46:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:19 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s Cache{ "file1": &{c:0xc00024aa80 mu:{state:0 sema:0} cond:0xc0005a3280 name:file1 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13826149278764087857 ext:61605076300 loc:0x266c360} ATime:{wall:13826149278764111871 ext:61605100270 loc:0x266c360} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, } 2020/11/03 05:46:19 DEBUG : >WaitForWriters: --- FAIL: TestRWFileHandleMethodsWrite (29.71s) === RUN TestRWFileHandleWriteAt run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:46:20 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache 2020/11/03 05:46:20 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 05:46:20 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 05:46:20 DEBUG : file1: newRWFileHandle: 2020/11/03 05:46:20 DEBUG : file1(0xc00007c8c0): openPending: 2020/11/03 05:46:20 ERROR : file1: vfs cache: detected external removal of cache file 2020/11/03 05:46:20 DEBUG : file1: vfs cache: truncate to size=0 2020/11/03 05:46:20 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:46:20 DEBUG : file1(0xc00007c8c0): >openPending: err= 2020/11/03 05:46:20 DEBUG : file1: vfs cache: cancelling writeback (uploading false) 0xc0003141c0 item 1 2020/11/03 05:46:20 DEBUG : file1: >newRWFileHandle: err= 2020/11/03 05:46:20 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:46:20 DEBUG : file1: >Open: fd=file1 (rw), err= 2020/11/03 05:46:20 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2020/11/03 05:46:20 DEBUG : file1(0xc00007c8c0): _writeAt: size=7, off=0 2020/11/03 05:46:20 DEBUG : file1(0xc00007c8c0): >_writeAt: n=7, err= 2020/11/03 05:46:20 DEBUG : file1(0xc00007c8c0): _writeAt: size=6, off=5 2020/11/03 05:46:20 DEBUG : file1(0xc00007c8c0): >_writeAt: n=6, err= 2020/11/03 05:46:20 DEBUG : file1(0xc00007c8c0): close: 2020/11/03 05:46:20 DEBUG : file1: vfs cache: setting modification time to 2020-11-03 05:46:20.930468349 +0000 UTC m=+91.195692766 2020/11/03 05:46:20 INFO : file1: vfs cache: queuing for upload in 100ms 2020/11/03 05:46:20 DEBUG : file1(0xc00007c8c0): >close: err= 2020/11/03 05:46:20 DEBUG : file1(0xc00007c8c0): _writeAt: size=5, off=0 2020/11/03 05:46:20 DEBUG : file1(0xc00007c8c0): >_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:46:20 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:46:20 DEBUG : dir: Looking for writers 2020/11/03 05:46:20 DEBUG : : Looking for writers 2020/11/03 05:46:20 DEBUG : dir: reading active writers 2020/11/03 05:46:20 DEBUG : file1: reading active writers 2020/11/03 05:46:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2020/11/03 05:46:20 DEBUG : dir: Looking for writers 2020/11/03 05:46:20 DEBUG : : Looking for writers 2020/11/03 05:46:20 DEBUG : dir: reading active writers 2020/11/03 05:46:20 DEBUG : file1: reading active writers 2020/11/03 05:46:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2020/11/03 05:46:20 DEBUG : dir: Looking for writers 2020/11/03 05:46:20 DEBUG : : Looking for writers 2020/11/03 05:46:20 DEBUG : dir: reading active writers 2020/11/03 05:46:20 DEBUG : file1: reading active writers 2020/11/03 05:46:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2020/11/03 05:46:21 DEBUG : dir: Looking for writers 2020/11/03 05:46:21 DEBUG : : Looking for writers 2020/11/03 05:46:21 DEBUG : dir: reading active writers 2020/11/03 05:46:21 DEBUG : file1: reading active writers 2020/11/03 05:46:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2020/11/03 05:46:21 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:46:21 DEBUG : dir: Looking for writers 2020/11/03 05:46:21 DEBUG : : Looking for writers 2020/11/03 05:46:21 DEBUG : dir: reading active writers 2020/11/03 05:46:21 DEBUG : file1: reading active writers 2020/11/03 05:46:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2020/11/03 05:46:21 DEBUG : dir: Looking for writers 2020/11/03 05:46:21 DEBUG : : Looking for writers 2020/11/03 05:46:21 DEBUG : dir: reading active writers 2020/11/03 05:46:21 DEBUG : file1: reading active writers 2020/11/03 05:46:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2020/11/03 05:46:21 DEBUG : dir: Looking for writers 2020/11/03 05:46:21 DEBUG : : Looking for writers 2020/11/03 05:46:21 DEBUG : dir: reading active writers 2020/11/03 05:46:21 DEBUG : file1: reading active writers 2020/11/03 05:46:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2020/11/03 05:46:22 DEBUG : dir: Looking for writers 2020/11/03 05:46:22 DEBUG : : Looking for writers 2020/11/03 05:46:22 DEBUG : file1: reading active writers 2020/11/03 05:46:22 DEBUG : dir: reading active writers 2020/11/03 05:46:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:22 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:22 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:46:22 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:46:23 DEBUG : dir: Looking for writers 2020/11/03 05:46:23 DEBUG : : Looking for writers 2020/11/03 05:46:23 DEBUG : file1: reading active writers 2020/11/03 05:46:23 DEBUG : dir: reading active writers 2020/11/03 05:46:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:24 DEBUG : dir: Looking for writers 2020/11/03 05:46:24 DEBUG : : Looking for writers 2020/11/03 05:46:24 DEBUG : file1: reading active writers 2020/11/03 05:46:24 DEBUG : dir: reading active writers 2020/11/03 05:46:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:24 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:24 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:46:24 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:46:25 DEBUG : dir: Looking for writers 2020/11/03 05:46:25 DEBUG : : Looking for writers 2020/11/03 05:46:25 DEBUG : dir: reading active writers 2020/11/03 05:46:25 DEBUG : file1: reading active writers 2020/11/03 05:46:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46: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:46:25 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:46:26 DEBUG : dir: Looking for writers 2020/11/03 05:46:26 DEBUG : : Looking for writers 2020/11/03 05:46:26 DEBUG : file1: reading active writers 2020/11/03 05:46:26 DEBUG : dir: reading active writers 2020/11/03 05:46:26 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:26 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:46:27 DEBUG : dir: Looking for writers 2020/11/03 05:46:27 DEBUG : : Looking for writers 2020/11/03 05:46:27 DEBUG : dir: reading active writers 2020/11/03 05:46:27 DEBUG : file1: reading active writers 2020/11/03 05:46:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:28 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:28 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:46:28 DEBUG : dir: Looking for writers 2020/11/03 05:46:28 DEBUG : : Looking for writers 2020/11/03 05:46:28 DEBUG : dir: reading active writers 2020/11/03 05:46:28 DEBUG : file1: reading active writers 2020/11/03 05:46:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:29 DEBUG : dir: Looking for writers 2020/11/03 05:46:29 DEBUG : : Looking for writers 2020/11/03 05:46:29 DEBUG : dir: reading active writers 2020/11/03 05:46:29 DEBUG : file1: reading active writers 2020/11/03 05:46:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:29 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:46:29 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:46:30 DEBUG : dir: Looking for writers 2020/11/03 05:46:30 DEBUG : : Looking for writers 2020/11/03 05:46:30 DEBUG : dir: reading active writers 2020/11/03 05:46:30 DEBUG : file1: reading active writers 2020/11/03 05:46:30 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:30 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:30 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:46:30 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s Cache{ "file1": &{c:0xc00024aa80 mu:{state:0 sema:0} cond:0xc0005a3280 name:file1 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13826149310493217277 ext:91195692766 loc:0x266c360} ATime:{wall:13826149310493232629 ext:91195708119 loc:0x266c360} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, } 2020/11/03 05:46:30 DEBUG : >WaitForWriters: 2020/11/03 05:46:31 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:46:31 DEBUG : dir: Looking for writers 2020/11/03 05:46:31 DEBUG : : Looking for writers 2020/11/03 05:46:31 DEBUG : dir: reading active writers 2020/11/03 05:46:31 DEBUG : file1: reading active writers 2020/11/03 05:46:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2020/11/03 05:46:31 DEBUG : dir: Looking for writers 2020/11/03 05:46:31 DEBUG : : Looking for writers 2020/11/03 05:46:31 DEBUG : dir: reading active writers 2020/11/03 05:46:31 DEBUG : file1: reading active writers 2020/11/03 05:46:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2020/11/03 05:46:31 DEBUG : dir: Looking for writers 2020/11/03 05:46:31 DEBUG : : Looking for writers 2020/11/03 05:46:31 DEBUG : dir: reading active writers 2020/11/03 05:46:31 DEBUG : file1: reading active writers 2020/11/03 05:46:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2020/11/03 05:46:31 DEBUG : dir: Looking for writers 2020/11/03 05:46:31 DEBUG : : Looking for writers 2020/11/03 05:46:31 DEBUG : dir: reading active writers 2020/11/03 05:46:31 DEBUG : file1: reading active writers 2020/11/03 05:46:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2020/11/03 05:46:31 DEBUG : dir: Looking for writers 2020/11/03 05:46:31 DEBUG : : Looking for writers 2020/11/03 05:46:31 DEBUG : dir: reading active writers 2020/11/03 05:46:31 DEBUG : file1: reading active writers 2020/11/03 05:46:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2020/11/03 05:46:31 DEBUG : dir: Looking for writers 2020/11/03 05:46:31 DEBUG : : Looking for writers 2020/11/03 05:46:31 DEBUG : dir: reading active writers 2020/11/03 05:46:31 DEBUG : file1: reading active writers 2020/11/03 05:46:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2020/11/03 05:46:31 DEBUG : dir: Looking for writers 2020/11/03 05:46:31 DEBUG : : Looking for writers 2020/11/03 05:46:31 DEBUG : dir: reading active writers 2020/11/03 05:46:31 DEBUG : file1: reading active writers 2020/11/03 05:46:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2020/11/03 05:46:32 DEBUG : dir: Looking for writers 2020/11/03 05:46:32 DEBUG : : Looking for writers 2020/11/03 05:46:32 DEBUG : file1: reading active writers 2020/11/03 05:46:32 DEBUG : dir: reading active writers 2020/11/03 05:46:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:32 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:46:33 DEBUG : dir: Looking for writers 2020/11/03 05:46:33 DEBUG : : Looking for writers 2020/11/03 05:46:33 DEBUG : dir: reading active writers 2020/11/03 05:46:33 DEBUG : file1: reading active writers 2020/11/03 05:46:33 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:33 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:46:34 DEBUG : dir: Looking for writers 2020/11/03 05:46:34 DEBUG : : Looking for writers 2020/11/03 05:46:34 DEBUG : dir: reading active writers 2020/11/03 05:46:34 DEBUG : file1: reading active writers 2020/11/03 05:46:34 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:34 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2020/11/03 05:46:34 INFO : vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 0, uploading 1, total size 11 (was 11) 2020/11/03 05:46:34 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:34 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:46:35 DEBUG : dir: Looking for writers 2020/11/03 05:46:35 DEBUG : : Looking for writers 2020/11/03 05:46:35 DEBUG : dir: reading active writers 2020/11/03 05:46:35 DEBUG : file1: reading active writers 2020/11/03 05:46:35 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:36 DEBUG : dir: Looking for writers 2020/11/03 05:46:36 DEBUG : : Looking for writers 2020/11/03 05:46:36 DEBUG : dir: reading active writers 2020/11/03 05:46:36 DEBUG : file1: reading active writers 2020/11/03 05:46:36 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:37 DEBUG : dir: Looking for writers 2020/11/03 05:46:37 DEBUG : : Looking for writers 2020/11/03 05:46:37 DEBUG : dir: reading active writers 2020/11/03 05:46:37 DEBUG : file1: reading active writers 2020/11/03 05:46:37 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:38 DEBUG : dir: Looking for writers 2020/11/03 05:46:38 DEBUG : : Looking for writers 2020/11/03 05:46:38 DEBUG : dir: reading active writers 2020/11/03 05:46:38 DEBUG : file1: reading active writers 2020/11/03 05:46:38 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:39 DEBUG : dir: Looking for writers 2020/11/03 05:46:39 DEBUG : : Looking for writers 2020/11/03 05:46:39 DEBUG : dir: reading active writers 2020/11/03 05:46:39 DEBUG : file1: reading active writers 2020/11/03 05:46:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:40 DEBUG : dir: Looking for writers 2020/11/03 05:46:40 DEBUG : : Looking for writers 2020/11/03 05:46:40 DEBUG : dir: reading active writers 2020/11/03 05:46:40 DEBUG : file1: reading active writers 2020/11/03 05:46:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:46:41 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s Cache{ "file1": &{c:0xc00024aa80 mu:{state:0 sema:0} cond:0xc0005a3280 name:file1 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13826149310493217277 ext:91195692766 loc:0x266c360} ATime:{wall:13826149310493232629 ext:91195708119 loc:0x266c360} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, } 2020/11/03 05:46:41 DEBUG : >WaitForWriters: 2020/11/03 05:46:41 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:46:41 ERROR : file1: vfs cache: failed to write metadata file: vfs cache item: failed to write metadata: open /home/rclone/.cache/rclone/vfsMeta/TestSharefile/rclone-test-veyasip2qigezit0potiyug1/file1: no such file or directory 2020/11/03 05:46:41 INFO : file1: vfs cache: upload succeeded try #7 --- FAIL: TestRWFileHandleWriteAt (20.71s) === RUN TestRWFileHandleWriteNoWrite run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:46:41 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache 2020/11/03 05:46:41 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 05:46:41 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 05:46:41 DEBUG : file1: newRWFileHandle: 2020/11/03 05:46:41 DEBUG : file1(0xc000629200): openPending: 2020/11/03 05:46:41 ERROR : file1: vfs cache: detected external removal of cache file 2020/11/03 05:46:41 DEBUG : file1: vfs cache: truncate to size=0 2020/11/03 05:46:41 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:46:41 DEBUG : file1(0xc000629200): >openPending: err= 2020/11/03 05:46:41 DEBUG : file1: >newRWFileHandle: err= 2020/11/03 05:46:41 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:46:41 DEBUG : file1: >Open: fd=file1 (rw), err= 2020/11/03 05:46:41 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2020/11/03 05:46:41 DEBUG : file1(0xc000629200): close: 2020/11/03 05:46:41 DEBUG : file1: vfs cache: setting modification time to 2020-11-03 05:46:41.643964227 +0000 UTC m=+111.909188662 2020/11/03 05:46:41 INFO : file1: vfs cache: queuing for upload in 100ms 2020/11/03 05:46:41 DEBUG : file1(0xc000629200): >close: err= 2020/11/03 05:46:41 DEBUG : file2: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx 2020/11/03 05:46:41 DEBUG : file2: Open: flags=O_WRONLY|O_CREATE|O_TRUNC 2020/11/03 05:46:41 DEBUG : file2: newRWFileHandle: 2020/11/03 05:46:41 DEBUG : file2(0xc000629300): openPending: 2020/11/03 05:46:41 DEBUG : file2: vfs cache: truncate to size=0 2020/11/03 05:46:41 DEBUG : : Added virtual directory entry vAdd: "file2" 2020/11/03 05:46:41 DEBUG : file2(0xc000629300): >openPending: err= 2020/11/03 05:46:41 DEBUG : file2: >newRWFileHandle: err= 2020/11/03 05:46:41 DEBUG : : Added virtual directory entry vAdd: "file2" 2020/11/03 05:46:41 DEBUG : file2: >Open: fd=file2 (rw), err= 2020/11/03 05:46:41 DEBUG : file2: >OpenFile: fd=file2 (rw), err= 2020/11/03 05:46:41 DEBUG : file2(0xc000629300): RWFileHandle.Flush 2020/11/03 05:46:41 DEBUG : file2(0xc000629300): RWFileHandle.Release 2020/11/03 05:46:41 DEBUG : file2(0xc000629300): close: 2020/11/03 05:46:41 DEBUG : file2: vfs cache: setting modification time to 2020-11-03 05:46:41.644725365 +0000 UTC m=+111.909949785 2020/11/03 05:46:41 INFO : file2: vfs cache: queuing for upload in 100ms 2020/11/03 05:46:41 DEBUG : file2(0xc000629300): >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:46:41 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:46:41 DEBUG : dir: Looking for writers 2020/11/03 05:46:41 DEBUG : : Looking for writers 2020/11/03 05:46:41 DEBUG : dir: reading active writers 2020/11/03 05:46:41 DEBUG : file1: reading active writers 2020/11/03 05:46:41 DEBUG : file2: reading active writers 2020/11/03 05:46:41 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms 2020/11/03 05:46:41 DEBUG : dir: Looking for writers 2020/11/03 05:46:41 DEBUG : : Looking for writers 2020/11/03 05:46:41 DEBUG : dir: reading active writers 2020/11/03 05:46:41 DEBUG : file1: reading active writers 2020/11/03 05:46:41 DEBUG : file2: reading active writers 2020/11/03 05:46:41 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms 2020/11/03 05:46:41 DEBUG : dir: Looking for writers 2020/11/03 05:46:41 DEBUG : : Looking for writers 2020/11/03 05:46:41 DEBUG : dir: reading active writers 2020/11/03 05:46:41 DEBUG : file1: reading active writers 2020/11/03 05:46:41 DEBUG : file2: reading active writers 2020/11/03 05:46:41 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms 2020/11/03 05:46:41 DEBUG : dir: Looking for writers 2020/11/03 05:46:41 DEBUG : : Looking for writers 2020/11/03 05:46:41 DEBUG : dir: reading active writers 2020/11/03 05:46:41 DEBUG : file1: reading active writers 2020/11/03 05:46:41 DEBUG : file2: reading active writers 2020/11/03 05:46:41 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms 2020/11/03 05:46:41 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:46:41 DEBUG : file2: vfs cache: starting upload 2020/11/03 05:46:41 DEBUG : dir: Looking for writers 2020/11/03 05:46:41 DEBUG : : Looking for writers 2020/11/03 05:46:41 DEBUG : dir: reading active writers 2020/11/03 05:46:41 DEBUG : file1: reading active writers 2020/11/03 05:46:41 DEBUG : file2: reading active writers 2020/11/03 05:46:41 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms 2020/11/03 05:46:41 DEBUG : dir: Looking for writers 2020/11/03 05:46:41 DEBUG : : Looking for writers 2020/11/03 05:46:41 DEBUG : dir: reading active writers 2020/11/03 05:46:41 DEBUG : file1: reading active writers 2020/11/03 05:46:41 DEBUG : file2: reading active writers 2020/11/03 05:46:41 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms 2020/11/03 05:46:42 DEBUG : dir: Looking for writers 2020/11/03 05:46:42 DEBUG : : Looking for writers 2020/11/03 05:46:42 DEBUG : dir: reading active writers 2020/11/03 05:46:42 DEBUG : file1: reading active writers 2020/11/03 05:46:42 DEBUG : file2: reading active writers 2020/11/03 05:46:42 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms 2020/11/03 05:46:42 DEBUG : dir: Looking for writers 2020/11/03 05:46:42 DEBUG : : Looking for writers 2020/11/03 05:46:42 DEBUG : dir: reading active writers 2020/11/03 05:46:42 DEBUG : file1: reading active writers 2020/11/03 05:46:42 DEBUG : file2: reading active writers 2020/11/03 05:46:42 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:46:43 ERROR : file2: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:43 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:46:43 DEBUG : file2: vfs cache: starting upload 2020/11/03 05:46:43 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:43 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:46:43 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:46:43 DEBUG : dir: Looking for writers 2020/11/03 05:46:43 DEBUG : : Looking for writers 2020/11/03 05:46:43 DEBUG : dir: reading active writers 2020/11/03 05:46:43 DEBUG : file1: reading active writers 2020/11/03 05:46:43 DEBUG : file2: reading active writers 2020/11/03 05:46:43 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:46:44 ERROR : file2: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:44 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:46:44 DEBUG : dir: Looking for writers 2020/11/03 05:46:44 DEBUG : : Looking for writers 2020/11/03 05:46:44 DEBUG : file1: reading active writers 2020/11/03 05:46:44 DEBUG : file2: reading active writers 2020/11/03 05:46:44 DEBUG : dir: reading active writers 2020/11/03 05:46:44 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:46:44 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:44 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:46:45 DEBUG : file2: vfs cache: starting upload 2020/11/03 05:46:45 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:46:45 DEBUG : dir: Looking for writers 2020/11/03 05:46:45 DEBUG : : Looking for writers 2020/11/03 05:46:45 DEBUG : dir: reading active writers 2020/11/03 05:46:45 DEBUG : file1: reading active writers 2020/11/03 05:46:45 DEBUG : file2: reading active writers 2020/11/03 05:46:45 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:46:46 ERROR : file2: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:46 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:46:46 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:46 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:46:46 DEBUG : file2: vfs cache: starting upload 2020/11/03 05:46:46 DEBUG : dir: Looking for writers 2020/11/03 05:46:46 DEBUG : : Looking for writers 2020/11/03 05:46:46 DEBUG : dir: reading active writers 2020/11/03 05:46:46 DEBUG : file1: reading active writers 2020/11/03 05:46:46 DEBUG : file2: reading active writers 2020/11/03 05:46:46 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:46:47 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:46:47 ERROR : file2: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:47 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:46:47 DEBUG : dir: Looking for writers 2020/11/03 05:46:47 DEBUG : : Looking for writers 2020/11/03 05:46:47 DEBUG : dir: reading active writers 2020/11/03 05:46:47 DEBUG : file1: reading active writers 2020/11/03 05:46:47 DEBUG : file2: reading active writers 2020/11/03 05:46:47 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:46:48 DEBUG : dir: Looking for writers 2020/11/03 05:46:48 DEBUG : : Looking for writers 2020/11/03 05:46:48 DEBUG : dir: reading active writers 2020/11/03 05:46:48 DEBUG : file1: reading active writers 2020/11/03 05:46:48 DEBUG : file2: reading active writers 2020/11/03 05:46:48 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:46:49 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:49 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:46:49 DEBUG : file2: vfs cache: starting upload 2020/11/03 05:46:49 DEBUG : dir: Looking for writers 2020/11/03 05:46:49 DEBUG : : Looking for writers 2020/11/03 05:46:49 DEBUG : dir: reading active writers 2020/11/03 05:46:49 DEBUG : file1: reading active writers 2020/11/03 05:46:49 DEBUG : file2: reading active writers 2020/11/03 05:46:49 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:46:50 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:46:50 ERROR : file2: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:50 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:46:50 DEBUG : dir: Looking for writers 2020/11/03 05:46:50 DEBUG : : Looking for writers 2020/11/03 05:46:50 DEBUG : dir: reading active writers 2020/11/03 05:46:50 DEBUG : file1: reading active writers 2020/11/03 05:46:50 DEBUG : file2: reading active writers 2020/11/03 05:46:50 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:46:51 ERROR : Exiting even though 0 writers active and 2 cache items in use after 10s Cache{ "file1": &{c:0xc00024aa80 mu:{state:0 sema:0} cond:0xc0005a3280 name:file1 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13826149332755291459 ext:111909188662 loc:0x266c360} ATime:{wall:13826149332755433688 ext:111909330897 loc:0x266c360} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, "file2": &{c:0xc00024aa80 mu:{state:0 sema:0} cond:0xc0006292c0 name:file2 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13826149332756052597 ext:111909949785 loc:0x266c360} ATime:{wall:13826149332756174520 ext:111910071705 loc:0x266c360} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2 pendingAccesses:0 beingReset:false}, } 2020/11/03 05:46:51 DEBUG : >WaitForWriters: 2020/11/03 05:46:51 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:46:51 DEBUG : dir: Looking for writers 2020/11/03 05:46:51 DEBUG : : Looking for writers 2020/11/03 05:46:51 DEBUG : dir: reading active writers 2020/11/03 05:46:51 DEBUG : file1: reading active writers 2020/11/03 05:46:51 DEBUG : file2: reading active writers 2020/11/03 05:46:51 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms 2020/11/03 05:46:51 DEBUG : dir: Looking for writers 2020/11/03 05:46:51 DEBUG : : Looking for writers 2020/11/03 05:46:51 DEBUG : dir: reading active writers 2020/11/03 05:46:51 DEBUG : file1: reading active writers 2020/11/03 05:46:51 DEBUG : file2: reading active writers 2020/11/03 05:46:51 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms 2020/11/03 05:46:51 DEBUG : dir: Looking for writers 2020/11/03 05:46:51 DEBUG : : Looking for writers 2020/11/03 05:46:51 DEBUG : dir: reading active writers 2020/11/03 05:46:51 DEBUG : file1: reading active writers 2020/11/03 05:46:51 DEBUG : file2: reading active writers 2020/11/03 05:46:51 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms 2020/11/03 05:46:51 DEBUG : dir: Looking for writers 2020/11/03 05:46:51 DEBUG : : Looking for writers 2020/11/03 05:46:51 DEBUG : dir: reading active writers 2020/11/03 05:46:51 DEBUG : file1: reading active writers 2020/11/03 05:46:51 DEBUG : file2: reading active writers 2020/11/03 05:46:51 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms 2020/11/03 05:46:51 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:51 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:46:51 DEBUG : dir: Looking for writers 2020/11/03 05:46:51 DEBUG : : Looking for writers 2020/11/03 05:46:51 DEBUG : dir: reading active writers 2020/11/03 05:46:51 DEBUG : file1: reading active writers 2020/11/03 05:46:51 DEBUG : file2: reading active writers 2020/11/03 05:46:51 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms 2020/11/03 05:46:52 DEBUG : dir: Looking for writers 2020/11/03 05:46:52 DEBUG : : Looking for writers 2020/11/03 05:46:52 DEBUG : dir: reading active writers 2020/11/03 05:46:52 DEBUG : file1: reading active writers 2020/11/03 05:46:52 DEBUG : file2: reading active writers 2020/11/03 05:46:52 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms 2020/11/03 05:46:52 DEBUG : dir: Looking for writers 2020/11/03 05:46:52 DEBUG : : Looking for writers 2020/11/03 05:46:52 DEBUG : dir: reading active writers 2020/11/03 05:46:52 DEBUG : file1: reading active writers 2020/11/03 05:46:52 DEBUG : file2: reading active writers 2020/11/03 05:46:52 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms 2020/11/03 05:46:53 DEBUG : dir: Looking for writers 2020/11/03 05:46:53 DEBUG : : Looking for writers 2020/11/03 05:46:53 DEBUG : dir: reading active writers 2020/11/03 05:46:53 DEBUG : file1: reading active writers 2020/11/03 05:46:53 DEBUG : file2: reading active writers 2020/11/03 05:46:53 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:46:54 DEBUG : file2: vfs cache: starting upload 2020/11/03 05:46:54 DEBUG : dir: Looking for writers 2020/11/03 05:46:54 DEBUG : : Looking for writers 2020/11/03 05:46:54 DEBUG : dir: reading active writers 2020/11/03 05:46:54 DEBUG : file1: reading active writers 2020/11/03 05:46:54 DEBUG : file2: reading active writers 2020/11/03 05:46:54 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:46:55 DEBUG : dir: Looking for writers 2020/11/03 05:46:55 DEBUG : : Looking for writers 2020/11/03 05:46:55 DEBUG : dir: reading active writers 2020/11/03 05:46:55 DEBUG : file1: reading active writers 2020/11/03 05:46:55 DEBUG : file2: reading active writers 2020/11/03 05:46:55 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:46:55 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:46:55 ERROR : file2: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:46:55 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:46:56 DEBUG : dir: Looking for writers 2020/11/03 05:46:56 DEBUG : : Looking for writers 2020/11/03 05:46:56 DEBUG : dir: reading active writers 2020/11/03 05:46:56 DEBUG : file1: reading active writers 2020/11/03 05:46:56 DEBUG : file2: reading active writers 2020/11/03 05:46:56 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:46: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:46:56 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:46:57 DEBUG : dir: Looking for writers 2020/11/03 05:46:57 DEBUG : : Looking for writers 2020/11/03 05:46:57 DEBUG : dir: reading active writers 2020/11/03 05:46:57 DEBUG : file1: reading active writers 2020/11/03 05:46:57 DEBUG : file2: reading active writers 2020/11/03 05:46:57 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:46:58 DEBUG : dir: Looking for writers 2020/11/03 05:46:58 DEBUG : : Looking for writers 2020/11/03 05:46:58 DEBUG : dir: reading active writers 2020/11/03 05:46:58 DEBUG : file1: reading active writers 2020/11/03 05:46:58 DEBUG : file2: reading active writers 2020/11/03 05:46:58 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:46:59 DEBUG : dir: Looking for writers 2020/11/03 05:46:59 DEBUG : : Looking for writers 2020/11/03 05:46:59 DEBUG : dir: reading active writers 2020/11/03 05:46:59 DEBUG : file1: reading active writers 2020/11/03 05:46:59 DEBUG : file2: reading active writers 2020/11/03 05:46:59 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:47:00 DEBUG : dir: Looking for writers 2020/11/03 05:47:00 DEBUG : : Looking for writers 2020/11/03 05:47:00 DEBUG : dir: reading active writers 2020/11/03 05:47:00 DEBUG : file1: reading active writers 2020/11/03 05:47:00 DEBUG : file2: reading active writers 2020/11/03 05:47:00 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:47:01 DEBUG : dir: Looking for writers 2020/11/03 05:47:01 DEBUG : : Looking for writers 2020/11/03 05:47:01 DEBUG : dir: reading active writers 2020/11/03 05:47:01 DEBUG : file1: reading active writers 2020/11/03 05:47:01 DEBUG : file2: reading active writers 2020/11/03 05:47:01 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:47:01 DEBUG : file2: vfs cache: starting upload 2020/11/03 05:47:01 ERROR : Exiting even though 0 writers active and 2 cache items in use after 10s Cache{ "file1": &{c:0xc00024aa80 mu:{state:0 sema:0} cond:0xc0005a3280 name:file1 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13826149332755291459 ext:111909188662 loc:0x266c360} ATime:{wall:13826149332755433688 ext:111909330897 loc:0x266c360} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, "file2": &{c:0xc00024aa80 mu:{state:0 sema:0} cond:0xc0006292c0 name:file2 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13826149332756052597 ext:111909949785 loc:0x266c360} ATime:{wall:13826149332756174520 ext:111910071705 loc:0x266c360} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2 pendingAccesses:0 beingReset:false}, } 2020/11/03 05:47:01 DEBUG : >WaitForWriters: --- FAIL: TestRWFileHandleWriteNoWrite (20.76s) === RUN TestRWFileHandleSizeTruncateExisting run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:47:02 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache 2020/11/03 05:47:02 DEBUG : file1: vfs cache: starting upload 2020/11/03 05:47:02 ERROR : file1: vfs cache: failed to write metadata file: vfs cache item: failed to write metadata: open /home/rclone/.cache/rclone/vfsMeta/TestSharefile/rclone-test-veyasip2qigezit0potiyug1/file1: no such file or directory 2020/11/03 05:47:02 INFO : file1: vfs cache: upload succeeded try #7 2020/11/03 05:47:02 ERROR : file2: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:47:02 ERROR : file2: 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 run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestRWFileHandleSizeTruncateExisting (1.64s) === RUN TestRWFileHandleSizeCreateExisting run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:47:04 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int --- FAIL: TestRWFileHandleSizeCreateExisting (1.27s) === RUN TestRWFileModTimeWithOpenWriters run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:47:05 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache 2020/11/03 05:47:05 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 05:47:05 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 05:47:05 DEBUG : file1: newRWFileHandle: 2020/11/03 05:47:05 DEBUG : file1(0xc00029f5c0): openPending: 2020/11/03 05:47:05 DEBUG : file1: vfs cache: truncate to size=0 2020/11/03 05:47:05 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:47:05 DEBUG : file1(0xc00029f5c0): >openPending: err= 2020/11/03 05:47:05 DEBUG : file1: >newRWFileHandle: err= 2020/11/03 05:47:05 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:47:05 DEBUG : file1: >Open: fd=file1 (rw), err= 2020/11/03 05:47:05 DEBUG : file1: >OpenFile: fd=file1 (rw), err= run.go:282: Failed to put "time_test" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:47:06 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:47:06 DEBUG : dir: Looking for writers 2020/11/03 05:47:06 DEBUG : : Looking for writers 2020/11/03 05:47:06 DEBUG : dir: reading active writers 2020/11/03 05:47:06 DEBUG : file1: reading active writers 2020/11/03 05:47:06 DEBUG : file1: active writers 1 2020/11/03 05:47:06 DEBUG : file2: reading active writers 2020/11/03 05:47:06 DEBUG : Still 1 writers active and 2 cache items in use, waiting 10ms 2020/11/03 05:47:06 DEBUG : dir: Looking for writers 2020/11/03 05:47:06 DEBUG : : Looking for writers 2020/11/03 05:47:06 DEBUG : dir: reading active writers 2020/11/03 05:47:06 DEBUG : file1: reading active writers 2020/11/03 05:47:06 DEBUG : file1: active writers 1 2020/11/03 05:47:06 DEBUG : file2: reading active writers 2020/11/03 05:47:06 DEBUG : Still 1 writers active and 2 cache items in use, waiting 20ms 2020/11/03 05:47:06 DEBUG : dir: Looking for writers 2020/11/03 05:47:06 DEBUG : : Looking for writers 2020/11/03 05:47:06 DEBUG : dir: reading active writers 2020/11/03 05:47:06 DEBUG : file1: reading active writers 2020/11/03 05:47:06 DEBUG : file1: active writers 1 2020/11/03 05:47:06 DEBUG : file2: reading active writers 2020/11/03 05:47:06 DEBUG : Still 1 writers active and 2 cache items in use, waiting 40ms 2020/11/03 05:47:06 DEBUG : dir: Looking for writers 2020/11/03 05:47:06 DEBUG : : Looking for writers 2020/11/03 05:47:06 DEBUG : dir: reading active writers 2020/11/03 05:47:06 DEBUG : file1: reading active writers 2020/11/03 05:47:06 DEBUG : file1: active writers 1 2020/11/03 05:47:06 DEBUG : file2: reading active writers 2020/11/03 05:47:06 DEBUG : Still 1 writers active and 2 cache items in use, waiting 80ms 2020/11/03 05:47:06 DEBUG : dir: Looking for writers 2020/11/03 05:47:06 DEBUG : : Looking for writers 2020/11/03 05:47:06 DEBUG : file2: reading active writers 2020/11/03 05:47:06 DEBUG : dir: reading active writers 2020/11/03 05:47:06 DEBUG : file1: reading active writers 2020/11/03 05:47:06 DEBUG : file1: active writers 1 2020/11/03 05:47:06 DEBUG : Still 1 writers active and 2 cache items in use, waiting 160ms 2020/11/03 05:47:07 DEBUG : dir: Looking for writers 2020/11/03 05:47:07 DEBUG : : Looking for writers 2020/11/03 05:47:07 DEBUG : file1: reading active writers 2020/11/03 05:47:07 DEBUG : file1: active writers 1 2020/11/03 05:47:07 DEBUG : file2: reading active writers 2020/11/03 05:47:07 DEBUG : dir: reading active writers 2020/11/03 05:47:07 DEBUG : Still 1 writers active and 2 cache items in use, waiting 320ms 2020/11/03 05:47:07 DEBUG : dir: Looking for writers 2020/11/03 05:47:07 DEBUG : : Looking for writers 2020/11/03 05:47:07 DEBUG : dir: reading active writers 2020/11/03 05:47:07 DEBUG : file1: reading active writers 2020/11/03 05:47:07 DEBUG : file1: active writers 1 2020/11/03 05:47:07 DEBUG : file2: reading active writers 2020/11/03 05:47:07 DEBUG : Still 1 writers active and 2 cache items in use, waiting 640ms 2020/11/03 05:47:08 DEBUG : dir: Looking for writers 2020/11/03 05:47:08 DEBUG : : Looking for writers 2020/11/03 05:47:08 DEBUG : file2: reading active writers 2020/11/03 05:47:08 DEBUG : dir: reading active writers 2020/11/03 05:47:08 DEBUG : file1: reading active writers 2020/11/03 05:47:08 DEBUG : file1: active writers 1 2020/11/03 05:47:08 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:47:09 DEBUG : dir: Looking for writers 2020/11/03 05:47:09 DEBUG : : Looking for writers 2020/11/03 05:47:09 DEBUG : dir: reading active writers 2020/11/03 05:47:09 DEBUG : file1: reading active writers 2020/11/03 05:47:09 DEBUG : file1: active writers 1 2020/11/03 05:47:09 DEBUG : file2: reading active writers 2020/11/03 05:47:09 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:47:10 DEBUG : dir: Looking for writers 2020/11/03 05:47:10 DEBUG : : Looking for writers 2020/11/03 05:47:10 DEBUG : dir: reading active writers 2020/11/03 05:47:10 DEBUG : file1: reading active writers 2020/11/03 05:47:10 DEBUG : file1: active writers 1 2020/11/03 05:47:10 DEBUG : file2: reading active writers 2020/11/03 05:47:10 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:47:11 DEBUG : dir: Looking for writers 2020/11/03 05:47:11 DEBUG : : Looking for writers 2020/11/03 05:47:11 DEBUG : dir: reading active writers 2020/11/03 05:47:11 DEBUG : file1: reading active writers 2020/11/03 05:47:11 DEBUG : file1: active writers 1 2020/11/03 05:47:11 DEBUG : file2: reading active writers 2020/11/03 05:47:11 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:47:12 DEBUG : dir: Looking for writers 2020/11/03 05:47:12 DEBUG : : Looking for writers 2020/11/03 05:47:12 DEBUG : file1: reading active writers 2020/11/03 05:47:12 DEBUG : file1: active writers 1 2020/11/03 05:47:12 DEBUG : file2: reading active writers 2020/11/03 05:47:12 DEBUG : dir: reading active writers 2020/11/03 05:47:12 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:47:13 DEBUG : dir: Looking for writers 2020/11/03 05:47:13 DEBUG : : Looking for writers 2020/11/03 05:47:13 DEBUG : dir: reading active writers 2020/11/03 05:47:13 DEBUG : file1: reading active writers 2020/11/03 05:47:13 DEBUG : file1: active writers 1 2020/11/03 05:47:13 DEBUG : file2: reading active writers 2020/11/03 05:47:13 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:47:14 DEBUG : dir: Looking for writers 2020/11/03 05:47:14 DEBUG : : Looking for writers 2020/11/03 05:47:14 DEBUG : dir: reading active writers 2020/11/03 05:47:14 DEBUG : file1: reading active writers 2020/11/03 05:47:14 DEBUG : file1: active writers 1 2020/11/03 05:47:14 DEBUG : file2: reading active writers 2020/11/03 05:47:14 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:47:15 DEBUG : dir: Looking for writers 2020/11/03 05:47:15 DEBUG : : Looking for writers 2020/11/03 05:47:15 DEBUG : file2: reading active writers 2020/11/03 05:47:15 DEBUG : dir: reading active writers 2020/11/03 05:47:15 DEBUG : file1: reading active writers 2020/11/03 05:47:15 DEBUG : file1: active writers 1 2020/11/03 05:47:15 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2020/11/03 05:47:15 DEBUG : file2: vfs cache: starting upload 2020/11/03 05:47:15 INFO : file2: vfs cache: upload succeeded try #8 2020/11/03 05:47:16 DEBUG : dir: Looking for writers 2020/11/03 05:47:16 DEBUG : : Looking for writers 2020/11/03 05:47:16 DEBUG : dir: reading active writers 2020/11/03 05:47:16 DEBUG : file1: reading active writers 2020/11/03 05:47:16 DEBUG : file1: active writers 1 2020/11/03 05:47:16 DEBUG : file2: reading active writers 2020/11/03 05:47:16 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2020/11/03 05:47:16 ERROR : Exiting even though 1 writers active and 1 cache items in use after 10s Cache{ "file1": &{c:0xc00024aa80 mu:{state:0 sema:0} cond:0xc0005a3280 name:file1 opens:1 downloaders: o: fd:0xc0003e3e30 metaDirty:false modified:true info:{ModTime:{wall:13826149358187681983 ext:135571775398 loc:0x266c360} ATime:{wall:13826149358187681983 ext:135571775398 loc:0x266c360} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, "file2": &{c:0xc00024aa80 mu:{state:0 sema:0} cond:0xc0006292c0 name:file2 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13826149332756052597 ext:111909949785 loc:0x266c360} ATime:{wall:13826149332756174520 ext:111910071705 loc:0x266c360} Size:0 Rs:[] Fingerprint: Dirty:false} writeBackID:2 pendingAccesses:0 beingReset:false}, } 2020/11/03 05:47:16 DEBUG : >WaitForWriters: --- FAIL: TestRWFileModTimeWithOpenWriters (12.82s) === 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-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:47:18 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': 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:47:18 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': 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:47:18 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:47:18 DEBUG : : Looking for writers 2020/11/03 05:47:18 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.26s) === RUN TestVFSStat run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:47:18 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:47:19 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:47:19 DEBUG : : Looking for writers 2020/11/03 05:47:19 DEBUG : >WaitForWriters: --- FAIL: TestVFSStat (2.23s) === RUN TestVFSStatParent run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:47:20 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:47:22 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:47:22 DEBUG : : Looking for writers 2020/11/03 05:47:22 DEBUG : >WaitForWriters: --- FAIL: TestVFSStatParent (1.95s) === RUN TestVFSOpenFile run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:47:22 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "file1" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:47:24 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:47:24 DEBUG : : Looking for writers 2020/11/03 05:47:24 DEBUG : >WaitForWriters: --- FAIL: TestVFSOpenFile (2.30s) === RUN TestVFSRename run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:47:24 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache run.go:282: Failed to put "dir/file2" to "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'": upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:47:27 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:47:27 DEBUG : : Looking for writers 2020/11/03 05:47:27 DEBUG : >WaitForWriters: --- FAIL: TestVFSRename (3.18s) === RUN TestWriteFileHandleMethods run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:47:28 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache 2020/11/03 05:47:28 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 05:47:28 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 05:47:28 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:47:28 DEBUG : file1: >Open: fd=file1 (w), err= 2020/11/03 05:47:28 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/11/03 05:47:28 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:47:28 ERROR : file1: WriteFileHandle: Read: Can't read and write to file without --vfs-cache-mode >= minimal 2020/11/03 05:47:28 ERROR : file1: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal 2020/11/03 05:47:28 ERROR : file1: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes 2020/11/03 05:47:28 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': File to upload is small (5 bytes), uploading instead of streaming 2020/11/03 05:47: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:47:29 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 05:47:29 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 05:47:29 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 05:47:29 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:47:29 DEBUG : file1: >Open: fd=file1 (w), err= 2020/11/03 05:47:29 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/11/03 05:47:29 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:47:29 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': File to upload is small (0 bytes), uploading instead of streaming 2020/11/03 05:47:31 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:47:31 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 05:47:31 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 05:47:31 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 05:47:31 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:47:31 DEBUG : file1: >Open: fd=file1 (w), err= 2020/11/03 05:47:31 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/11/03 05:47:31 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 05:47:31 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:47:31 DEBUG : : Looking for writers 2020/11/03 05:47:31 DEBUG : file1: reading active writers 2020/11/03 05:47:31 DEBUG : file1: active writers 1 2020/11/03 05:47:31 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/11/03 05:47:31 DEBUG : : Looking for writers 2020/11/03 05:47:31 DEBUG : file1: reading active writers 2020/11/03 05:47:31 DEBUG : file1: active writers 1 2020/11/03 05:47:31 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/11/03 05:47:31 DEBUG : : Looking for writers 2020/11/03 05:47:31 DEBUG : file1: reading active writers 2020/11/03 05:47:31 DEBUG : file1: active writers 1 2020/11/03 05:47:31 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/11/03 05:47:31 DEBUG : : Looking for writers 2020/11/03 05:47:31 DEBUG : file1: reading active writers 2020/11/03 05:47:31 DEBUG : file1: active writers 1 2020/11/03 05:47:31 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/11/03 05:47:31 DEBUG : : Looking for writers 2020/11/03 05:47:31 DEBUG : file1: reading active writers 2020/11/03 05:47:31 DEBUG : file1: active writers 1 2020/11/03 05:47:31 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/11/03 05:47:32 DEBUG : : Looking for writers 2020/11/03 05:47:32 DEBUG : file1: reading active writers 2020/11/03 05:47:32 DEBUG : file1: active writers 1 2020/11/03 05:47:32 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/11/03 05:47:32 DEBUG : : Looking for writers 2020/11/03 05:47:32 DEBUG : file1: reading active writers 2020/11/03 05:47:32 DEBUG : file1: active writers 1 2020/11/03 05:47:32 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/11/03 05:47:33 DEBUG : : Looking for writers 2020/11/03 05:47:33 DEBUG : file1: reading active writers 2020/11/03 05:47:33 DEBUG : file1: active writers 1 2020/11/03 05:47:33 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:34 DEBUG : : Looking for writers 2020/11/03 05:47:34 DEBUG : file1: reading active writers 2020/11/03 05:47:34 DEBUG : file1: active writers 1 2020/11/03 05:47:34 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:35 DEBUG : : Looking for writers 2020/11/03 05:47:35 DEBUG : file1: reading active writers 2020/11/03 05:47:35 DEBUG : file1: active writers 1 2020/11/03 05:47:35 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:36 DEBUG : : Looking for writers 2020/11/03 05:47:36 DEBUG : file1: reading active writers 2020/11/03 05:47:36 DEBUG : file1: active writers 1 2020/11/03 05:47:36 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:37 DEBUG : : Looking for writers 2020/11/03 05:47:37 DEBUG : file1: reading active writers 2020/11/03 05:47:37 DEBUG : file1: active writers 1 2020/11/03 05:47:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:38 DEBUG : : Looking for writers 2020/11/03 05:47:38 DEBUG : file1: reading active writers 2020/11/03 05:47:38 DEBUG : file1: active writers 1 2020/11/03 05:47:38 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:39 DEBUG : : Looking for writers 2020/11/03 05:47:39 DEBUG : file1: reading active writers 2020/11/03 05:47:39 DEBUG : file1: active writers 1 2020/11/03 05:47:39 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:40 DEBUG : : Looking for writers 2020/11/03 05:47:40 DEBUG : file1: reading active writers 2020/11/03 05:47:40 DEBUG : file1: active writers 1 2020/11/03 05:47:40 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:41 DEBUG : : Looking for writers 2020/11/03 05:47:41 DEBUG : file1: reading active writers 2020/11/03 05:47:41 DEBUG : file1: active writers 1 2020/11/03 05:47:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:41 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/11/03 05:47:41 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleMethods (14.31s) === RUN TestWriteFileHandleWriteAt run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:47:42 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache 2020/11/03 05:47:42 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 05:47:42 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 05:47:42 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:47:42 DEBUG : file1: >Open: fd=file1 (w), err= 2020/11/03 05:47:42 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/11/03 05:47:42 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:47:42 DEBUG : file1: waiting for in-sequence write to 100 for 1s 2020/11/03 05:47:43 DEBUG : file1: aborting in-sequence write wait, off=100 2020/11/03 05:47:43 DEBUG : file1: failed to wait for in-sequence write to 100 2020/11/03 05:47:43 ERROR : file1: WriteFileHandle.Write: can't seek in file without --vfs-cache-mode >= writes 2020/11/03 05:47:43 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': File to upload is small (11 bytes), uploading instead of streaming 2020/11/03 05:47:44 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:47:44 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 05:47:44 ERROR : file1: WriteFileHandle.Write: error: Bad file descriptor 2020/11/03 05:47:44 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:47:44 DEBUG : : Looking for writers 2020/11/03 05:47:44 DEBUG : file1: reading active writers 2020/11/03 05:47:44 DEBUG : file1: active writers 1 2020/11/03 05:47:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/11/03 05:47:44 DEBUG : : Looking for writers 2020/11/03 05:47:44 DEBUG : file1: reading active writers 2020/11/03 05:47:44 DEBUG : file1: active writers 1 2020/11/03 05:47:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/11/03 05:47:44 DEBUG : : Looking for writers 2020/11/03 05:47:44 DEBUG : file1: reading active writers 2020/11/03 05:47:44 DEBUG : file1: active writers 1 2020/11/03 05:47:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/11/03 05:47:44 DEBUG : : Looking for writers 2020/11/03 05:47:44 DEBUG : file1: reading active writers 2020/11/03 05:47:44 DEBUG : file1: active writers 1 2020/11/03 05:47:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/11/03 05:47:44 DEBUG : : Looking for writers 2020/11/03 05:47:44 DEBUG : file1: reading active writers 2020/11/03 05:47:44 DEBUG : file1: active writers 1 2020/11/03 05:47:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/11/03 05:47:45 DEBUG : : Looking for writers 2020/11/03 05:47:45 DEBUG : file1: reading active writers 2020/11/03 05:47:45 DEBUG : file1: active writers 1 2020/11/03 05:47:45 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/11/03 05:47:45 DEBUG : : Looking for writers 2020/11/03 05:47:45 DEBUG : file1: reading active writers 2020/11/03 05:47:45 DEBUG : file1: active writers 1 2020/11/03 05:47:45 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/11/03 05:47:46 DEBUG : : Looking for writers 2020/11/03 05:47:46 DEBUG : file1: reading active writers 2020/11/03 05:47:46 DEBUG : file1: active writers 1 2020/11/03 05:47:46 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:47 DEBUG : : Looking for writers 2020/11/03 05:47:47 DEBUG : file1: reading active writers 2020/11/03 05:47:47 DEBUG : file1: active writers 1 2020/11/03 05:47:47 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:48 DEBUG : : Looking for writers 2020/11/03 05:47:48 DEBUG : file1: reading active writers 2020/11/03 05:47:48 DEBUG : file1: active writers 1 2020/11/03 05:47:48 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:49 DEBUG : : Looking for writers 2020/11/03 05:47:49 DEBUG : file1: reading active writers 2020/11/03 05:47:49 DEBUG : file1: active writers 1 2020/11/03 05:47:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:50 DEBUG : : Looking for writers 2020/11/03 05:47:50 DEBUG : file1: reading active writers 2020/11/03 05:47:50 DEBUG : file1: active writers 1 2020/11/03 05:47:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:51 DEBUG : : Looking for writers 2020/11/03 05:47:51 DEBUG : file1: reading active writers 2020/11/03 05:47:51 DEBUG : file1: active writers 1 2020/11/03 05:47:51 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:52 DEBUG : : Looking for writers 2020/11/03 05:47:52 DEBUG : file1: reading active writers 2020/11/03 05:47:52 DEBUG : file1: active writers 1 2020/11/03 05:47:52 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:53 DEBUG : : Looking for writers 2020/11/03 05:47:53 DEBUG : file1: reading active writers 2020/11/03 05:47:53 DEBUG : file1: active writers 1 2020/11/03 05:47:53 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:54 DEBUG : : Looking for writers 2020/11/03 05:47:54 DEBUG : file1: reading active writers 2020/11/03 05:47:54 DEBUG : file1: active writers 1 2020/11/03 05:47:54 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:54 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/11/03 05:47:54 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleWriteAt (12.97s) === RUN TestWriteFileHandleFlush run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:47:55 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache 2020/11/03 05:47:55 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 05:47:55 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 05:47:55 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:47:55 DEBUG : file1: >Open: fd=file1 (w), err= 2020/11/03 05:47:55 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/11/03 05:47:55 DEBUG : file1: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions 2020/11/03 05:47:55 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:47:55 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': File to upload is small (5 bytes), uploading instead of streaming 2020/11/03 05:47: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:47:56 ERROR : file1: WriteFileHandle.New Rcat failed: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:47:56 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 05:47:56 DEBUG : file1: WriteFileHandle.Flush nothing to do 2020/11/03 05:47:56 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:47:56 DEBUG : : Looking for writers 2020/11/03 05:47:56 DEBUG : file1: reading active writers 2020/11/03 05:47:56 DEBUG : file1: active writers 1 2020/11/03 05:47:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/11/03 05:47:56 DEBUG : : Looking for writers 2020/11/03 05:47:56 DEBUG : file1: reading active writers 2020/11/03 05:47:56 DEBUG : file1: active writers 1 2020/11/03 05:47:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/11/03 05:47:56 DEBUG : : Looking for writers 2020/11/03 05:47:56 DEBUG : file1: reading active writers 2020/11/03 05:47:56 DEBUG : file1: active writers 1 2020/11/03 05:47:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/11/03 05:47:56 DEBUG : : Looking for writers 2020/11/03 05:47:56 DEBUG : file1: reading active writers 2020/11/03 05:47:56 DEBUG : file1: active writers 1 2020/11/03 05:47:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/11/03 05:47:56 DEBUG : : Looking for writers 2020/11/03 05:47:56 DEBUG : file1: reading active writers 2020/11/03 05:47:56 DEBUG : file1: active writers 1 2020/11/03 05:47:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/11/03 05:47:56 DEBUG : : Looking for writers 2020/11/03 05:47:56 DEBUG : file1: reading active writers 2020/11/03 05:47:56 DEBUG : file1: active writers 1 2020/11/03 05:47:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/11/03 05:47:57 DEBUG : : Looking for writers 2020/11/03 05:47:57 DEBUG : file1: reading active writers 2020/11/03 05:47:57 DEBUG : file1: active writers 1 2020/11/03 05:47:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/11/03 05:47:57 DEBUG : : Looking for writers 2020/11/03 05:47:57 DEBUG : file1: reading active writers 2020/11/03 05:47:57 DEBUG : file1: active writers 1 2020/11/03 05:47:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:58 DEBUG : : Looking for writers 2020/11/03 05:47:58 DEBUG : file1: reading active writers 2020/11/03 05:47:58 DEBUG : file1: active writers 1 2020/11/03 05:47:58 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:47:59 DEBUG : : Looking for writers 2020/11/03 05:47:59 DEBUG : file1: reading active writers 2020/11/03 05:47:59 DEBUG : file1: active writers 1 2020/11/03 05:47:59 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:00 DEBUG : : Looking for writers 2020/11/03 05:48:00 DEBUG : file1: reading active writers 2020/11/03 05:48:00 DEBUG : file1: active writers 1 2020/11/03 05:48:00 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:01 DEBUG : : Looking for writers 2020/11/03 05:48:01 DEBUG : file1: reading active writers 2020/11/03 05:48:01 DEBUG : file1: active writers 1 2020/11/03 05:48:01 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:02 DEBUG : : Looking for writers 2020/11/03 05:48:02 DEBUG : file1: reading active writers 2020/11/03 05:48:02 DEBUG : file1: active writers 1 2020/11/03 05:48:02 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:03 DEBUG : : Looking for writers 2020/11/03 05:48:03 DEBUG : file1: reading active writers 2020/11/03 05:48:03 DEBUG : file1: active writers 1 2020/11/03 05:48:03 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:04 DEBUG : : Looking for writers 2020/11/03 05:48:04 DEBUG : file1: reading active writers 2020/11/03 05:48:04 DEBUG : file1: active writers 1 2020/11/03 05:48:04 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:05 DEBUG : : Looking for writers 2020/11/03 05:48:05 DEBUG : file1: reading active writers 2020/11/03 05:48:05 DEBUG : file1: active writers 1 2020/11/03 05:48:05 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:06 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/11/03 05:48:06 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleFlush (11.71s) === RUN TestWriteFileHandleRelease run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:48:07 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache 2020/11/03 05:48:07 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 05:48:07 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 05:48:07 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:48:07 DEBUG : file1: >Open: fd=file1 (w), err= 2020/11/03 05:48:07 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/11/03 05:48:07 DEBUG : file1: WriteFileHandle.Release closing 2020/11/03 05:48:07 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:48:07 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': File to upload is small (0 bytes), uploading instead of streaming 2020/11/03 05:48:08 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:48:08 ERROR : file1: WriteFileHandle.New Rcat failed: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:48:08 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 05:48:08 DEBUG : file1: WriteFileHandle.Release nothing to do 2020/11/03 05:48:08 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:48:08 DEBUG : : Looking for writers 2020/11/03 05:48:08 DEBUG : file1: reading active writers 2020/11/03 05:48:08 DEBUG : file1: active writers 1 2020/11/03 05:48:08 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/11/03 05:48:08 DEBUG : : Looking for writers 2020/11/03 05:48:08 DEBUG : file1: reading active writers 2020/11/03 05:48:08 DEBUG : file1: active writers 1 2020/11/03 05:48:08 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/11/03 05:48:08 DEBUG : : Looking for writers 2020/11/03 05:48:08 DEBUG : file1: reading active writers 2020/11/03 05:48:08 DEBUG : file1: active writers 1 2020/11/03 05:48:08 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/11/03 05:48:08 DEBUG : : Looking for writers 2020/11/03 05:48:08 DEBUG : file1: reading active writers 2020/11/03 05:48:08 DEBUG : file1: active writers 1 2020/11/03 05:48:08 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/11/03 05:48:08 DEBUG : : Looking for writers 2020/11/03 05:48:08 DEBUG : file1: reading active writers 2020/11/03 05:48:08 DEBUG : file1: active writers 1 2020/11/03 05:48:08 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/11/03 05:48:08 DEBUG : : Looking for writers 2020/11/03 05:48:08 DEBUG : file1: reading active writers 2020/11/03 05:48:08 DEBUG : file1: active writers 1 2020/11/03 05:48:08 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/11/03 05:48:09 DEBUG : : Looking for writers 2020/11/03 05:48:09 DEBUG : file1: reading active writers 2020/11/03 05:48:09 DEBUG : file1: active writers 1 2020/11/03 05:48:09 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/11/03 05:48:09 DEBUG : : Looking for writers 2020/11/03 05:48:09 DEBUG : file1: reading active writers 2020/11/03 05:48:09 DEBUG : file1: active writers 1 2020/11/03 05:48:09 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:10 DEBUG : : Looking for writers 2020/11/03 05:48:10 DEBUG : file1: reading active writers 2020/11/03 05:48:10 DEBUG : file1: active writers 1 2020/11/03 05:48:10 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:11 DEBUG : : Looking for writers 2020/11/03 05:48:11 DEBUG : file1: reading active writers 2020/11/03 05:48:11 DEBUG : file1: active writers 1 2020/11/03 05:48:11 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:12 DEBUG : : Looking for writers 2020/11/03 05:48:12 DEBUG : file1: reading active writers 2020/11/03 05:48:12 DEBUG : file1: active writers 1 2020/11/03 05:48:12 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:13 DEBUG : : Looking for writers 2020/11/03 05:48:13 DEBUG : file1: reading active writers 2020/11/03 05:48:13 DEBUG : file1: active writers 1 2020/11/03 05:48:13 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:14 DEBUG : : Looking for writers 2020/11/03 05:48:14 DEBUG : file1: reading active writers 2020/11/03 05:48:14 DEBUG : file1: active writers 1 2020/11/03 05:48:14 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:15 DEBUG : : Looking for writers 2020/11/03 05:48:15 DEBUG : file1: reading active writers 2020/11/03 05:48:15 DEBUG : file1: active writers 1 2020/11/03 05:48:15 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:16 DEBUG : : Looking for writers 2020/11/03 05:48:16 DEBUG : file1: reading active writers 2020/11/03 05:48:16 DEBUG : file1: active writers 1 2020/11/03 05:48:16 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:17 DEBUG : : Looking for writers 2020/11/03 05:48:17 DEBUG : file1: reading active writers 2020/11/03 05:48:17 DEBUG : file1: active writers 1 2020/11/03 05:48:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:18 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/11/03 05:48:18 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleRelease (12.11s) === RUN TestWriteFileModTimeWithOpenWriters run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:48:19 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache 2020/11/03 05:48:19 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 05:48:19 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 05:48:19 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:48:19 DEBUG : file1: >Open: fd=file1 (w), err= 2020/11/03 05:48:19 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/11/03 05:48:19 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:48:19 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': File to upload is small (2 bytes), uploading instead of streaming 2020/11/03 05:48: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:48:20 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 05:48:20 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:48:20 DEBUG : : Looking for writers 2020/11/03 05:48:20 DEBUG : file1: reading active writers 2020/11/03 05:48:20 DEBUG : file1: active writers 1 2020/11/03 05:48:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/11/03 05:48:20 DEBUG : : Looking for writers 2020/11/03 05:48:20 DEBUG : file1: reading active writers 2020/11/03 05:48:20 DEBUG : file1: active writers 1 2020/11/03 05:48:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/11/03 05:48:20 DEBUG : : Looking for writers 2020/11/03 05:48:20 DEBUG : file1: reading active writers 2020/11/03 05:48:20 DEBUG : file1: active writers 1 2020/11/03 05:48:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/11/03 05:48:20 DEBUG : : Looking for writers 2020/11/03 05:48:20 DEBUG : file1: reading active writers 2020/11/03 05:48:20 DEBUG : file1: active writers 1 2020/11/03 05:48:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/11/03 05:48:20 DEBUG : : Looking for writers 2020/11/03 05:48:20 DEBUG : file1: reading active writers 2020/11/03 05:48:20 DEBUG : file1: active writers 1 2020/11/03 05:48:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/11/03 05:48:20 DEBUG : : Looking for writers 2020/11/03 05:48:20 DEBUG : file1: reading active writers 2020/11/03 05:48:20 DEBUG : file1: active writers 1 2020/11/03 05:48:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/11/03 05:48:21 DEBUG : : Looking for writers 2020/11/03 05:48:21 DEBUG : file1: reading active writers 2020/11/03 05:48:21 DEBUG : file1: active writers 1 2020/11/03 05:48:21 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/11/03 05:48:21 DEBUG : : Looking for writers 2020/11/03 05:48:21 DEBUG : file1: reading active writers 2020/11/03 05:48:21 DEBUG : file1: active writers 1 2020/11/03 05:48:21 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:22 DEBUG : : Looking for writers 2020/11/03 05:48:22 DEBUG : file1: reading active writers 2020/11/03 05:48:22 DEBUG : file1: active writers 1 2020/11/03 05:48:22 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:23 DEBUG : : Looking for writers 2020/11/03 05:48:23 DEBUG : file1: reading active writers 2020/11/03 05:48:23 DEBUG : file1: active writers 1 2020/11/03 05:48:23 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:24 DEBUG : : Looking for writers 2020/11/03 05:48:24 DEBUG : file1: reading active writers 2020/11/03 05:48:24 DEBUG : file1: active writers 1 2020/11/03 05:48:24 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:25 DEBUG : : Looking for writers 2020/11/03 05:48:25 DEBUG : file1: reading active writers 2020/11/03 05:48:25 DEBUG : file1: active writers 1 2020/11/03 05:48:25 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:26 DEBUG : : Looking for writers 2020/11/03 05:48:26 DEBUG : file1: reading active writers 2020/11/03 05:48:26 DEBUG : file1: active writers 1 2020/11/03 05:48:26 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:27 DEBUG : : Looking for writers 2020/11/03 05:48:27 DEBUG : file1: reading active writers 2020/11/03 05:48:27 DEBUG : file1: active writers 1 2020/11/03 05:48:27 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:28 DEBUG : : Looking for writers 2020/11/03 05:48:28 DEBUG : file1: reading active writers 2020/11/03 05:48:28 DEBUG : file1: active writers 1 2020/11/03 05:48:28 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:29 DEBUG : : Looking for writers 2020/11/03 05:48:29 DEBUG : file1: reading active writers 2020/11/03 05:48:29 DEBUG : file1: active writers 1 2020/11/03 05:48:29 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:30 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/11/03 05:48:30 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileModTimeWithOpenWriters (12.12s) === RUN TestFileReadAtZeroLength run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:48:31 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache 2020/11/03 05:48:31 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 05:48:31 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 05:48:31 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:48:31 DEBUG : file1: >Open: fd=file1 (w), err= 2020/11/03 05:48:31 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/11/03 05:48:31 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:48:31 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': File to upload is small (0 bytes), uploading instead of streaming 2020/11/03 05:48: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:48:32 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 05:48:32 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2020/11/03 05:48:32 DEBUG : file1: Open: flags=O_RDONLY 2020/11/03 05:48:37 DEBUG : file1: >Open: fd=, err=file does not exist 2020/11/03 05:48:37 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 05:48:37 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:48:37 DEBUG : : Looking for writers 2020/11/03 05:48:37 DEBUG : file1: reading active writers 2020/11/03 05:48:37 DEBUG : file1: active writers 1 2020/11/03 05:48:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/11/03 05:48:37 DEBUG : : Looking for writers 2020/11/03 05:48:37 DEBUG : file1: reading active writers 2020/11/03 05:48:37 DEBUG : file1: active writers 1 2020/11/03 05:48:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/11/03 05:48:37 DEBUG : : Looking for writers 2020/11/03 05:48:37 DEBUG : file1: reading active writers 2020/11/03 05:48:37 DEBUG : file1: active writers 1 2020/11/03 05:48:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/11/03 05:48:37 DEBUG : : Looking for writers 2020/11/03 05:48:37 DEBUG : file1: reading active writers 2020/11/03 05:48:37 DEBUG : file1: active writers 1 2020/11/03 05:48:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/11/03 05:48:37 DEBUG : : Looking for writers 2020/11/03 05:48:37 DEBUG : file1: reading active writers 2020/11/03 05:48:37 DEBUG : file1: active writers 1 2020/11/03 05:48:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/11/03 05:48:38 DEBUG : : Looking for writers 2020/11/03 05:48:38 DEBUG : file1: reading active writers 2020/11/03 05:48:38 DEBUG : file1: active writers 1 2020/11/03 05:48:38 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/11/03 05:48:38 DEBUG : : Looking for writers 2020/11/03 05:48:38 DEBUG : file1: reading active writers 2020/11/03 05:48:38 DEBUG : file1: active writers 1 2020/11/03 05:48:38 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/11/03 05:48:39 DEBUG : : Looking for writers 2020/11/03 05:48:39 DEBUG : file1: reading active writers 2020/11/03 05:48:39 DEBUG : file1: active writers 1 2020/11/03 05:48:39 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:40 DEBUG : : Looking for writers 2020/11/03 05:48:40 DEBUG : file1: reading active writers 2020/11/03 05:48:40 DEBUG : file1: active writers 1 2020/11/03 05:48:40 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:41 DEBUG : : Looking for writers 2020/11/03 05:48:41 DEBUG : file1: reading active writers 2020/11/03 05:48:41 DEBUG : file1: active writers 1 2020/11/03 05:48:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:42 DEBUG : : Looking for writers 2020/11/03 05:48:42 DEBUG : file1: reading active writers 2020/11/03 05:48:42 DEBUG : file1: active writers 1 2020/11/03 05:48:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:43 DEBUG : : Looking for writers 2020/11/03 05:48:43 DEBUG : file1: reading active writers 2020/11/03 05:48:43 DEBUG : file1: active writers 1 2020/11/03 05:48:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:44 DEBUG : : Looking for writers 2020/11/03 05:48:44 DEBUG : file1: reading active writers 2020/11/03 05:48:44 DEBUG : file1: active writers 1 2020/11/03 05:48:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:45 DEBUG : : Looking for writers 2020/11/03 05:48:45 DEBUG : file1: reading active writers 2020/11/03 05:48:45 DEBUG : file1: active writers 1 2020/11/03 05:48:45 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:46 DEBUG : : Looking for writers 2020/11/03 05:48:46 DEBUG : file1: reading active writers 2020/11/03 05:48:46 DEBUG : file1: active writers 1 2020/11/03 05:48:46 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:47 DEBUG : : Looking for writers 2020/11/03 05:48:47 DEBUG : file1: reading active writers 2020/11/03 05:48:47 DEBUG : file1: active writers 1 2020/11/03 05:48:47 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:47 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/11/03 05:48:47 DEBUG : >WaitForWriters: --- FAIL: TestFileReadAtZeroLength (16.94s) === RUN TestFileReadAtNonZeroLength run.go:176: Remote "sharefile root 'rclone-test-veyasip2qigezit0potiyug1'", Local "Local file system at /tmp/rclone389296597", Modify Window "1s" 2020/11/03 05:48:48 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': Re-using VFS from active cache 2020/11/03 05:48:48 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/11/03 05:48:48 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/11/03 05:48:48 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:48:48 DEBUG : file1: >Open: fd=file1 (w), err= 2020/11/03 05:48:48 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/11/03 05:48:48 DEBUG : : Added virtual directory entry vAdd: "file1" 2020/11/03 05:48:48 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': File to upload is small (100 bytes), uploading instead of streaming 2020/11/03 05:48:49 ERROR : file1: Failed to copy: upload file: json: cannot unmarshal string into Go struct field .value.size of type int 2020/11/03 05:48:49 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 05:48:49 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2020/11/03 05:48:49 DEBUG : file1: Open: flags=O_RDONLY 2020/11/03 05:48:54 DEBUG : file1: >Open: fd=, err=file does not exist 2020/11/03 05:48:54 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 05:48:54 DEBUG : WaitForWriters: timeout=10s 2020/11/03 05:48:54 DEBUG : : Looking for writers 2020/11/03 05:48:54 DEBUG : file1: reading active writers 2020/11/03 05:48:54 DEBUG : file1: active writers 1 2020/11/03 05:48:54 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/11/03 05:48:54 DEBUG : : Looking for writers 2020/11/03 05:48:54 DEBUG : file1: reading active writers 2020/11/03 05:48:54 DEBUG : file1: active writers 1 2020/11/03 05:48:54 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/11/03 05:48:54 DEBUG : : Looking for writers 2020/11/03 05:48:54 DEBUG : file1: reading active writers 2020/11/03 05:48:54 DEBUG : file1: active writers 1 2020/11/03 05:48:54 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/11/03 05:48:54 DEBUG : : Looking for writers 2020/11/03 05:48:54 DEBUG : file1: reading active writers 2020/11/03 05:48:54 DEBUG : file1: active writers 1 2020/11/03 05:48:54 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/11/03 05:48:54 DEBUG : : Looking for writers 2020/11/03 05:48:54 DEBUG : file1: reading active writers 2020/11/03 05:48:54 DEBUG : file1: active writers 1 2020/11/03 05:48:54 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/11/03 05:48:54 DEBUG : : Looking for writers 2020/11/03 05:48:54 DEBUG : file1: reading active writers 2020/11/03 05:48:54 DEBUG : file1: active writers 1 2020/11/03 05:48:54 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/11/03 05:48:55 DEBUG : : Looking for writers 2020/11/03 05:48:55 DEBUG : file1: reading active writers 2020/11/03 05:48:55 DEBUG : file1: active writers 1 2020/11/03 05:48:55 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/11/03 05:48:55 DEBUG : : Looking for writers 2020/11/03 05:48:55 DEBUG : file1: reading active writers 2020/11/03 05:48:55 DEBUG : file1: active writers 1 2020/11/03 05:48:55 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:56 DEBUG : : Looking for writers 2020/11/03 05:48:56 DEBUG : file1: reading active writers 2020/11/03 05:48:56 DEBUG : file1: active writers 1 2020/11/03 05:48:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:57 DEBUG : : Looking for writers 2020/11/03 05:48:57 DEBUG : file1: reading active writers 2020/11/03 05:48:57 DEBUG : file1: active writers 1 2020/11/03 05:48:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:58 DEBUG : : Looking for writers 2020/11/03 05:48:58 DEBUG : file1: reading active writers 2020/11/03 05:48:58 DEBUG : file1: active writers 1 2020/11/03 05:48:58 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:48:59 DEBUG : : Looking for writers 2020/11/03 05:48:59 DEBUG : file1: reading active writers 2020/11/03 05:48:59 DEBUG : file1: active writers 1 2020/11/03 05:48:59 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:49:00 DEBUG : : Looking for writers 2020/11/03 05:49:00 DEBUG : file1: reading active writers 2020/11/03 05:49:00 DEBUG : file1: active writers 1 2020/11/03 05:49:00 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:49:01 DEBUG : : Looking for writers 2020/11/03 05:49:01 DEBUG : file1: reading active writers 2020/11/03 05:49:01 DEBUG : file1: active writers 1 2020/11/03 05:49:01 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:49:02 DEBUG : : Looking for writers 2020/11/03 05:49:02 DEBUG : file1: reading active writers 2020/11/03 05:49:02 DEBUG : file1: active writers 1 2020/11/03 05:49:02 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:49:03 DEBUG : : Looking for writers 2020/11/03 05:49:03 DEBUG : file1: reading active writers 2020/11/03 05:49:03 DEBUG : file1: active writers 1 2020/11/03 05:49:03 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/11/03 05:49:04 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/11/03 05:49:04 DEBUG : >WaitForWriters: --- FAIL: TestFileReadAtNonZeroLength (17.03s) FAIL 2020/11/03 05:49:05 DEBUG : sharefile root 'rclone-test-veyasip2qigezit0potiyug1': 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 4m15.666195453s (try 2/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]