"./vfs.test -test.v -test.timeout 1h0m0s -remote TestMega: -verbose -test.run '^(TestFileRename|TestRWFileHandleOpenTests)$/^(CacheModeFull|CacheModeOff)$'" - Starting (try 4/5) === RUN TestFileRename === RUN TestFileRename/CacheModeOff 2020/05/15 05:19:54 INFO : mega root 'rclone-test-faboyem1ribuzes8ralepeg9': poll-interval is not supported by this remote 2020/05/15 05:19:54 DEBUG : Adding path "vfs/forget" to remote control registry 2020/05/15 05:19:54 DEBUG : Adding path "vfs/refresh" to remote control registry 2020/05/15 05:19:54 DEBUG : Adding path "vfs/poll-interval" to remote control registry 2020/05/15 05:19:59 INFO : dir/file1: Moved (server side) 2020/05/15 05:19:59 DEBUG : newLeaf: Updating file with newLeaf 0xc0002880e0 2020/05/15 05:20:08 INFO : newLeaf: Moved (server side) 2020/05/15 05:20:08 DEBUG : dir/file1: Updating file with dir/file1 0xc0002880e0 2020/05/15 05:20:15 DEBUG : dir/file1: Open: flags=O_WRONLY|O_TRUNC 2020/05/15 05:20:15 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err= 2020/05/15 05:20:15 DEBUG : newLeaf: File is currently open, delaying rename 0xc0002880e0 2020/05/15 05:20:15 DEBUG : mega root 'rclone-test-faboyem1ribuzes8ralepeg9': File to upload is small (25 bytes), uploading instead of streaming 2020/05/15 05:20:15 INFO : dir/file1: Copied (new) 2020/05/15 05:20:15 DEBUG : newLeaf: Running delayed rename now 2020/05/15 05:20:15 INFO : newLeaf: Deleted 2020/05/15 05:20:18 INFO : dir/file1: Moved (server side) 2020/05/15 05:20:18 DEBUG : newLeaf: Updating file with newLeaf 0xc0002880e0 === RUN TestFileRename/CacheModeFull 2020/05/15 05:20:18 INFO : mega root 'rclone-test-faboyem1ribuzes8ralepeg9': poll-interval is not supported by this remote 2020/05/15 05:20:18 DEBUG : vfs cache root is "/home/rclone/.cache/rclone/vfs/TestMega/rclone-test-faboyem1ribuzes8ralepeg9" 2020/05/15 05:20:18 DEBUG : Adding path "vfs/forget" to remote control registry 2020/05/15 05:20:18 DEBUG : Adding path "vfs/refresh" to remote control registry 2020/05/15 05:20:18 DEBUG : Adding path "vfs/poll-interval" to remote control registry 2020/05/15 05:20:19 DEBUG : dir/file1: Open: flags=O_RDONLY 2020/05/15 05:20:19 DEBUG : dir/file1: >Open: fd=dir/file1 (rw), err= 2020/05/15 05:20:19 DEBUG : dir/file1: Need to transfer - File not found at Destination 2020/05/15 05:20:20 INFO : dir/file1: Copied (new) 2020/05/15 05:20:20 DEBUG : dir/file1(0xc00200d100): Opening cached copy with flags=O_RDONLY 2020/05/15 05:20:20 DEBUG : dir/file1(0xc00200d100): close: 2020/05/15 05:20:20 DEBUG : dir/file1(0xc00200d100): >close: err= 2020/05/15 05:20:20 INFO : dir/file1: Renamed in cache 2020/05/15 05:20:22 INFO : dir/file1: Moved (server side) 2020/05/15 05:20:22 DEBUG : newLeaf: Updating file with newLeaf 0xc0021d0000 2020/05/15 05:20:22 INFO : newLeaf: Renamed in cache 2020/05/15 05:20:24 INFO : newLeaf: Moved (server side) 2020/05/15 05:20:24 DEBUG : dir/file1: Updating file with dir/file1 0xc0021d0000 2020/05/15 05:20:31 DEBUG : dir/file1: Open: flags=O_WRONLY|O_TRUNC 2020/05/15 05:20:31 DEBUG : dir/file1(0xc000432cc0): Opening cached copy with flags=O_WRONLY|O_TRUNC 2020/05/15 05:20:31 DEBUG : dir/file1: >Open: fd=dir/file1 (rw), err= 2020/05/15 05:20:31 INFO : dir/file1: Renamed in cache 2020/05/15 05:20:31 DEBUG : newLeaf: File is currently open, delaying rename 0xc0021d0000 2020/05/15 05:20:31 DEBUG : newLeaf(0xc000432cc0): close: 2020/05/15 05:20:31 DEBUG : newLeaf: Sizes differ (src 25 vs dst 14) 2020/05/15 05:20:31 INFO : newLeaf: Copied (replaced existing) 2020/05/15 05:20:31 DEBUG : dir/file1: transferred to remote 2020/05/15 05:20:31 DEBUG : newLeaf: Running delayed rename now 2020/05/15 05:20:34 INFO : dir/file1: Moved (server side) 2020/05/15 05:20:34 DEBUG : newLeaf: Updating file with newLeaf 0xc0021d0000 2020/05/15 05:20:34 DEBUG : newLeaf(0xc000432cc0): >close: err= --- FAIL: TestFileRename (42.28s) --- FAIL: TestFileRename/CacheModeOff (24.20s) run.go:176: Remote "mega root 'rclone-test-faboyem1ribuzes8ralepeg9'", Local "Local file system at /tmp/rclone318024101", Modify Window "876000h0m0s" fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Flushing the directory cache fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:298: Flushing the directory cache fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:298: Flushing the directory cache fstest.go:302: Error Trace: fstest.go:302 fstest.go:335 fstest.go:347 file_test.go:279 file_test.go:334 Error: Should be true Test: TestFileRename/CacheModeOff Messages: listing wrong, want newLeaf (14) got file1 (14), newLeaf (14) fstest.go:188: Error Trace: fstest.go:188 fstest.go:305 fstest.go:335 fstest.go:347 file_test.go:279 file_test.go:334 Error: Should be true Test: TestFileRename/CacheModeOff Messages: Unexpected file "file1" fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Flushing the directory cache fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:298: Flushing the directory cache fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:298: Flushing the directory cache fstest.go:302: Error Trace: fstest.go:302 fstest.go:335 fstest.go:347 file_test.go:295 file_test.go:334 Error: Should be true Test: TestFileRename/CacheModeOff Messages: listing wrong, want dir/file1 (14) got dir/file1 (14), dir/file1 (14), newLeaf (14) fstest.go:188: Error Trace: fstest.go:188 fstest.go:305 fstest.go:335 fstest.go:347 file_test.go:295 file_test.go:334 Error: Should be true Test: TestFileRename/CacheModeOff Messages: Unexpected file "newLeaf" fstest.go:188: Error Trace: fstest.go:188 fstest.go:305 fstest.go:335 fstest.go:347 file_test.go:295 file_test.go:334 Error: Should be true Test: TestFileRename/CacheModeOff Messages: Unexpected file "dir/file1" --- FAIL: TestFileRename/CacheModeFull (18.09s) run.go:176: Remote "mega root 'rclone-test-faboyem1ribuzes8ralepeg9'", Local "Local file system at /tmp/rclone318024101", Modify Window "876000h0m0s" fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Flushing the directory cache fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:298: Flushing the directory cache fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:298: Flushing the directory cache fstest.go:302: Error Trace: fstest.go:302 fstest.go:335 fstest.go:347 file_test.go:295 file_test.go:337 Error: Should be true Test: TestFileRename/CacheModeFull Messages: listing wrong, want dir/file1 (14) got dir/file1 (14), dir/file1 (14) fstest.go:188: Error Trace: fstest.go:188 fstest.go:305 fstest.go:335 fstest.go:347 file_test.go:295 file_test.go:337 Error: Should be true Test: TestFileRename/CacheModeFull Messages: Unexpected file "dir/file1" === RUN TestRWFileHandleOpenTests 2020/05/15 05:20:36 INFO : mega root 'rclone-test-faboyem1ribuzes8ralepeg9': poll-interval is not supported by this remote 2020/05/15 05:20:36 DEBUG : vfs cache root is "/home/rclone/.cache/rclone/vfs/TestMega/rclone-test-faboyem1ribuzes8ralepeg9" 2020/05/15 05:20:36 DEBUG : Adding path "vfs/forget" to remote control registry 2020/05/15 05:20:36 DEBUG : Adding path "vfs/refresh" to remote control registry 2020/05/15 05:20:36 DEBUG : Adding path "vfs/poll-interval" to remote control registry 2020/05/15 05:20:36 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=-rw-rw-rw- 2020/05/15 05:20:36 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/05/15 05:20:36 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/05/15 05:20:36 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/05/15 05:20:36 DEBUG : open-test-file(0xc00205f240): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/05/15 05:20:36 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:36 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:36 DEBUG : open-test-file(0xc00205f240): close: 2020/05/15 05:20:36 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/05/15 05:20:36 DEBUG : newLeaf: updateTime: setting atime to 2020-05-15 05:20:31.203952433 +0000 UTC 2020/05/15 05:20:36 DEBUG : dir: Removed empty directory 2020/05/15 05:20:36 INFO : Cleaned the cache: objects 3 (was 2), total size 30 (was 0) 2020/05/15 05:20:38 INFO : open-test-file: Copied (new) 2020/05/15 05:20:38 DEBUG : open-test-file: transferred to remote 2020/05/15 05:20:38 DEBUG : open-test-file(0xc00205f240): >close: err= 2020/05/15 05:20:38 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=-rw-rw-rw- 2020/05/15 05:20:38 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/05/15 05:20:38 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:38 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:38 DEBUG : open-test-file: Sizes identical 2020/05/15 05:20:38 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:20:38 DEBUG : open-test-file(0xc0001f5000): Opened existing cached copy with flags=O_RDONLY 2020/05/15 05:20:38 DEBUG : open-test-file(0xc0001f5000): close: 2020/05/15 05:20:38 DEBUG : open-test-file(0xc0001f5000): >close: err= 2020/05/15 05:20:38 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/05/15 05:20:38 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/05/15 05:20:38 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:38 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:38 DEBUG : open-test-file: Sizes identical 2020/05/15 05:20:38 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:20:38 DEBUG : open-test-file(0xc0001f5080): Opened existing cached copy with flags=O_RDONLY 2020/05/15 05:20:38 DEBUG : open-test-file(0xc0001f5080): close: 2020/05/15 05:20:38 DEBUG : open-test-file(0xc0001f5080): >close: err= 2020/05/15 05:20:41 INFO : open-test-file: Removed from cache 2020/05/15 05:20:41 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_TRUNC, perm=-rw-rw-rw- 2020/05/15 05:20:41 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/05/15 05:20:41 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/05/15 05:20:41 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/05/15 05:20:41 DEBUG : open-test-file(0xc0006d8140): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/05/15 05:20:41 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:41 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:41 DEBUG : open-test-file(0xc0006d8140): close: 2020/05/15 05:20:41 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/05/15 05:20:43 INFO : open-test-file: Copied (new) 2020/05/15 05:20:43 DEBUG : open-test-file: transferred to remote 2020/05/15 05:20:43 DEBUG : open-test-file(0xc0006d8140): >close: err= 2020/05/15 05:20:43 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_TRUNC, perm=-rw-rw-rw- 2020/05/15 05:20:43 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/05/15 05:20:43 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/05/15 05:20:43 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/05/15 05:20:43 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:43 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:43 DEBUG : open-test-file: Sizes identical 2020/05/15 05:20:43 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:20:43 DEBUG : open-test-file(0xc0006d8580): Opened existing cached copy with flags=O_RDONLY 2020/05/15 05:20:43 DEBUG : open-test-file(0xc0006d8580): close: 2020/05/15 05:20:43 DEBUG : open-test-file(0xc0006d8580): >close: err= 2020/05/15 05:20:43 INFO : open-test-file: Removed from cache 2020/05/15 05:20:43 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_SYNC, perm=-rw-rw-rw- 2020/05/15 05:20:43 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/05/15 05:20:43 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/05/15 05:20:43 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/05/15 05:20:43 DEBUG : open-test-file(0xc0001f5d80): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/05/15 05:20:43 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:43 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:43 DEBUG : open-test-file(0xc0001f5d80): close: 2020/05/15 05:20:43 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/05/15 05:20:44 INFO : open-test-file: Copied (new) 2020/05/15 05:20:44 DEBUG : open-test-file: transferred to remote 2020/05/15 05:20:44 DEBUG : open-test-file(0xc0001f5d80): >close: err= 2020/05/15 05:20:44 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_SYNC, perm=-rw-rw-rw- 2020/05/15 05:20:44 DEBUG : open-test-file: Open: flags=O_RDONLY|O_SYNC 2020/05/15 05:20:44 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:44 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:44 DEBUG : open-test-file: Sizes identical 2020/05/15 05:20:44 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:20:44 DEBUG : open-test-file(0xc00205e380): Opened existing cached copy with flags=O_RDONLY|O_SYNC 2020/05/15 05:20:44 DEBUG : open-test-file(0xc00205e380): close: 2020/05/15 05:20:44 DEBUG : open-test-file(0xc00205e380): >close: err= 2020/05/15 05:20:44 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/05/15 05:20:44 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/05/15 05:20:44 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:44 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:44 DEBUG : open-test-file: Sizes identical 2020/05/15 05:20:44 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:20:44 DEBUG : open-test-file(0xc00205e3c0): Opened existing cached copy with flags=O_RDONLY 2020/05/15 05:20:44 DEBUG : open-test-file(0xc00205e3c0): close: 2020/05/15 05:20:44 DEBUG : open-test-file(0xc00205e3c0): >close: err= 2020/05/15 05:20:44 INFO : open-test-file: Removed from cache 2020/05/15 05:20:44 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/05/15 05:20:44 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/05/15 05:20:44 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/05/15 05:20:44 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/05/15 05:20:44 DEBUG : open-test-file(0xc00205e580): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/05/15 05:20:44 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:44 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:44 DEBUG : open-test-file(0xc00205e580): close: 2020/05/15 05:20:44 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/05/15 05:20:51 INFO : open-test-file: Copied (new) 2020/05/15 05:20:51 DEBUG : open-test-file: transferred to remote 2020/05/15 05:20:51 DEBUG : open-test-file(0xc00205e580): >close: err= 2020/05/15 05:20:51 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/05/15 05:20:51 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/05/15 05:20:51 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/05/15 05:20:51 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/05/15 05:20:51 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:51 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:51 DEBUG : open-test-file: Sizes identical 2020/05/15 05:20:51 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:20:51 DEBUG : open-test-file(0xc0006d93c0): Opened existing cached copy with flags=O_RDONLY 2020/05/15 05:20:51 DEBUG : open-test-file(0xc0006d93c0): close: 2020/05/15 05:20:51 DEBUG : open-test-file(0xc0006d93c0): >close: err= 2020/05/15 05:20:51 INFO : open-test-file: Removed from cache 2020/05/15 05:20:51 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_EXCL, perm=-rw-rw-rw- 2020/05/15 05:20:51 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/05/15 05:20:51 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/05/15 05:20:51 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/05/15 05:20:51 DEBUG : open-test-file(0xc00205ebc0): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/05/15 05:20:51 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:51 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:51 DEBUG : open-test-file(0xc00205ebc0): close: 2020/05/15 05:20:51 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/05/15 05:20:52 INFO : open-test-file: Copied (new) 2020/05/15 05:20:52 DEBUG : open-test-file: transferred to remote 2020/05/15 05:20:52 DEBUG : open-test-file(0xc00205ebc0): >close: err= 2020/05/15 05:20:52 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_EXCL, perm=-rw-rw-rw- 2020/05/15 05:20:52 DEBUG : open-test-file: Open: flags=O_RDONLY|O_EXCL 2020/05/15 05:20:52 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:52 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:52 DEBUG : open-test-file: Sizes identical 2020/05/15 05:20:52 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:20:52 DEBUG : open-test-file(0xc00008bdc0): Opened existing cached copy with flags=O_RDONLY|O_EXCL 2020/05/15 05:20:52 DEBUG : open-test-file(0xc00008bdc0): close: 2020/05/15 05:20:52 DEBUG : open-test-file(0xc00008bdc0): >close: err= 2020/05/15 05:20:52 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/05/15 05:20:52 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/05/15 05:20:52 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:52 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:52 DEBUG : open-test-file: Sizes identical 2020/05/15 05:20:52 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:20:52 DEBUG : open-test-file(0xc00008be00): Opened existing cached copy with flags=O_RDONLY 2020/05/15 05:20:52 DEBUG : open-test-file(0xc00008be00): close: 2020/05/15 05:20:52 DEBUG : open-test-file(0xc00008be00): >close: err= 2020/05/15 05:20:52 INFO : open-test-file: Removed from cache 2020/05/15 05:20:52 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_EXCL|O_TRUNC, perm=-rw-rw-rw- 2020/05/15 05:20:52 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/05/15 05:20:52 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/05/15 05:20:52 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/05/15 05:20:52 DEBUG : open-test-file(0xc0006d95c0): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/05/15 05:20:52 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:52 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:52 DEBUG : open-test-file(0xc0006d95c0): close: 2020/05/15 05:20:52 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/05/15 05:20:53 INFO : open-test-file: Copied (new) 2020/05/15 05:20:53 DEBUG : open-test-file: transferred to remote 2020/05/15 05:20:53 DEBUG : open-test-file(0xc0006d95c0): >close: err= 2020/05/15 05:20:53 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_EXCL|O_TRUNC, perm=-rw-rw-rw- 2020/05/15 05:20:53 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/05/15 05:20:53 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/05/15 05:20:53 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/05/15 05:20:53 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:53 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:53 DEBUG : open-test-file: Sizes identical 2020/05/15 05:20:53 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:20:53 DEBUG : open-test-file(0xc00205f5c0): Opened existing cached copy with flags=O_RDONLY 2020/05/15 05:20:53 DEBUG : open-test-file(0xc00205f5c0): close: 2020/05/15 05:20:53 DEBUG : open-test-file(0xc00205f5c0): >close: err= 2020/05/15 05:20:53 INFO : open-test-file: Removed from cache 2020/05/15 05:20:53 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_EXCL|O_SYNC, perm=-rw-rw-rw- 2020/05/15 05:20:53 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/05/15 05:20:53 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/05/15 05:20:53 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/05/15 05:20:53 DEBUG : open-test-file(0xc00205f800): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/05/15 05:20:53 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:53 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:53 DEBUG : open-test-file(0xc00205f800): close: 2020/05/15 05:20:53 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/05/15 05:20:54 INFO : open-test-file: Copied (new) 2020/05/15 05:20:54 DEBUG : open-test-file: transferred to remote 2020/05/15 05:20:54 DEBUG : open-test-file(0xc00205f800): >close: err= 2020/05/15 05:20:54 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_EXCL|O_SYNC, perm=-rw-rw-rw- 2020/05/15 05:20:54 DEBUG : open-test-file: Open: flags=O_RDONLY|O_EXCL|O_SYNC 2020/05/15 05:20:54 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:54 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:54 DEBUG : open-test-file: Sizes identical 2020/05/15 05:20:54 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:20:54 DEBUG : open-test-file(0xc00205fb80): Opened existing cached copy with flags=O_RDONLY|O_EXCL|O_SYNC 2020/05/15 05:20:54 DEBUG : open-test-file(0xc00205fb80): close: 2020/05/15 05:20:54 DEBUG : open-test-file(0xc00205fb80): >close: err= 2020/05/15 05:20:54 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/05/15 05:20:54 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/05/15 05:20:54 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:54 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:54 DEBUG : open-test-file: Sizes identical 2020/05/15 05:20:54 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:20:54 DEBUG : open-test-file(0xc00205fc00): Opened existing cached copy with flags=O_RDONLY 2020/05/15 05:20:54 DEBUG : open-test-file(0xc00205fc00): close: 2020/05/15 05:20:54 DEBUG : open-test-file(0xc00205fc00): >close: err= 2020/05/15 05:20:54 INFO : open-test-file: Removed from cache 2020/05/15 05:20:54 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_EXCL|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/05/15 05:20:54 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/05/15 05:20:54 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/05/15 05:20:54 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/05/15 05:20:54 DEBUG : open-test-file(0xc00200c140): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/05/15 05:20:54 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:54 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:54 DEBUG : open-test-file(0xc00200c140): close: 2020/05/15 05:20:54 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/05/15 05:20:55 INFO : open-test-file: Copied (new) 2020/05/15 05:20:55 DEBUG : open-test-file: transferred to remote 2020/05/15 05:20:55 DEBUG : open-test-file(0xc00200c140): >close: err= 2020/05/15 05:20:55 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_EXCL|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/05/15 05:20:55 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/05/15 05:20:55 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/05/15 05:20:55 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/05/15 05:20:55 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:55 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:55 DEBUG : open-test-file: Sizes identical 2020/05/15 05:20:55 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:20:55 DEBUG : open-test-file(0xc0005da140): Opened existing cached copy with flags=O_RDONLY 2020/05/15 05:20:55 DEBUG : open-test-file(0xc0005da140): close: 2020/05/15 05:20:55 DEBUG : open-test-file(0xc0005da140): >close: err= 2020/05/15 05:20:55 INFO : open-test-file: Removed from cache 2020/05/15 05:20:55 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE, perm=-rw-rw-rw- 2020/05/15 05:20:55 DEBUG : open-test-file: Open: flags=O_RDONLY|O_CREATE 2020/05/15 05:20:55 DEBUG : open-test-file(0xc0005da340): Opening cached copy with flags=O_RDONLY|O_CREATE 2020/05/15 05:20:55 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:55 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:55 DEBUG : open-test-file(0xc0005da340): close: 2020/05/15 05:20:55 DEBUG : open-test-file(0xc0005da340): >close: err= 2020/05/15 05:20:55 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/05/15 05:20:55 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/05/15 05:20:55 DEBUG : open-test-file(0xc0005da380): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/05/15 05:20:55 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:55 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:55 DEBUG : open-test-file(0xc0005da380): close: 2020/05/15 05:20:55 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/05/15 05:20:56 INFO : open-test-file: Copied (new) 2020/05/15 05:20:56 DEBUG : open-test-file: transferred to remote 2020/05/15 05:20:56 DEBUG : open-test-file(0xc0005da380): >close: err= 2020/05/15 05:20:56 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE, perm=-rw-rw-rw- 2020/05/15 05:20:56 DEBUG : open-test-file: Open: flags=O_RDONLY|O_CREATE 2020/05/15 05:20:56 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:56 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:56 DEBUG : open-test-file: Sizes identical 2020/05/15 05:20:56 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:20:56 DEBUG : open-test-file(0xc0005da640): Opened existing cached copy with flags=O_RDONLY|O_CREATE 2020/05/15 05:20:56 DEBUG : open-test-file(0xc0005da640): close: 2020/05/15 05:20:56 DEBUG : open-test-file(0xc0005da640): >close: err= 2020/05/15 05:20:56 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/05/15 05:20:56 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/05/15 05:20:56 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:56 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:56 DEBUG : open-test-file: Sizes identical 2020/05/15 05:20:56 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:20:56 DEBUG : open-test-file(0xc0005da680): Opened existing cached copy with flags=O_RDONLY 2020/05/15 05:20:56 DEBUG : open-test-file(0xc0005da680): close: 2020/05/15 05:20:56 DEBUG : open-test-file(0xc0005da680): >close: err= 2020/05/15 05:20:56 INFO : open-test-file: Removed from cache 2020/05/15 05:20:56 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_TRUNC, perm=-rw-rw-rw- 2020/05/15 05:20:56 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/05/15 05:20:56 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/05/15 05:20:56 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/05/15 05:20:56 DEBUG : open-test-file(0xc00200c680): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/05/15 05:20:56 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:56 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:56 DEBUG : open-test-file(0xc00200c680): close: 2020/05/15 05:20:56 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/05/15 05:20:56 INFO : open-test-file: Copied (new) 2020/05/15 05:20:56 DEBUG : open-test-file: transferred to remote 2020/05/15 05:20:56 DEBUG : open-test-file(0xc00200c680): >close: err= 2020/05/15 05:20:56 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_TRUNC, perm=-rw-rw-rw- 2020/05/15 05:20:56 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/05/15 05:20:56 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/05/15 05:20:56 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/05/15 05:20:56 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:56 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:56 DEBUG : open-test-file: Sizes identical 2020/05/15 05:20:56 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:20:56 DEBUG : open-test-file(0xc0005da7c0): Opened existing cached copy with flags=O_RDONLY 2020/05/15 05:20:56 DEBUG : open-test-file(0xc0005da7c0): close: 2020/05/15 05:20:56 DEBUG : open-test-file(0xc0005da7c0): >close: err= 2020/05/15 05:20:56 INFO : open-test-file: Removed from cache 2020/05/15 05:20:56 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_SYNC, perm=-rw-rw-rw- 2020/05/15 05:20:56 DEBUG : open-test-file: Open: flags=O_RDONLY|O_CREATE|O_SYNC 2020/05/15 05:20:56 DEBUG : open-test-file(0xc000143940): Opening cached copy with flags=O_RDONLY|O_CREATE|O_SYNC 2020/05/15 05:20:56 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:56 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:56 DEBUG : open-test-file(0xc000143940): close: 2020/05/15 05:20:56 DEBUG : open-test-file(0xc000143940): >close: err= 2020/05/15 05:20:56 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/05/15 05:20:56 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/05/15 05:20:56 DEBUG : open-test-file(0xc0001439c0): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/05/15 05:20:56 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:20:56 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:20:56 DEBUG : open-test-file(0xc0001439c0): close: 2020/05/15 05:20:56 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/05/15 05:21:02 INFO : open-test-file: Copied (new) 2020/05/15 05:21:02 DEBUG : open-test-file: transferred to remote 2020/05/15 05:21:02 DEBUG : open-test-file(0xc0001439c0): >close: err= 2020/05/15 05:21:02 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_SYNC, perm=-rw-rw-rw- 2020/05/15 05:21:02 DEBUG : open-test-file: Open: flags=O_RDONLY|O_CREATE|O_SYNC 2020/05/15 05:21:02 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:21:02 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:21:02 DEBUG : open-test-file: Sizes identical 2020/05/15 05:21:02 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:21:02 DEBUG : open-test-file(0xc0006d9e40): Opened existing cached copy with flags=O_RDONLY|O_CREATE|O_SYNC 2020/05/15 05:21:02 DEBUG : open-test-file(0xc0006d9e40): close: 2020/05/15 05:21:02 DEBUG : open-test-file(0xc0006d9e40): >close: err= 2020/05/15 05:21:02 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/05/15 05:21:02 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/05/15 05:21:02 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:21:02 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:21:02 DEBUG : open-test-file: Sizes identical 2020/05/15 05:21:02 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:21:02 DEBUG : open-test-file(0xc0006d9ec0): Opened existing cached copy with flags=O_RDONLY 2020/05/15 05:21:02 DEBUG : open-test-file(0xc0006d9ec0): close: 2020/05/15 05:21:02 DEBUG : open-test-file(0xc0006d9ec0): >close: err= 2020/05/15 05:21:02 INFO : open-test-file: Removed from cache 2020/05/15 05:21:02 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/05/15 05:21:02 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/05/15 05:21:02 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/05/15 05:21:02 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/05/15 05:21:02 DEBUG : open-test-file(0xc0005db380): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/05/15 05:21:02 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:21:02 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:21:02 DEBUG : open-test-file(0xc0005db380): close: 2020/05/15 05:21:02 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/05/15 05:21:02 INFO : open-test-file: Copied (new) 2020/05/15 05:21:02 DEBUG : open-test-file: transferred to remote 2020/05/15 05:21:02 DEBUG : open-test-file(0xc0005db380): >close: err= 2020/05/15 05:21:02 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/05/15 05:21:02 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/05/15 05:21:02 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/05/15 05:21:02 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/05/15 05:21:02 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:21:02 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:21:02 DEBUG : open-test-file: Sizes identical 2020/05/15 05:21:02 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:21:02 DEBUG : open-test-file(0xc0005db780): Opened existing cached copy with flags=O_RDONLY 2020/05/15 05:21:02 DEBUG : open-test-file(0xc0005db780): close: 2020/05/15 05:21:02 DEBUG : open-test-file(0xc0005db780): >close: err= 2020/05/15 05:21:02 INFO : open-test-file: Removed from cache 2020/05/15 05:21:02 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_EXCL, perm=-rw-rw-rw- 2020/05/15 05:21:02 DEBUG : open-test-file: Open: flags=O_RDONLY|O_CREATE|O_EXCL 2020/05/15 05:21:02 DEBUG : open-test-file(0xc000660300): Opening cached copy with flags=O_RDONLY|O_CREATE|O_EXCL 2020/05/15 05:21:02 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:21:02 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:21:02 DEBUG : open-test-file(0xc000660300): close: 2020/05/15 05:21:02 DEBUG : open-test-file(0xc000660300): >close: err= 2020/05/15 05:21:02 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/05/15 05:21:02 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/05/15 05:21:02 DEBUG : open-test-file(0xc000660380): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/05/15 05:21:02 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:21:02 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:21:02 DEBUG : open-test-file(0xc000660380): close: 2020/05/15 05:21:02 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/05/15 05:21:03 INFO : open-test-file: Copied (new) 2020/05/15 05:21:03 DEBUG : open-test-file: transferred to remote 2020/05/15 05:21:03 DEBUG : open-test-file(0xc000660380): >close: err= 2020/05/15 05:21:03 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_EXCL, perm=-rw-rw-rw- 2020/05/15 05:21:03 DEBUG : open-test-file: Open: flags=O_RDONLY|O_CREATE|O_EXCL 2020/05/15 05:21:03 DEBUG : open-test-file: File.openRW failed: file already exists 2020/05/15 05:21:03 DEBUG : open-test-file: >Open: fd=, err=file already exists 2020/05/15 05:21:03 DEBUG : open-test-file: >OpenFile: fd=, err=file already exists 2020/05/15 05:21:03 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/05/15 05:21:03 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/05/15 05:21:03 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:21:03 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:21:03 DEBUG : open-test-file: Sizes identical 2020/05/15 05:21:03 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:21:03 DEBUG : open-test-file(0xc0005dba00): Opened existing cached copy with flags=O_RDONLY 2020/05/15 05:21:03 DEBUG : open-test-file(0xc0005dba00): close: 2020/05/15 05:21:03 DEBUG : open-test-file(0xc0005dba00): >close: err= 2020/05/15 05:21:03 INFO : open-test-file: Removed from cache 2020/05/15 05:21:03 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_EXCL|O_TRUNC, perm=-rw-rw-rw- 2020/05/15 05:21:03 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/05/15 05:21:03 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/05/15 05:21:03 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/05/15 05:21:03 DEBUG : open-test-file(0xc0005dbc40): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/05/15 05:21:03 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:21:03 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:21:03 DEBUG : open-test-file(0xc0005dbc40): close: 2020/05/15 05:21:03 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/05/15 05:21:04 INFO : open-test-file: Copied (new) 2020/05/15 05:21:04 DEBUG : open-test-file: transferred to remote 2020/05/15 05:21:04 DEBUG : open-test-file(0xc0005dbc40): >close: err= 2020/05/15 05:21:04 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_EXCL|O_TRUNC, perm=-rw-rw-rw- 2020/05/15 05:21:04 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/05/15 05:21:04 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/05/15 05:21:04 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/05/15 05:21:04 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:21:04 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:21:04 DEBUG : open-test-file: Sizes identical 2020/05/15 05:21:04 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:21:04 DEBUG : open-test-file(0xc000660b40): Opened existing cached copy with flags=O_RDONLY 2020/05/15 05:21:04 DEBUG : open-test-file(0xc000660b40): close: 2020/05/15 05:21:04 DEBUG : open-test-file(0xc000660b40): >close: err= 2020/05/15 05:21:04 INFO : open-test-file: Removed from cache 2020/05/15 05:21:04 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_EXCL|O_SYNC, perm=-rw-rw-rw- 2020/05/15 05:21:04 DEBUG : open-test-file: Open: flags=O_RDONLY|O_CREATE|O_EXCL|O_SYNC 2020/05/15 05:21:04 DEBUG : open-test-file(0xc000660e00): Opening cached copy with flags=O_RDONLY|O_CREATE|O_EXCL|O_SYNC 2020/05/15 05:21:04 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:21:04 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:21:04 DEBUG : open-test-file(0xc000660e00): close: 2020/05/15 05:21:04 DEBUG : open-test-file(0xc000660e00): >close: err= 2020/05/15 05:21:04 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/05/15 05:21:04 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/05/15 05:21:04 DEBUG : open-test-file(0xc000660e80): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/05/15 05:21:04 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:21:04 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:21:04 DEBUG : open-test-file(0xc000660e80): close: 2020/05/15 05:21:04 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/05/15 05:21:06 INFO : open-test-file: Copied (new) 2020/05/15 05:21:06 DEBUG : open-test-file: transferred to remote 2020/05/15 05:21:06 DEBUG : open-test-file(0xc000660e80): >close: err= 2020/05/15 05:21:06 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_EXCL|O_SYNC, perm=-rw-rw-rw- 2020/05/15 05:21:06 DEBUG : open-test-file: Open: flags=O_RDONLY|O_CREATE|O_EXCL|O_SYNC 2020/05/15 05:21:06 DEBUG : open-test-file: File.openRW failed: file already exists 2020/05/15 05:21:06 DEBUG : open-test-file: >Open: fd=, err=file already exists 2020/05/15 05:21:06 DEBUG : open-test-file: >OpenFile: fd=, err=file already exists 2020/05/15 05:21:06 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/05/15 05:21:06 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/05/15 05:21:06 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:21:06 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:21:06 DEBUG : open-test-file: Sizes identical 2020/05/15 05:21:06 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:21:06 DEBUG : open-test-file(0xc000661100): Opened existing cached copy with flags=O_RDONLY 2020/05/15 05:21:06 DEBUG : open-test-file(0xc000661100): close: 2020/05/15 05:21:06 DEBUG : open-test-file(0xc000661100): >close: err= 2020/05/15 05:21:06 INFO : open-test-file: Removed from cache 2020/05/15 05:21:06 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_EXCL|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/05/15 05:21:06 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/05/15 05:21:06 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/05/15 05:21:06 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/05/15 05:21:06 DEBUG : open-test-file(0xc000688cc0): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/05/15 05:21:06 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:21:06 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:21:06 DEBUG : open-test-file(0xc000688cc0): close: 2020/05/15 05:21:06 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/05/15 05:21:07 INFO : open-test-file: Copied (new) 2020/05/15 05:21:07 DEBUG : open-test-file: transferred to remote 2020/05/15 05:21:07 DEBUG : open-test-file(0xc000688cc0): >close: err= 2020/05/15 05:21:07 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_EXCL|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/05/15 05:21:07 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/05/15 05:21:07 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/05/15 05:21:07 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/05/15 05:21:07 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:21:07 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:21:07 DEBUG : open-test-file: Sizes identical 2020/05/15 05:21:07 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:21:07 DEBUG : open-test-file(0xc000756480): Opened existing cached copy with flags=O_RDONLY 2020/05/15 05:21:07 DEBUG : open-test-file(0xc000756480): close: 2020/05/15 05:21:07 DEBUG : open-test-file(0xc000756480): >close: err= 2020/05/15 05:21:07 INFO : open-test-file: Removed from cache 2020/05/15 05:21:07 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND, perm=-rw-rw-rw- 2020/05/15 05:21:07 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/05/15 05:21:07 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/05/15 05:21:07 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/05/15 05:21:07 DEBUG : open-test-file(0xc000688f40): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/05/15 05:21:07 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:21:07 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:21:07 DEBUG : open-test-file(0xc000688f40): close: 2020/05/15 05:21:07 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/05/15 05:21:07 INFO : open-test-file: Copied (new) 2020/05/15 05:21:07 DEBUG : open-test-file: transferred to remote 2020/05/15 05:21:07 DEBUG : open-test-file(0xc000688f40): >close: err= 2020/05/15 05:21:07 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND, perm=-rw-rw-rw- 2020/05/15 05:21:07 DEBUG : open-test-file: Open: flags=O_RDONLY|O_APPEND 2020/05/15 05:21:07 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:21:07 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:21:07 DEBUG : open-test-file: Sizes identical 2020/05/15 05:21:07 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:21:07 DEBUG : open-test-file(0xc000756a00): Opened existing cached copy with flags=O_RDONLY|O_APPEND 2020/05/15 05:21:07 DEBUG : open-test-file(0xc000756a00): close: 2020/05/15 05:21:07 DEBUG : open-test-file(0xc000756a00): >close: err= 2020/05/15 05:21:07 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/05/15 05:21:07 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/05/15 05:21:07 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:21:07 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:21:07 DEBUG : open-test-file: Sizes identical 2020/05/15 05:21:07 DEBUG : open-test-file: Unchanged skipping 2020/05/15 05:21:07 DEBUG : open-test-file(0xc000756a40): Opened existing cached copy with flags=O_RDONLY 2020/05/15 05:21:07 DEBUG : open-test-file(0xc000756a40): close: 2020/05/15 05:21:07 DEBUG : open-test-file(0xc000756a40): >close: err= 2020/05/15 05:21:07 INFO : open-test-file: Removed from cache 2020/05/15 05:21:07 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_TRUNC, perm=-rw-rw-rw- 2020/05/15 05:21:07 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/05/15 05:21:07 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/05/15 05:21:07 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/05/15 05:21:07 DEBUG : open-test-file(0xc00200cdc0): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/05/15 05:21:07 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/05/15 05:21:07 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/05/15 05:21:07 DEBUG : open-test-file(0xc00200cdc0): close: 2020/05/15 05:21:07 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/05/15 05:21:08 ERROR : open-test-file: Failed to copy: failed to finish upload: Invalid arguments 2020/05/15 05:21:08 ERROR : open-test-file(0xc00200cdc0): failed to transfer file from cache to remote: failed to finish upload: Invalid arguments 2020/05/15 05:21:08 DEBUG : open-test-file(0xc00200cdc0): >close: err=failed to transfer file from cache to remote: failed to finish upload: Invalid arguments 2020/05/15 05:21:08 DEBUG : cache cleaner exiting --- FAIL: TestRWFileHandleOpenTests (31.23s) run.go:176: Remote "mega root 'rclone-test-faboyem1ribuzes8ralepeg9'", Local "Local file system at /tmp/rclone318024101", Modify Window "876000h0m0s" read_write_test.go:618: Error Trace: read_write_test.go:618 read_write_test.go:671 Error: Received unexpected error: failed to finish upload: Invalid arguments failed to transfer file from cache to remote github.com/rclone/rclone/vfs/vfscache.(*Cache).Store /home/rclone/go/src/github.com/rclone/rclone/vfs/vfscache/vfscache.go:592 github.com/rclone/rclone/vfs.(*RWFileHandle).flushWrites /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write.go:265 github.com/rclone/rclone/vfs.(*RWFileHandle).close /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write.go:300 github.com/rclone/rclone/vfs.(*RWFileHandle).Close /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write.go:307 github.com/rclone/rclone/vfs.testRWFileHandleOpenTest /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write_test.go:617 github.com/rclone/rclone/vfs.TestRWFileHandleOpenTests /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write_test.go:671 testing.tRunner /usr/local/go/src/testing/testing.go:909 runtime.goexit /usr/local/go/src/runtime/asm_amd64.s:1357 Test: TestRWFileHandleOpenTests Messages: os.O_RDONLY|os.O_APPEND|os.O_TRUNC FAIL 2020/05/15 05:21:08 DEBUG : mega root 'rclone-test-faboyem1ribuzes8ralepeg9': Purge remote "./vfs.test -test.v -test.timeout 1h0m0s -remote TestMega: -verbose -test.run '^(TestFileRename|TestRWFileHandleOpenTests)$/^(CacheModeFull|CacheModeOff)$'" - Finished ERROR in 1m18.782645958s (try 4/5): exit status 1: Failed [TestFileRename/CacheModeOff TestFileRename/CacheModeFull TestRWFileHandleOpenTests]