"./vfs.test -test.v -test.timeout 1h0m0s -remote TestHdfs: -verbose -test.run '^(TestCaseSensitivity|TestDirHandleMethods|TestDirHandleReaddir|TestDirReadDirAll|TestDirRename|TestDirWalk|TestFileReadAtNonZeroLength|TestFileReadAtZeroLength|TestFileSetModTime|TestRcGetVFS|TestReadFileHandleFlush|TestVFSNew|TestVFSOpenFile|TestVFSRename|TestVFSStat|TestVFSStatParent|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleWriteAt|TestWriteFileModTimeWithOpenWriters)$/^(cache=full,open=true,write=false|cache=off,open=false,write=false)$'" - Starting (try 2/5) 2022/05/21 06:51:11 DEBUG : Creating backend with remote "TestHdfs:rclone-test-mocudub5zimetaw7zegixuj6" 2022/05/21 06:51:11 DEBUG : Setting type="hdfs" for "TestHdfs" from environment variable RCLONE_CONFIG_TESTHDFS_TYPE 2022/05/21 06:51:11 DEBUG : Setting namenode="127.0.0.1:8020" for "TestHdfs" from environment variable RCLONE_CONFIG_TESTHDFS_NAMENODE 2022/05/21 06:51:11 DEBUG : Setting username="root" for "TestHdfs" from environment variable RCLONE_CONFIG_TESTHDFS_USERNAME 2022/05/21 06:51:11 DEBUG : TestHdfs: detected overridden config - adding "{cNNQW}" suffix to name 2022/05/21 06:51:11 DEBUG : Setting namenode="127.0.0.1:8020" for "TestHdfs" from environment variable RCLONE_CONFIG_TESTHDFS_NAMENODE 2022/05/21 06:51:11 DEBUG : Setting username="root" for "TestHdfs" from environment variable RCLONE_CONFIG_TESTHDFS_USERNAME 2022/05/21 06:51:11 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2022/05/21 06:51:12 DEBUG : Creating backend with remote "/tmp/rclone1442219142" === RUN TestDirHandleMethods run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:12 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: mkdir [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file1] run.go:287: Failed to put "dir/file1" to "hdfs://127.0.0.1:8020": create /rclone-test-mocudub5zimetaw7zegixuj6/dir/file1: replication in progress --- FAIL: TestDirHandleMethods (0.23s) === RUN TestDirHandleReaddir run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: Re-using VFS from active cache 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file1] run.go:287: Failed to put "dir/file1" to "hdfs://127.0.0.1:8020": create /rclone-test-mocudub5zimetaw7zegixuj6/dir/file1: replication in progress 2022/05/21 06:51:12 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:12 DEBUG : : Looking for writers 2022/05/21 06:51:12 DEBUG : >WaitForWriters: 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] --- FAIL: TestDirHandleReaddir (0.06s) === RUN TestDirWalk run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: Re-using VFS from active cache 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file1] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/fil/a/b/c] run.go:287: Failed to put "fil/a/b/c" to "hdfs://127.0.0.1:8020": create /rclone-test-mocudub5zimetaw7zegixuj6/fil/a/b/c: replication in progress 2022/05/21 06:51:12 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:12 DEBUG : dir: Looking for writers 2022/05/21 06:51:12 DEBUG : : Looking for writers 2022/05/21 06:51:12 DEBUG : dir: reading active writers 2022/05/21 06:51:12 DEBUG : >WaitForWriters: 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/fil] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/fil/a] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file1] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/fil/a/b] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-mocudub5zimetaw7zegixuj6/fil/a/b] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-mocudub5zimetaw7zegixuj6/fil/a] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-mocudub5zimetaw7zegixuj6/fil] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] --- FAIL: TestDirWalk (0.09s) === RUN TestDirReadDirAll run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: Re-using VFS from active cache 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file1] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file2] run.go:287: Failed to put "dir/file2" to "hdfs://127.0.0.1:8020": create /rclone-test-mocudub5zimetaw7zegixuj6/dir/file2: replication in progress 2022/05/21 06:51:12 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:12 DEBUG : dir: Looking for writers 2022/05/21 06:51:12 DEBUG : : Looking for writers 2022/05/21 06:51:12 DEBUG : dir: reading active writers 2022/05/21 06:51:12 DEBUG : >WaitForWriters: 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file1] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] --- FAIL: TestDirReadDirAll (0.04s) === RUN TestDirRename run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: Re-using VFS from active cache 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file1] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file3] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 ERROR : dir/not found: Dir.Rename error: file does not exist 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rename [/rclone-test-mocudub5zimetaw7zegixuj6/dir] to [/rclone-test-mocudub5zimetaw7zegixuj6/dir2] 2022/05/21 06:51:12 DEBUG : dir: Updating dir with dir2 0xc00027ea80 2022/05/21 06:51:12 DEBUG : dir: forgetting directory cache 2022/05/21 06:51:12 DEBUG : : Added virtual directory entry vDel: "dir" 2022/05/21 06:51:12 DEBUG : : Added virtual directory entry vAddDir: "dir2" 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir2] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir2] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: new [/rclone-test-mocudub5zimetaw7zegixuj6/file2] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rename [/rclone-test-mocudub5zimetaw7zegixuj6/dir2/file1] to [/rclone-test-mocudub5zimetaw7zegixuj6/file2] 2022/05/21 06:51:12 INFO : dir2/file1: Moved (server-side) to: file2 2022/05/21 06:51:12 DEBUG : file2: Updating file with file2 0xc00003a3c0 2022/05/21 06:51:12 DEBUG : dir2: Added virtual directory entry vDel: "file1" 2022/05/21 06:51:12 DEBUG : : Added virtual directory entry vAddFile: "file2" 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir2] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: new [/rclone-test-mocudub5zimetaw7zegixuj6/dir2/file3] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/dir2/file3] 2022/05/21 06:51:12 INFO : dir2/file3: Deleted 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rename [/rclone-test-mocudub5zimetaw7zegixuj6/file2] to [/rclone-test-mocudub5zimetaw7zegixuj6/dir2/file3] 2022/05/21 06:51:12 INFO : file2: Moved (server-side) to: dir2/file3 2022/05/21 06:51:12 DEBUG : dir2/file3: Updating file with dir2/file3 0xc00003a3c0 2022/05/21 06:51:12 DEBUG : : Added virtual directory entry vDel: "file2" 2022/05/21 06:51:12 DEBUG : dir2: Added virtual directory entry vAddFile: "file3" 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir2] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: mkdir [/rclone-test-mocudub5zimetaw7zegixuj6/empty directory] 2022/05/21 06:51:12 DEBUG : : Added virtual directory entry vAddDir: "empty directory" 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rename [/rclone-test-mocudub5zimetaw7zegixuj6/empty directory] to [/rclone-test-mocudub5zimetaw7zegixuj6/renamed empty directory] 2022/05/21 06:51:12 DEBUG : empty directory: Updating dir with renamed empty directory 0xc00027ed80 2022/05/21 06:51:12 DEBUG : empty directory: forgetting directory cache 2022/05/21 06:51:12 DEBUG : : Added virtual directory entry vDel: "empty directory" 2022/05/21 06:51:12 DEBUG : : Added virtual directory entry vAddDir: "renamed empty directory" 2022/05/21 06:51:12 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:12 DEBUG : dir2: Looking for writers 2022/05/21 06:51:12 DEBUG : file3: reading active writers 2022/05/21 06:51:12 DEBUG : renamed empty directory: Looking for writers 2022/05/21 06:51:12 DEBUG : : Looking for writers 2022/05/21 06:51:12 DEBUG : dir2: reading active writers 2022/05/21 06:51:12 DEBUG : renamed empty directory: reading active writers 2022/05/21 06:51:12 DEBUG : >WaitForWriters: 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/renamed empty directory] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir2] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/dir2/file3] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-mocudub5zimetaw7zegixuj6/renamed empty directory] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-mocudub5zimetaw7zegixuj6/dir2] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] --- PASS: TestDirRename (0.09s) === RUN TestFileSetModTime === RUN TestFileSetModTime/cache=off,open=false,write=false run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:12 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file1] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/time_test] run.go:287: Failed to put "time_test" to "hdfs://127.0.0.1:8020": create /rclone-test-mocudub5zimetaw7zegixuj6/time_test: replication in progress 2022/05/21 06:51:12 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:12 DEBUG : dir: Looking for writers 2022/05/21 06:51:12 DEBUG : file1: reading active writers 2022/05/21 06:51:12 DEBUG : : Looking for writers 2022/05/21 06:51:12 DEBUG : dir: reading active writers 2022/05/21 06:51:12 DEBUG : >WaitForWriters: 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file1] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] === RUN TestFileSetModTime/cache=full,open=true,write=false run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:12 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/05/21 06:51:12 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone" 2022/05/21 06:51:12 DEBUG : vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestHdfs{cNNQW}/rclone-test-mocudub5zimetaw7zegixuj6" 2022/05/21 06:51:12 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestHdfs{cNNQW}/rclone-test-mocudub5zimetaw7zegixuj6" 2022/05/21 06:51:12 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestHdfs{cNNQW}/rclone-test-mocudub5zimetaw7zegixuj6" 2022/05/21 06:51:12 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfsMeta/TestHdfs{cNNQW}/rclone-test-mocudub5zimetaw7zegixuj6" 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file1] 2022/05/21 06:51:12 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : dir/file1: Open: flags=O_WRONLY 2022/05/21 06:51:12 DEBUG : dir/file1: newRWFileHandle: 2022/05/21 06:51:12 DEBUG : dir/file1: >newRWFileHandle: err= 2022/05/21 06:51:12 DEBUG : dir/file1: >Open: fd=dir/file1 (rw), err= 2022/05/21 06:51:12 DEBUG : dir/file1(0xc00086b240): close: 2022/05/21 06:51:12 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK 2022/05/21 06:51:12 DEBUG : dir/file1(0xc00086b240): >close: err= 2022/05/21 06:51:12 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:12 DEBUG : dir: Looking for writers 2022/05/21 06:51:12 DEBUG : file1: reading active writers 2022/05/21 06:51:12 DEBUG : : Looking for writers 2022/05/21 06:51:12 DEBUG : dir: reading active writers 2022/05/21 06:51:12 DEBUG : >WaitForWriters: 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:12 DEBUG : dir: Looking for writers 2022/05/21 06:51:12 DEBUG : file1: reading active writers 2022/05/21 06:51:12 DEBUG : : Looking for writers 2022/05/21 06:51:12 DEBUG : dir: reading active writers 2022/05/21 06:51:12 DEBUG : >WaitForWriters: 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : vfs cache: cleaner exiting 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file1] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] --- FAIL: TestFileSetModTime (0.11s) --- FAIL: TestFileSetModTime/cache=off,open=false,write=false (0.06s) --- PASS: TestFileSetModTime/cache=full,open=true,write=false (0.05s) === RUN TestRcGetVFS rc_test.go:28: Error Trace: rc_test.go:28 Error: An error is expected but got nil. Test: TestRcGetVFS --- FAIL: TestRcGetVFS (0.00s) === RUN TestReadFileHandleFlush run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:12 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file1] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : dir/file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : dir/file1: Open: flags=O_RDONLY 2022/05/21 06:51:12 DEBUG : dir/file1: >Open: fd=dir/file1 (r), err= 2022/05/21 06:51:12 DEBUG : dir/file1: >OpenFile: fd=dir/file1 (r), err= 2022/05/21 06:51:12 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: open [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file1] 2022/05/21 06:51:12 DEBUG : dir/file1: ChunkedReader.Read at 0 length 256 chunkOffset 0 chunkSize 134217728 2022/05/21 06:51:12 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:12 DEBUG : dir: Looking for writers 2022/05/21 06:51:12 DEBUG : file1: reading active writers 2022/05/21 06:51:12 DEBUG : : Looking for writers 2022/05/21 06:51:12 DEBUG : dir: reading active writers 2022/05/21 06:51:12 DEBUG : >WaitForWriters: 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file1] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] --- PASS: TestReadFileHandleFlush (0.08s) === RUN TestCaseSensitivity run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/FiLeA] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/FiLeB] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/FilEb] 2022/05/21 06:51:12 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/05/21 06:51:12 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/05/21 06:51:12 DEBUG : FiLeA: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : FiLeA: Open: flags=O_RDONLY 2022/05/21 06:51:12 DEBUG : FiLeA: >Open: fd=FiLeA (r), err= 2022/05/21 06:51:12 DEBUG : FiLeA: >OpenFile: fd=FiLeA (r), err= 2022/05/21 06:51:12 DEBUG : FiLeA: ChunkedReader.openRange at 0 length 134217728 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: open [/rclone-test-mocudub5zimetaw7zegixuj6/FiLeA] 2022/05/21 06:51:12 DEBUG : FiLeA: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2022/05/21 06:51:12 DEBUG : FiLeA: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : FiLeA: Open: flags=O_RDONLY 2022/05/21 06:51:12 DEBUG : FiLeA: >Open: fd=FiLeA (r), err= 2022/05/21 06:51:12 DEBUG : FiLeA: >OpenFile: fd=FiLeA (r), err= 2022/05/21 06:51:12 DEBUG : FiLeA: ChunkedReader.openRange at 0 length 134217728 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: open [/rclone-test-mocudub5zimetaw7zegixuj6/FiLeA] 2022/05/21 06:51:12 DEBUG : FiLeA: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2022/05/21 06:51:12 DEBUG : FiLeA: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : FiLeA: Open: flags=O_RDONLY 2022/05/21 06:51:12 DEBUG : FiLeA: >Open: fd=FiLeA (r), err= 2022/05/21 06:51:12 DEBUG : FiLeA: >OpenFile: fd=FiLeA (r), err= 2022/05/21 06:51:12 DEBUG : FiLeA: ChunkedReader.openRange at 0 length 134217728 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: open [/rclone-test-mocudub5zimetaw7zegixuj6/FiLeA] 2022/05/21 06:51:12 DEBUG : FiLeA: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2022/05/21 06:51:12 DEBUG : FiLeB: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : FiLeB: Open: flags=O_RDONLY 2022/05/21 06:51:12 DEBUG : FiLeB: >Open: fd=FiLeB (r), err= 2022/05/21 06:51:12 DEBUG : FiLeB: >OpenFile: fd=FiLeB (r), err= 2022/05/21 06:51:12 DEBUG : FiLeB: ChunkedReader.openRange at 0 length 134217728 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: open [/rclone-test-mocudub5zimetaw7zegixuj6/FiLeB] 2022/05/21 06:51:12 DEBUG : FiLeB: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2022/05/21 06:51:12 DEBUG : FilEb: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : FilEb: Open: flags=O_RDONLY 2022/05/21 06:51:12 DEBUG : FilEb: >Open: fd=FilEb (r), err= 2022/05/21 06:51:12 DEBUG : FilEb: >OpenFile: fd=FilEb (r), err= 2022/05/21 06:51:12 DEBUG : FilEb: ChunkedReader.openRange at 0 length 134217728 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: open [/rclone-test-mocudub5zimetaw7zegixuj6/FilEb] 2022/05/21 06:51:12 DEBUG : FilEb: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : FiLeA: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : FiLeA: Open: flags=O_RDONLY 2022/05/21 06:51:12 DEBUG : FiLeA: >Open: fd=FiLeA (r), err= 2022/05/21 06:51:12 DEBUG : FiLeA: >OpenFile: fd=FiLeA (r), err= 2022/05/21 06:51:12 DEBUG : FiLeA: ChunkedReader.openRange at 0 length 134217728 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: open [/rclone-test-mocudub5zimetaw7zegixuj6/FiLeA] 2022/05/21 06:51:12 DEBUG : FiLeA: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2022/05/21 06:51:12 DEBUG : fileA: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : FiLeA: Open: flags=O_RDONLY 2022/05/21 06:51:12 DEBUG : FiLeA: >Open: fd=FiLeA (r), err= 2022/05/21 06:51:12 DEBUG : fileA: >OpenFile: fd=FiLeA (r), err= 2022/05/21 06:51:12 DEBUG : FiLeA: ChunkedReader.openRange at 0 length 134217728 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: open [/rclone-test-mocudub5zimetaw7zegixuj6/FiLeA] 2022/05/21 06:51:12 DEBUG : FiLeA: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2022/05/21 06:51:12 DEBUG : filea: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : FiLeA: Open: flags=O_RDONLY 2022/05/21 06:51:12 DEBUG : FiLeA: >Open: fd=FiLeA (r), err= 2022/05/21 06:51:12 DEBUG : filea: >OpenFile: fd=FiLeA (r), err= 2022/05/21 06:51:12 DEBUG : FiLeA: ChunkedReader.openRange at 0 length 134217728 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: open [/rclone-test-mocudub5zimetaw7zegixuj6/FiLeA] 2022/05/21 06:51:12 DEBUG : FiLeA: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2022/05/21 06:51:12 DEBUG : FILEA: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : FiLeA: Open: flags=O_RDONLY 2022/05/21 06:51:12 DEBUG : FiLeA: >Open: fd=FiLeA (r), err= 2022/05/21 06:51:12 DEBUG : FILEA: >OpenFile: fd=FiLeA (r), err= 2022/05/21 06:51:12 DEBUG : FiLeA: ChunkedReader.openRange at 0 length 134217728 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: open [/rclone-test-mocudub5zimetaw7zegixuj6/FiLeA] 2022/05/21 06:51:12 DEBUG : FiLeA: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2022/05/21 06:51:12 DEBUG : FiLeB: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : FiLeB: Open: flags=O_RDONLY 2022/05/21 06:51:12 DEBUG : FiLeB: >Open: fd=FiLeB (r), err= 2022/05/21 06:51:12 DEBUG : FiLeB: >OpenFile: fd=FiLeB (r), err= 2022/05/21 06:51:12 DEBUG : FiLeB: ChunkedReader.openRange at 0 length 134217728 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: open [/rclone-test-mocudub5zimetaw7zegixuj6/FiLeB] 2022/05/21 06:51:12 DEBUG : FiLeB: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2022/05/21 06:51:12 DEBUG : FilEb: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : FilEb: Open: flags=O_RDONLY 2022/05/21 06:51:12 DEBUG : FilEb: >Open: fd=FilEb (r), err= 2022/05/21 06:51:12 DEBUG : FilEb: >OpenFile: fd=FilEb (r), err= 2022/05/21 06:51:12 DEBUG : FilEb: ChunkedReader.openRange at 0 length 134217728 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: open [/rclone-test-mocudub5zimetaw7zegixuj6/FilEb] 2022/05/21 06:51:12 DEBUG : FilEb: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2022/05/21 06:51:12 DEBUG : fileb: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 ERROR : /: Dir.Stat error: duplicate filename "fileb" detected with --vfs-case-insensitive set 2022/05/21 06:51:12 DEBUG : fileb: >OpenFile: fd=, err=duplicate filename "fileb" detected with --vfs-case-insensitive set 2022/05/21 06:51:12 DEBUG : FILEB: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 ERROR : /: Dir.Stat error: duplicate filename "FILEB" detected with --vfs-case-insensitive set 2022/05/21 06:51:12 DEBUG : FILEB: >OpenFile: fd=, err=duplicate filename "FILEB" detected with --vfs-case-insensitive set 2022/05/21 06:51:12 DEBUG : FiLeA: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : FiLeA: Open: flags=O_RDONLY 2022/05/21 06:51:12 DEBUG : FiLeA: >Open: fd=FiLeA (r), err= 2022/05/21 06:51:12 DEBUG : FiLeA: >OpenFile: fd=FiLeA (r), err= 2022/05/21 06:51:12 DEBUG : FiLeA: ChunkedReader.openRange at 0 length 134217728 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: open [/rclone-test-mocudub5zimetaw7zegixuj6/FiLeA] 2022/05/21 06:51:12 DEBUG : FiLeA: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2022/05/21 06:51:12 DEBUG : fileA: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : fileA: >OpenFile: fd=, err=file does not exist 2022/05/21 06:51:12 DEBUG : filea: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : filea: >OpenFile: fd=, err=file does not exist 2022/05/21 06:51:12 DEBUG : FILEA: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : FILEA: >OpenFile: fd=, err=file does not exist 2022/05/21 06:51:12 DEBUG : FiLeB: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : FiLeB: Open: flags=O_RDONLY 2022/05/21 06:51:12 DEBUG : FiLeB: >Open: fd=FiLeB (r), err= 2022/05/21 06:51:12 DEBUG : FiLeB: >OpenFile: fd=FiLeB (r), err= 2022/05/21 06:51:12 DEBUG : FiLeB: ChunkedReader.openRange at 0 length 134217728 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: open [/rclone-test-mocudub5zimetaw7zegixuj6/FiLeB] 2022/05/21 06:51:12 DEBUG : FiLeB: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2022/05/21 06:51:12 DEBUG : FilEb: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : FilEb: Open: flags=O_RDONLY 2022/05/21 06:51:12 DEBUG : FilEb: >Open: fd=FilEb (r), err= 2022/05/21 06:51:12 DEBUG : FilEb: >OpenFile: fd=FilEb (r), err= 2022/05/21 06:51:12 DEBUG : FilEb: ChunkedReader.openRange at 0 length 134217728 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: open [/rclone-test-mocudub5zimetaw7zegixuj6/FilEb] 2022/05/21 06:51:12 DEBUG : FilEb: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2022/05/21 06:51:12 DEBUG : fileb: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : fileb: >OpenFile: fd=, err=file does not exist 2022/05/21 06:51:12 DEBUG : FILEB: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : FILEB: >OpenFile: fd=, err=file does not exist 2022/05/21 06:51:12 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:12 DEBUG : : Looking for writers 2022/05/21 06:51:12 DEBUG : FiLeA: reading active writers 2022/05/21 06:51:12 DEBUG : FiLeB: reading active writers 2022/05/21 06:51:12 DEBUG : FilEb: reading active writers 2022/05/21 06:51:12 DEBUG : >WaitForWriters: 2022/05/21 06:51:12 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:12 DEBUG : : Looking for writers 2022/05/21 06:51:12 DEBUG : FiLeA: reading active writers 2022/05/21 06:51:12 DEBUG : FiLeB: reading active writers 2022/05/21 06:51:12 DEBUG : FilEb: reading active writers 2022/05/21 06:51:12 DEBUG : >WaitForWriters: 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/FiLeA] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/FiLeB] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/FilEb] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] --- PASS: TestCaseSensitivity (0.10s) === RUN TestVFSNew vfs_test.go:134: Error Trace: vfs_test.go:134 vfs_test.go:137 Error: Not equal: expected: 0 actual : 1 Test: TestVFSNew run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:12 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote vfs_test.go:134: Error Trace: vfs_test.go:134 vfs_test.go:147 Error: Not equal: expected: 1 actual : 2 Test: TestVFSNew 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: 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 : 2 Test: TestVFSNew vfs_test.go:134: Error Trace: vfs_test.go:134 vfs_test.go:159 Error: Not equal: expected: 1 actual : 2 Test: TestVFSNew 2022/05/21 06:51:12 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:12 DEBUG : : Looking for writers 2022/05/21 06:51:12 DEBUG : >WaitForWriters: 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] vfs_test.go:134: Error Trace: vfs_test.go:134 vfs_test.go:163 Error: Not equal: expected: 0 actual : 1 Test: TestVFSNew --- FAIL: TestVFSNew (0.00s) === RUN TestVFSStat run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:12 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file2] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:12 DEBUG : dir: Looking for writers 2022/05/21 06:51:12 DEBUG : file2: reading active writers 2022/05/21 06:51:12 DEBUG : : Looking for writers 2022/05/21 06:51:12 DEBUG : dir: reading active writers 2022/05/21 06:51:12 DEBUG : file1: reading active writers 2022/05/21 06:51:12 DEBUG : >WaitForWriters: 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file2] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] --- PASS: TestVFSStat (0.04s) === RUN TestVFSStatParent run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:12 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file2] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:12 DEBUG : dir: Looking for writers 2022/05/21 06:51:12 DEBUG : : Looking for writers 2022/05/21 06:51:12 DEBUG : dir: reading active writers 2022/05/21 06:51:12 DEBUG : file1: reading active writers 2022/05/21 06:51:12 DEBUG : >WaitForWriters: 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file2] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] --- PASS: TestVFSStatParent (0.04s) === RUN TestVFSOpenFile run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:12 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file2] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : file1: Open: flags=O_RDONLY 2022/05/21 06:51:12 DEBUG : file1: >Open: fd=file1 (r), err= 2022/05/21 06:51:12 DEBUG : file1: >OpenFile: fd=file1 (r), err= 2022/05/21 06:51:12 DEBUG : dir: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : dir: >OpenFile: fd=dir/ (r), err= 2022/05/21 06:51:12 DEBUG : dir/new_file.txt: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : dir/new_file.txt: >OpenFile: fd=, err=file does not exist 2022/05/21 06:51:12 DEBUG : dir/new_file.txt: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : dir/new_file.txt: Open: flags=O_WRONLY|O_CREATE 2022/05/21 06:51:12 DEBUG : dir: Added virtual directory entry vAddFile: "new_file.txt" 2022/05/21 06:51:12 DEBUG : dir/new_file.txt: >Open: fd=dir/new_file.txt (w), err= 2022/05/21 06:51:12 DEBUG : dir/new_file.txt: >OpenFile: fd=dir/new_file.txt (w), err= 2022/05/21 06:51:12 DEBUG : dir: Added virtual directory entry vAddFile: "new_file.txt" 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: File to upload is small (0 bytes), uploading instead of streaming 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/dir/new_file.txt] 2022/05/21 06:51:12 INFO : dir/new_file.txt: Copied (new) 2022/05/21 06:51:12 DEBUG : dir: Added virtual directory entry vAddFile: "new_file.txt" 2022/05/21 06:51:12 DEBUG : not found/new_file.txt: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2022/05/21 06:51:12 DEBUG : not found/new_file.txt: >OpenFile: fd=, err=file does not exist 2022/05/21 06:51:12 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:12 DEBUG : dir: Looking for writers 2022/05/21 06:51:12 DEBUG : file2: reading active writers 2022/05/21 06:51:12 DEBUG : new_file.txt: reading active writers 2022/05/21 06:51:12 DEBUG : : Looking for writers 2022/05/21 06:51:12 DEBUG : dir: reading active writers 2022/05/21 06:51:12 DEBUG : file1: reading active writers 2022/05/21 06:51:12 DEBUG : >WaitForWriters: 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file2] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/dir/new_file.txt] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] --- PASS: TestVFSOpenFile (0.06s) === RUN TestVFSRename run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:12 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file2] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: new [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file1] 2022/05/21 06:51:12 DEBUG : hdfs://127.0.0.1:8020: rename [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file2] to [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file1] 2022/05/21 06:51:13 INFO : dir/file2: Moved (server-side) to: dir/file1 2022/05/21 06:51:13 DEBUG : dir/file1: Updating file with dir/file1 0xc0005ae540 2022/05/21 06:51:13 DEBUG : dir: Added virtual directory entry vDel: "file2" 2022/05/21 06:51:13 DEBUG : dir: Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: new [/rclone-test-mocudub5zimetaw7zegixuj6/file0] 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: rename [/rclone-test-mocudub5zimetaw7zegixuj6/dir/file1] to [/rclone-test-mocudub5zimetaw7zegixuj6/file0] 2022/05/21 06:51:13 INFO : dir/file1: Moved (server-side) to: file0 2022/05/21 06:51:13 DEBUG : file0: Updating file with file0 0xc0005ae540 2022/05/21 06:51:13 DEBUG : dir: Added virtual directory entry vDel: "file1" 2022/05/21 06:51:13 DEBUG : : Added virtual directory entry vAddFile: "file0" 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:13 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:13 DEBUG : dir: Looking for writers 2022/05/21 06:51:13 DEBUG : : Looking for writers 2022/05/21 06:51:13 DEBUG : dir: reading active writers 2022/05/21 06:51:13 DEBUG : file0: reading active writers 2022/05/21 06:51:13 DEBUG : >WaitForWriters: 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/file0] 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-mocudub5zimetaw7zegixuj6/dir] 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] --- PASS: TestVFSRename (0.03s) === RUN TestWriteFileHandleMethods run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:13 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/05/21 06:51:13 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:13 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2022/05/21 06:51:13 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:13 DEBUG : file1: >Open: fd=file1 (w), err= 2022/05/21 06:51:13 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2022/05/21 06:51:13 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:13 ERROR : file1: WriteFileHandle: Read: Can't read and write to file without --vfs-cache-mode >= minimal 2022/05/21 06:51:13 ERROR : file1: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal 2022/05/21 06:51:13 ERROR : file1: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: File to upload is small (5 bytes), uploading instead of streaming 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:13 INFO : file1: Copied (new) 2022/05/21 06:51:13 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:13 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2022/05/21 06:51:13 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2022/05/21 06:51:13 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:13 DEBUG : file1: >Open: fd=file1 (w), err= 2022/05/21 06:51:13 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2022/05/21 06:51:13 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2022/05/21 06:51:13 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2022/05/21 06:51:13 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:13 DEBUG : file1: >Open: fd=file1 (w), err= 2022/05/21 06:51:13 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2022/05/21 06:51:13 ERROR : file1: WriteFileHandle: Can't open for write without O_TRUNC on existing file without --vfs-cache-mode >= writes 2022/05/21 06:51:13 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx 2022/05/21 06:51:13 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE|O_TRUNC 2022/05/21 06:51:13 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:13 DEBUG : file1: >Open: fd=file1 (w), err= 2022/05/21 06:51:13 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2022/05/21 06:51:13 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: File to upload is small (0 bytes), uploading instead of streaming 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:13 INFO : file1: Copied (new) 2022/05/21 06:51:13 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:13 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx 2022/05/21 06:51:13 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE|O_TRUNC 2022/05/21 06:51:13 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:13 DEBUG : file1: >Open: fd=file1 (w), err= 2022/05/21 06:51:13 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2022/05/21 06:51:13 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: File to upload is small (7 bytes), uploading instead of streaming 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:13 INFO : file1: Copied (new) 2022/05/21 06:51:13 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:13 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:13 DEBUG : : Looking for writers 2022/05/21 06:51:13 DEBUG : file1: reading active writers 2022/05/21 06:51:13 DEBUG : >WaitForWriters: 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] --- PASS: TestWriteFileHandleMethods (0.06s) === RUN TestWriteFileHandleWriteAt run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:13 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/05/21 06:51:13 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2022/05/21 06:51:13 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:13 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2022/05/21 06:51:13 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:13 DEBUG : file1: >Open: fd=file1 (w), err= 2022/05/21 06:51:13 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2022/05/21 06:51:13 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:13 DEBUG : file1: waiting for in-sequence write to 100 for 1s 2022/05/21 06:51:14 DEBUG : file1: aborting in-sequence write wait, off=100 2022/05/21 06:51:14 DEBUG : file1: failed to wait for in-sequence write to 100 2022/05/21 06:51:14 ERROR : file1: WriteFileHandle.Write: can't seek in file without --vfs-cache-mode >= writes 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: File to upload is small (11 bytes), uploading instead of streaming 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:14 INFO : file1: Copied (new) 2022/05/21 06:51:14 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:14 ERROR : file1: WriteFileHandle.Write: error: Bad file descriptor 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:14 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:14 DEBUG : : Looking for writers 2022/05/21 06:51:14 DEBUG : file1: reading active writers 2022/05/21 06:51:14 DEBUG : >WaitForWriters: 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] --- PASS: TestWriteFileHandleWriteAt (1.02s) === RUN TestWriteFileHandleFlush run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:14 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/05/21 06:51:14 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:14 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2022/05/21 06:51:14 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:14 DEBUG : file1: >Open: fd=file1 (w), err= 2022/05/21 06:51:14 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2022/05/21 06:51:14 DEBUG : file1: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions 2022/05/21 06:51:14 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: File to upload is small (5 bytes), uploading instead of streaming 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:14 INFO : file1: Copied (new) 2022/05/21 06:51:14 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:14 DEBUG : file1: WriteFileHandle.Flush nothing to do 2022/05/21 06:51:14 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:14 DEBUG : : Looking for writers 2022/05/21 06:51:14 DEBUG : file1: reading active writers 2022/05/21 06:51:14 DEBUG : >WaitForWriters: 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] --- PASS: TestWriteFileHandleFlush (0.01s) === RUN TestWriteFileModTimeWithOpenWriters run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:14 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/05/21 06:51:14 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:14 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2022/05/21 06:51:14 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:14 DEBUG : file1: >Open: fd=file1 (w), err= 2022/05/21 06:51:14 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2022/05/21 06:51:14 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: File to upload is small (2 bytes), uploading instead of streaming 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:14 ERROR : file1: Failed to copy: create /rclone-test-mocudub5zimetaw7zegixuj6/file1: replication in progress 2022/05/21 06:51:14 ERROR : file1: WriteFileHandle.New Rcat failed: create /rclone-test-mocudub5zimetaw7zegixuj6/file1: replication in progress write_test.go:277: Error Trace: write_test.go:277 Error: Received unexpected error: create /rclone-test-mocudub5zimetaw7zegixuj6/file1: replication in progress Test: TestWriteFileModTimeWithOpenWriters 2022/05/21 06:51:14 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:14 DEBUG : : Looking for writers 2022/05/21 06:51:14 DEBUG : file1: reading active writers 2022/05/21 06:51:14 DEBUG : >WaitForWriters: 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] --- FAIL: TestWriteFileModTimeWithOpenWriters (0.01s) === RUN TestFileReadAtZeroLength run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:14 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/05/21 06:51:14 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:14 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2022/05/21 06:51:14 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:14 DEBUG : file1: >Open: fd=file1 (w), err= 2022/05/21 06:51:14 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2022/05/21 06:51:14 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: File to upload is small (0 bytes), uploading instead of streaming 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:14 INFO : file1: Copied (new) 2022/05/21 06:51:14 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:14 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2022/05/21 06:51:14 DEBUG : file1: Open: flags=O_RDONLY 2022/05/21 06:51:14 DEBUG : file1: >Open: fd=file1 (r), err= 2022/05/21 06:51:14 DEBUG : file1: >OpenFile: fd=file1 (r), err= 2022/05/21 06:51:14 DEBUG : file1: ChunkedReader.openRange at 0 length 134217728 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: open [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:14 DEBUG : file1: ChunkedReader.Read at 0 length 1024 chunkOffset 0 chunkSize 134217728 2022/05/21 06:51:14 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:14 DEBUG : : Looking for writers 2022/05/21 06:51:14 DEBUG : file1: reading active writers 2022/05/21 06:51:14 DEBUG : >WaitForWriters: 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] --- PASS: TestFileReadAtZeroLength (0.01s) === RUN TestFileReadAtNonZeroLength run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone1442219142", Modify Window "1s" 2022/05/21 06:51:14 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/05/21 06:51:14 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:14 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2022/05/21 06:51:14 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:14 DEBUG : file1: >Open: fd=file1 (w), err= 2022/05/21 06:51:14 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2022/05/21 06:51:14 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: File to upload is small (100 bytes), uploading instead of streaming 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:14 INFO : file1: Copied (new) 2022/05/21 06:51:14 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/05/21 06:51:14 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2022/05/21 06:51:14 DEBUG : file1: Open: flags=O_RDONLY 2022/05/21 06:51:14 DEBUG : file1: >Open: fd=file1 (r), err= 2022/05/21 06:51:14 DEBUG : file1: >OpenFile: fd=file1 (r), err= 2022/05/21 06:51:14 DEBUG : file1: ChunkedReader.openRange at 0 length 134217728 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: open [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:14 DEBUG : file1: ChunkedReader.Read at 0 length 1024 chunkOffset 0 chunkSize 134217728 2022/05/21 06:51:14 DEBUG : WaitForWriters: timeout=30s 2022/05/21 06:51:14 DEBUG : : Looking for writers 2022/05/21 06:51:14 DEBUG : file1: reading active writers 2022/05/21 06:51:14 DEBUG : >WaitForWriters: 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-mocudub5zimetaw7zegixuj6/file1] 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-mocudub5zimetaw7zegixuj6] --- PASS: TestFileReadAtNonZeroLength (0.02s) FAIL 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: Purge remote 2022/05/21 06:51:14 DEBUG : hdfs://127.0.0.1:8020: purge [/rclone-test-mocudub5zimetaw7zegixuj6] "./vfs.test -test.v -test.timeout 1h0m0s -remote TestHdfs: -verbose -test.run '^(TestCaseSensitivity|TestDirHandleMethods|TestDirHandleReaddir|TestDirReadDirAll|TestDirRename|TestDirWalk|TestFileReadAtNonZeroLength|TestFileReadAtZeroLength|TestFileSetModTime|TestRcGetVFS|TestReadFileHandleFlush|TestVFSNew|TestVFSOpenFile|TestVFSRename|TestVFSStat|TestVFSStatParent|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleWriteAt|TestWriteFileModTimeWithOpenWriters)$/^(cache=full,open=true,write=false|cache=off,open=false,write=false)$'" - Finished ERROR in 2.23180553s (try 2/5): exit status 1: Failed [TestDirHandleMethods TestDirHandleReaddir TestDirWalk TestDirReadDirAll TestFileSetModTime/cache=off,open=false,write=false TestRcGetVFS TestVFSNew TestWriteFileModTimeWithOpenWriters]