"./vfs.test -test.v -test.timeout 1h0m0s -remote TestHdfs: -verbose -test.run '^(TestDirForgetAll|TestDirForgetPath|TestDirHandleMethods|TestDirHandleReaddirnames|TestDirOpen|TestDirReadDirAll|TestDirSetModTime|TestFileOpenRead|TestFileSetModTime|TestRcGetVFS|TestVFSNew|TestVFSStat|TestWriteFileHandleMethods)$/^cache=off,open=true,write=true$'" - Starting (try 2/5) 2022/06/17 08:08:28 DEBUG : Creating backend with remote "TestHdfs:rclone-test-cuyucoq8muzumed2kafapib1" 2022/06/17 08:08:28 DEBUG : Setting type="hdfs" for "TestHdfs" from environment variable RCLONE_CONFIG_TESTHDFS_TYPE 2022/06/17 08:08:28 DEBUG : Setting namenode="127.0.0.1:8020" for "TestHdfs" from environment variable RCLONE_CONFIG_TESTHDFS_NAMENODE 2022/06/17 08:08:28 DEBUG : Setting username="root" for "TestHdfs" from environment variable RCLONE_CONFIG_TESTHDFS_USERNAME 2022/06/17 08:08:28 DEBUG : TestHdfs: detected overridden config - adding "{cNNQW}" suffix to name 2022/06/17 08:08:28 DEBUG : Setting namenode="127.0.0.1:8020" for "TestHdfs" from environment variable RCLONE_CONFIG_TESTHDFS_NAMENODE 2022/06/17 08:08:28 DEBUG : Setting username="root" for "TestHdfs" from environment variable RCLONE_CONFIG_TESTHDFS_USERNAME 2022/06/17 08:08:28 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2022/06/17 08:08:28 DEBUG : Creating backend with remote "/tmp/rclone2226715574" === RUN TestDirHandleMethods run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone2226715574", Modify Window "1s" 2022/06/17 08:08:28 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: mkdir [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file1] run.go:287: Failed to put "dir/file1" to "hdfs://127.0.0.1:8020": create /rclone-test-cuyucoq8muzumed2kafapib1/dir/file1: replication in progress --- FAIL: TestDirHandleMethods (0.22s) === RUN TestDirHandleReaddirnames run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone2226715574", Modify Window "1s" 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: Re-using VFS from active cache 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:28 DEBUG : WaitForWriters: timeout=30s 2022/06/17 08:08:28 DEBUG : dir: Looking for writers 2022/06/17 08:08:28 DEBUG : file1: reading active writers 2022/06/17 08:08:28 DEBUG : : Looking for writers 2022/06/17 08:08:28 DEBUG : dir: reading active writers 2022/06/17 08:08:28 DEBUG : >WaitForWriters: 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] --- PASS: TestDirHandleReaddirnames (0.04s) === RUN TestDirForgetAll run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone2226715574", Modify Window "1s" 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: Re-using VFS from active cache 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:28 DEBUG : dir: forgetting directory cache 2022/06/17 08:08:28 DEBUG : : forgetting directory cache 2022/06/17 08:08:28 DEBUG : dir: forgetting directory cache 2022/06/17 08:08:28 DEBUG : WaitForWriters: timeout=30s 2022/06/17 08:08:28 DEBUG : : Looking for writers 2022/06/17 08:08:28 DEBUG : >WaitForWriters: 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] --- PASS: TestDirForgetAll (0.03s) === RUN TestDirForgetPath run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone2226715574", Modify Window "1s" 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: Re-using VFS from active cache 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file1] run.go:287: Failed to put "dir/file1" to "hdfs://127.0.0.1:8020": create /rclone-test-cuyucoq8muzumed2kafapib1/dir/file1: replication in progress --- FAIL: TestDirForgetPath (0.01s) === RUN TestDirSetModTime run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone2226715574", Modify Window "1s" 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: Re-using VFS from active cache 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:28 DEBUG : WaitForWriters: timeout=30s 2022/06/17 08:08:28 DEBUG : dir: Looking for writers 2022/06/17 08:08:28 DEBUG : : Looking for writers 2022/06/17 08:08:28 DEBUG : dir: reading active writers 2022/06/17 08:08:28 DEBUG : >WaitForWriters: 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] --- PASS: TestDirSetModTime (0.03s) === RUN TestDirReadDirAll run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone2226715574", Modify Window "1s" 2022/06/17 08:08:28 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file2] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-cuyucoq8muzumed2kafapib1/dir/subdir/file3] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir/subdir] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir/subdir] 2022/06/17 08:08:28 DEBUG : WaitForWriters: timeout=30s 2022/06/17 08:08:28 DEBUG : dir/subdir: Looking for writers 2022/06/17 08:08:28 DEBUG : file3: reading active writers 2022/06/17 08:08:28 DEBUG : dir: Looking for writers 2022/06/17 08:08:28 DEBUG : file1: reading active writers 2022/06/17 08:08:28 DEBUG : file2: reading active writers 2022/06/17 08:08:28 DEBUG : subdir: reading active writers 2022/06/17 08:08:28 DEBUG : : Looking for writers 2022/06/17 08:08:28 DEBUG : dir: reading active writers 2022/06/17 08:08:28 DEBUG : >WaitForWriters: 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file2] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir/subdir] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-cuyucoq8muzumed2kafapib1/dir/subdir/file3] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-cuyucoq8muzumed2kafapib1/dir/subdir] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] --- PASS: TestDirReadDirAll (0.06s) === RUN TestDirOpen run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone2226715574", Modify Window "1s" 2022/06/17 08:08:28 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file1] run.go:287: Failed to put "dir/file1" to "hdfs://127.0.0.1:8020": create /rclone-test-cuyucoq8muzumed2kafapib1/dir/file1: replication in progress --- FAIL: TestDirOpen (0.01s) === RUN TestFileSetModTime === RUN TestFileSetModTime/cache=off,open=true,write=true run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone2226715574", Modify Window "1s" 2022/06/17 08:08:28 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-cuyucoq8muzumed2kafapib1/time_test] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: new [/rclone-test-cuyucoq8muzumed2kafapib1/time_test] 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-cuyucoq8muzumed2kafapib1/time_test] 2022/06/17 08:08:28 DEBUG : Can set mod time: true 2022/06/17 08:08:28 DEBUG : dir/file1: Open: flags=O_WRONLY|O_TRUNC 2022/06/17 08:08:28 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err= 2022/06/17 08:08:28 DEBUG : dir: Added virtual directory entry vAddFile: "file1" 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: File to upload is small (5 bytes), uploading instead of streaming 2022/06/17 08:08:28 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file1] 2022/06/17 08:08:29 INFO : dir/file1: Copied (new) 2022/06/17 08:08:29 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK 2022/06/17 08:08:29 DEBUG : dir: Added virtual directory entry vAddFile: "file1" 2022/06/17 08:08:29 DEBUG : WaitForWriters: timeout=30s 2022/06/17 08:08:29 DEBUG : dir: Looking for writers 2022/06/17 08:08:29 DEBUG : file1: reading active writers 2022/06/17 08:08:29 DEBUG : : Looking for writers 2022/06/17 08:08:29 DEBUG : dir: reading active writers 2022/06/17 08:08:29 DEBUG : >WaitForWriters: 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:29 DEBUG : WaitForWriters: timeout=30s 2022/06/17 08:08:29 DEBUG : dir: Looking for writers 2022/06/17 08:08:29 DEBUG : file1: reading active writers 2022/06/17 08:08:29 DEBUG : : Looking for writers 2022/06/17 08:08:29 DEBUG : dir: reading active writers 2022/06/17 08:08:29 DEBUG : >WaitForWriters: 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file1] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] --- PASS: TestFileSetModTime (0.05s) --- PASS: TestFileSetModTime/cache=off,open=true,write=true (0.05s) === RUN TestFileOpenRead run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone2226715574", Modify Window "1s" 2022/06/17 08:08:29 INFO : hdfs://127.0.0.1:8020: poll-interval is not supported by this remote 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file1] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:29 DEBUG : dir/file1: Open: flags=O_RDONLY 2022/06/17 08:08:29 DEBUG : dir/file1: >Open: fd=dir/file1 (r), err= 2022/06/17 08:08:29 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: open [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file1] 2022/06/17 08:08:29 DEBUG : dir/file1: ChunkedReader.Read at 0 length 512 chunkOffset 0 chunkSize 134217728 2022/06/17 08:08:29 DEBUG : WaitForWriters: timeout=30s 2022/06/17 08:08:29 DEBUG : dir: Looking for writers 2022/06/17 08:08:29 DEBUG : file1: reading active writers 2022/06/17 08:08:29 DEBUG : : Looking for writers 2022/06/17 08:08:29 DEBUG : dir: reading active writers 2022/06/17 08:08:29 DEBUG : >WaitForWriters: 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file1] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] --- PASS: TestFileOpenRead (0.06s) === 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:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone2226715574", Modify Window "1s" 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: 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 Test: TestRcGetVFS 2022/06/17 08:08:29 DEBUG : WaitForWriters: timeout=30s 2022/06/17 08:08:29 DEBUG : : Looking for writers 2022/06/17 08:08:29 DEBUG : >WaitForWriters: 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] --- FAIL: TestRcGetVFS (0.00s) === RUN TestVFSNew vfs_test.go:134: Error Trace: vfs_test.go:134 vfs_test.go:137 Error: Not equal: expected: 0 actual : 2 Test: TestVFSNew run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone2226715574", Modify Window "1s" 2022/06/17 08:08:29 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:147 Error: Not equal: expected: 1 actual : 2 Test: TestVFSNew 2022/06/17 08:08:29 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/06/17 08:08:29 DEBUG : WaitForWriters: timeout=30s 2022/06/17 08:08:29 DEBUG : : Looking for writers 2022/06/17 08:08:29 DEBUG : >WaitForWriters: 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] vfs_test.go:134: Error Trace: vfs_test.go:134 vfs_test.go:163 Error: Not equal: expected: 0 actual : 2 Test: TestVFSNew --- FAIL: TestVFSNew (0.00s) === RUN TestVFSStat run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone2226715574", Modify Window "1s" 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: Re-using VFS from active cache 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-cuyucoq8muzumed2kafapib1/file1] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file2] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:29 DEBUG : WaitForWriters: timeout=30s 2022/06/17 08:08:29 DEBUG : dir: Looking for writers 2022/06/17 08:08:29 DEBUG : file2: reading active writers 2022/06/17 08:08:29 DEBUG : : Looking for writers 2022/06/17 08:08:29 DEBUG : dir: reading active writers 2022/06/17 08:08:29 DEBUG : file1: reading active writers 2022/06/17 08:08:29 DEBUG : >WaitForWriters: 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-cuyucoq8muzumed2kafapib1/file1] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: remove [/rclone-test-cuyucoq8muzumed2kafapib1/dir/file2] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: rmdir [/rclone-test-cuyucoq8muzumed2kafapib1/dir] 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] --- PASS: TestVFSStat (0.04s) === RUN TestWriteFileHandleMethods run.go:181: Remote "hdfs://127.0.0.1:8020", Local "Local file system at /tmp/rclone2226715574", Modify Window "1s" 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: Re-using VFS from active cache 2022/06/17 08:08:29 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2022/06/17 08:08:29 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2022/06/17 08:08:29 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/06/17 08:08:29 DEBUG : file1: >Open: fd=file1 (w), err= 2022/06/17 08:08:29 DEBUG : file1: >OpenFile: fd=file1 (w), err= write_test.go:46: Error Trace: write_test.go:46 Error: Not equal: expected: 0 actual : 14 Test: TestWriteFileHandleMethods 2022/06/17 08:08:29 ERROR : file1: WriteFileHandle: Can't open for write without O_TRUNC on existing file without --vfs-cache-mode >= writes write_test.go:50: Error Trace: write_test.go:50 Error: Received unexpected error: permission denied Test: TestWriteFileHandleMethods write_test.go:51: Error Trace: write_test.go:51 Error: Not equal: expected: 5 actual : 0 Test: TestWriteFileHandleMethods write_test.go:54: Error Trace: write_test.go:54 Error: Not equal: expected: 5 actual : 0 Test: TestWriteFileHandleMethods write_test.go:55: Error Trace: write_test.go:55 Error: Not equal: expected: 5 actual : 14 Test: TestWriteFileHandleMethods write_test.go:61: Error Trace: write_test.go:61 Error: Not equal: expected: 5 actual : 14 Test: TestWriteFileHandleMethods 2022/06/17 08:08:29 ERROR : file1: WriteFileHandle: Read: Can't read and write to file without --vfs-cache-mode >= minimal 2022/06/17 08:08:29 ERROR : file1: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal 2022/06/17 08:08:29 ERROR : file1: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes write_test.go:79: Error Trace: write_test.go:79 Error: Received unexpected error: permission denied Test: TestWriteFileHandleMethods 2022/06/17 08:08:29 ERROR : file1: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes dir_test.go:252: Error Trace: dir_test.go:252 write_test.go:93 Error: Not equal: expected: []string{"file1,5,false"} actual : []string{"dir,0,true", "file1,14,false"} Diff: --- Expected +++ Actual @@ -1,3 +1,4 @@ -([]string) (len=1) { - (string) (len=13) "file1,5,false" +([]string) (len=2) { + (string) (len=10) "dir,0,true", + (string) (len=14) "file1,14,false" } Test: TestWriteFileHandleMethods 2022/06/17 08:08:29 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 2022/06/17 08:08:30 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 2022/06/17 08:08:32 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 write_test.go:97 Error: Should be true Test: TestWriteFileHandleMethods Messages: listing wrong, want file1 (5) got fstest.go:204: Not found "file1" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 write_test.go:97 Error: Not equal: expected: 0 actual : 1 Test: TestWriteFileHandleMethods Messages: 1 objects not found 2022/06/17 08:08:36 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2022/06/17 08:08:36 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2022/06/17 08:08:36 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/06/17 08:08:36 DEBUG : file1: >Open: fd=file1 (w), err= 2022/06/17 08:08:36 DEBUG : file1: >OpenFile: fd=file1 (w), err= dir_test.go:252: Error Trace: dir_test.go:252 write_test.go:104 Error: Not equal: expected: []string{"file1,5,false"} actual : []string{"dir,0,true", "file1,14,false"} Diff: --- Expected +++ Actual @@ -1,3 +1,4 @@ -([]string) (len=1) { - (string) (len=13) "file1,5,false" +([]string) (len=2) { + (string) (len=10) "dir,0,true", + (string) (len=14) "file1,14,false" } Test: TestWriteFileHandleMethods 2022/06/17 08:08:36 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2022/06/17 08:08:36 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2022/06/17 08:08:36 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/06/17 08:08:36 DEBUG : file1: >Open: fd=file1 (w), err= 2022/06/17 08:08:36 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2022/06/17 08:08:36 ERROR : file1: WriteFileHandle: Can't open for write without O_TRUNC on existing file without --vfs-cache-mode >= writes dir_test.go:252: Error Trace: dir_test.go:252 write_test.go:113 Error: Not equal: expected: []string{"file1,5,false"} actual : []string{"dir,0,true", "file1,14,false"} Diff: --- Expected +++ Actual @@ -1,3 +1,4 @@ -([]string) (len=1) { - (string) (len=13) "file1,5,false" +([]string) (len=2) { + (string) (len=10) "dir,0,true", + (string) (len=14) "file1,14,false" } Test: TestWriteFileHandleMethods 2022/06/17 08:08:36 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx 2022/06/17 08:08:36 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE|O_TRUNC 2022/06/17 08:08:36 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/06/17 08:08:36 DEBUG : file1: >Open: fd=file1 (w), err= 2022/06/17 08:08:36 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2022/06/17 08:08:36 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/06/17 08:08:36 DEBUG : hdfs://127.0.0.1:8020: File to upload is small (0 bytes), uploading instead of streaming 2022/06/17 08:08:36 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-cuyucoq8muzumed2kafapib1/file1] 2022/06/17 08:08:36 INFO : file1: Copied (new) 2022/06/17 08:08:36 DEBUG : : Added virtual directory entry vAddFile: "file1" dir_test.go:252: Error Trace: dir_test.go:252 write_test.go:122 Error: Not equal: expected: []string{"file1,0,false"} actual : []string{"dir,0,true", "file1,0,false"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) (len=1) { +([]string) (len=2) { + (string) (len=10) "dir,0,true", (string) (len=13) "file1,0,false" Test: TestWriteFileHandleMethods 2022/06/17 08:08:36 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx 2022/06/17 08:08:36 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE|O_TRUNC 2022/06/17 08:08:36 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/06/17 08:08:36 DEBUG : file1: >Open: fd=file1 (w), err= 2022/06/17 08:08:36 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2022/06/17 08:08:36 DEBUG : : Added virtual directory entry vAddFile: "file1" 2022/06/17 08:08:36 DEBUG : hdfs://127.0.0.1:8020: File to upload is small (7 bytes), uploading instead of streaming 2022/06/17 08:08:36 DEBUG : hdfs://127.0.0.1:8020: update [/rclone-test-cuyucoq8muzumed2kafapib1/file1] 2022/06/17 08:08:36 ERROR : file1: Failed to copy: create /rclone-test-cuyucoq8muzumed2kafapib1/file1: replication in progress 2022/06/17 08:08:36 ERROR : file1: WriteFileHandle.New Rcat failed: create /rclone-test-cuyucoq8muzumed2kafapib1/file1: replication in progress write_test.go:130: Error Trace: write_test.go:130 Error: Received unexpected error: create /rclone-test-cuyucoq8muzumed2kafapib1/file1: replication in progress Test: TestWriteFileHandleMethods dir_test.go:252: Error Trace: dir_test.go:252 write_test.go:131 Error: Not equal: expected: []string{"file1,7,false"} actual : []string{"dir,0,true", "file1,0,false"} Diff: --- Expected +++ Actual @@ -1,3 +1,4 @@ -([]string) (len=1) { - (string) (len=13) "file1,7,false" +([]string) (len=2) { + (string) (len=10) "dir,0,true", + (string) (len=13) "file1,0,false" } Test: TestWriteFileHandleMethods 2022/06/17 08:08:36 DEBUG : WaitForWriters: timeout=30s 2022/06/17 08:08:36 DEBUG : dir: Looking for writers 2022/06/17 08:08:36 DEBUG : file2: reading active writers 2022/06/17 08:08:36 DEBUG : : Looking for writers 2022/06/17 08:08:36 DEBUG : dir: reading active writers 2022/06/17 08:08:36 DEBUG : file1: reading active writers 2022/06/17 08:08:36 DEBUG : >WaitForWriters: 2022/06/17 08:08:36 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] 2022/06/17 08:08:36 DEBUG : hdfs://127.0.0.1:8020: list [/rclone-test-cuyucoq8muzumed2kafapib1] --- FAIL: TestWriteFileHandleMethods (7.04s) FAIL 2022/06/17 08:08:36 DEBUG : hdfs://127.0.0.1:8020: Purge remote 2022/06/17 08:08:36 DEBUG : hdfs://127.0.0.1:8020: purge [/rclone-test-cuyucoq8muzumed2kafapib1] "./vfs.test -test.v -test.timeout 1h0m0s -remote TestHdfs: -verbose -test.run '^(TestDirForgetAll|TestDirForgetPath|TestDirHandleMethods|TestDirHandleReaddirnames|TestDirOpen|TestDirReadDirAll|TestDirSetModTime|TestFileOpenRead|TestFileSetModTime|TestRcGetVFS|TestVFSNew|TestVFSStat|TestWriteFileHandleMethods)$/^cache=off,open=true,write=true$'" - Finished ERROR in 7.720829869s (try 2/5): exit status 1: Failed [TestDirHandleMethods TestDirForgetPath TestDirOpen TestRcGetVFS TestVFSNew TestWriteFileHandleMethods]