"./vfs.test -test.v -test.timeout 30m0s -remote TestOneDrive: -verbose -test.run '^TestRWFileHandleOpenTests$'" - Starting (try 4/5) === RUN TestRWFileHandleOpenTests 2020/01/19 06:02:34 INFO : One drive root 'rclone-test-jefitaz6luwiyuk6lolehom0': poll-interval is not supported by this remote 2020/01/19 06:02:34 DEBUG : vfs cache root is "/home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-jefitaz6luwiyuk6lolehom0" 2020/01/19 06:02:34 DEBUG : Adding path "vfs/forget" to remote control registry 2020/01/19 06:02:34 DEBUG : Adding path "vfs/refresh" to remote control registry 2020/01/19 06:02:34 DEBUG : Adding path "vfs/poll-interval" to remote control registry 2020/01/19 06:02:34 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=-rw-rw-rw- 2020/01/19 06:02:34 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:02:34 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:34 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:34 DEBUG : open-test-file(0xc000080b80): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:34 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:34 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:34 DEBUG : open-test-file(0xc000080b80): close: 2020/01/19 06:02:34 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:35 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:36 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:36 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:36 INFO : open-test-file: Copied (new) 2020/01/19 06:02:36 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:36 DEBUG : open-test-file(0xc000080b80): >close: err= 2020/01/19 06:02:36 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=-rw-rw-rw- 2020/01/19 06:02:36 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:36 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:36 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:36 DEBUG : open-test-file: Size and modification time the same (differ by 612.479506ms, within tolerance 1s) 2020/01/19 06:02:36 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:36 DEBUG : open-test-file(0xc000126340): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:36 DEBUG : open-test-file(0xc000126340): close: 2020/01/19 06:02:36 DEBUG : open-test-file(0xc000126340): >close: err= 2020/01/19 06:02:36 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:36 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:36 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:36 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:36 DEBUG : open-test-file: Size and modification time the same (differ by 612.479506ms, within tolerance 1s) 2020/01/19 06:02:36 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:36 DEBUG : open-test-file(0xc000126380): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:36 DEBUG : open-test-file(0xc000126380): close: 2020/01/19 06:02:36 DEBUG : open-test-file(0xc000126380): >close: err= 2020/01/19 06:02:37 INFO : open-test-file: Removed from cache 2020/01/19 06:02:37 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:37 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:37 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:37 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:37 DEBUG : open-test-file(0xc000126400): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:37 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:37 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:37 DEBUG : open-test-file(0xc000126400): close: 2020/01/19 06:02:37 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:37 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:37 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:37 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:37 INFO : open-test-file: Copied (new) 2020/01/19 06:02:37 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:37 DEBUG : open-test-file(0xc000126400): >close: err= 2020/01/19 06:02:37 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:37 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:37 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:37 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:37 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:37 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:37 DEBUG : open-test-file: Size and modification time the same (differ by 120.517786ms, within tolerance 1s) 2020/01/19 06:02:37 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:37 DEBUG : open-test-file(0xc000126880): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:37 DEBUG : open-test-file(0xc000126880): close: 2020/01/19 06:02:37 DEBUG : open-test-file(0xc000126880): >close: err= 2020/01/19 06:02:38 INFO : open-test-file: Removed from cache 2020/01/19 06:02:38 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:02:38 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:02:38 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:38 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:38 DEBUG : open-test-file(0xc000170a80): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:38 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:38 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:38 DEBUG : open-test-file(0xc000170a80): close: 2020/01/19 06:02:38 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:38 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:38 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:38 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:38 INFO : open-test-file: Copied (new) 2020/01/19 06:02:38 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:38 DEBUG : open-test-file(0xc000170a80): >close: err= 2020/01/19 06:02:38 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:02:38 DEBUG : open-test-file: Open: flags=O_RDONLY|O_SYNC 2020/01/19 06:02:38 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:38 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:38 DEBUG : open-test-file: Size and modification time the same (differ by 20.531523ms, within tolerance 1s) 2020/01/19 06:02:38 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:38 DEBUG : open-test-file(0xc000170e80): Opened existing cached copy with flags=O_RDONLY|O_SYNC 2020/01/19 06:02:38 DEBUG : open-test-file(0xc000170e80): close: 2020/01/19 06:02:38 DEBUG : open-test-file(0xc000170e80): >close: err= 2020/01/19 06:02:38 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:38 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:38 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:38 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:38 DEBUG : open-test-file: Size and modification time the same (differ by 20.531523ms, within tolerance 1s) 2020/01/19 06:02:38 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:38 DEBUG : open-test-file(0xc000170ec0): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:38 DEBUG : open-test-file(0xc000170ec0): close: 2020/01/19 06:02:38 DEBUG : open-test-file(0xc000170ec0): >close: err= 2020/01/19 06:02:38 INFO : open-test-file: Removed from cache 2020/01/19 06:02:38 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:38 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:38 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:38 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:38 DEBUG : open-test-file(0xc000126b00): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:38 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:38 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:38 DEBUG : open-test-file(0xc000126b00): close: 2020/01/19 06:02:38 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:38 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:39 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:42 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:42 INFO : open-test-file: Copied (new) 2020/01/19 06:02:42 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:42 DEBUG : open-test-file(0xc000126b00): >close: err= 2020/01/19 06:02:42 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:42 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:42 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:42 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:42 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:42 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:42 DEBUG : open-test-file: Size and modification time the same (differ by 936.545504ms, within tolerance 1s) 2020/01/19 06:02:42 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:42 DEBUG : open-test-file(0xc000126dc0): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:42 DEBUG : open-test-file(0xc000126dc0): close: 2020/01/19 06:02:42 DEBUG : open-test-file(0xc000126dc0): >close: err= 2020/01/19 06:02:42 INFO : open-test-file: Removed from cache 2020/01/19 06:02:42 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_EXCL, perm=-rw-rw-rw- 2020/01/19 06:02:42 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:02:42 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:42 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:42 DEBUG : open-test-file(0xc000126e40): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:42 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:42 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:42 DEBUG : open-test-file(0xc000126e40): close: 2020/01/19 06:02:42 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:42 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:43 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:43 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:43 INFO : open-test-file: Copied (new) 2020/01/19 06:02:43 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:43 DEBUG : open-test-file(0xc000126e40): >close: err= 2020/01/19 06:02:43 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_EXCL, perm=-rw-rw-rw- 2020/01/19 06:02:43 DEBUG : open-test-file: Open: flags=O_RDONLY|O_EXCL 2020/01/19 06:02:43 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:43 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:43 DEBUG : open-test-file: Size and modification time the same (differ by 880.605704ms, within tolerance 1s) 2020/01/19 06:02:43 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:43 DEBUG : open-test-file(0xc0001715c0): Opened existing cached copy with flags=O_RDONLY|O_EXCL 2020/01/19 06:02:43 DEBUG : open-test-file(0xc0001715c0): close: 2020/01/19 06:02:43 DEBUG : open-test-file(0xc0001715c0): >close: err= 2020/01/19 06:02:43 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:43 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:43 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:43 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:43 DEBUG : open-test-file: Size and modification time the same (differ by 880.605704ms, within tolerance 1s) 2020/01/19 06:02:43 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:43 DEBUG : open-test-file(0xc000171640): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:43 DEBUG : open-test-file(0xc000171640): close: 2020/01/19 06:02:43 DEBUG : open-test-file(0xc000171640): >close: err= 2020/01/19 06:02:43 INFO : open-test-file: Removed from cache 2020/01/19 06:02:43 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_EXCL|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:43 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:43 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:43 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:43 DEBUG : open-test-file(0xc000362500): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:43 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:43 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:43 DEBUG : open-test-file(0xc000362500): close: 2020/01/19 06:02:43 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:43 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:44 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:44 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:44 INFO : open-test-file: Copied (new) 2020/01/19 06:02:44 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:44 DEBUG : open-test-file(0xc000362500): >close: err= 2020/01/19 06:02:44 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_EXCL|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:44 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:44 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:44 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:44 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:44 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:44 DEBUG : open-test-file: Size and modification time the same (differ by 840.620356ms, within tolerance 1s) 2020/01/19 06:02:44 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:44 DEBUG : open-test-file(0xc000362e00): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:44 DEBUG : open-test-file(0xc000362e00): close: 2020/01/19 06:02:44 DEBUG : open-test-file(0xc000362e00): >close: err= 2020/01/19 06:02:45 INFO : open-test-file: Removed from cache 2020/01/19 06:02:45 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_EXCL|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:02:45 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:02:45 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:45 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:45 DEBUG : open-test-file(0xc000363640): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:45 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:45 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:45 DEBUG : open-test-file(0xc000363640): close: 2020/01/19 06:02:45 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:45 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:45 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:45 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:45 INFO : open-test-file: Copied (new) 2020/01/19 06:02:45 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:45 DEBUG : open-test-file(0xc000363640): >close: err= 2020/01/19 06:02:45 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_EXCL|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:02:45 DEBUG : open-test-file: Open: flags=O_RDONLY|O_EXCL|O_SYNC 2020/01/19 06:02:45 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:45 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:45 DEBUG : open-test-file: Size and modification time the same (differ by 56.638915ms, within tolerance 1s) 2020/01/19 06:02:45 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:45 DEBUG : open-test-file(0xc0003639c0): Opened existing cached copy with flags=O_RDONLY|O_EXCL|O_SYNC 2020/01/19 06:02:45 DEBUG : open-test-file(0xc0003639c0): close: 2020/01/19 06:02:45 DEBUG : open-test-file(0xc0003639c0): >close: err= 2020/01/19 06:02:45 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:45 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:45 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:45 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:45 DEBUG : open-test-file: Size and modification time the same (differ by 56.638915ms, within tolerance 1s) 2020/01/19 06:02:45 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:45 DEBUG : open-test-file(0xc000363a40): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:45 DEBUG : open-test-file(0xc000363a40): close: 2020/01/19 06:02:45 DEBUG : open-test-file(0xc000363a40): >close: err= 2020/01/19 06:02:45 INFO : open-test-file: Removed from cache 2020/01/19 06:02:45 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_EXCL|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:45 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:45 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:45 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:45 DEBUG : open-test-file(0xc0001272c0): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:45 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:45 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:45 DEBUG : open-test-file(0xc0001272c0): close: 2020/01/19 06:02:45 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:45 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:46 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:46 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:46 INFO : open-test-file: Copied (new) 2020/01/19 06:02:46 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:46 DEBUG : open-test-file(0xc0001272c0): >close: err= 2020/01/19 06:02:46 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_EXCL|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:46 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:46 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:46 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:46 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:46 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:46 DEBUG : open-test-file: Size and modification time the same (differ by 964.652775ms, within tolerance 1s) 2020/01/19 06:02:46 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:46 DEBUG : open-test-file(0xc000363dc0): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:46 DEBUG : open-test-file(0xc000363dc0): close: 2020/01/19 06:02:46 DEBUG : open-test-file(0xc000363dc0): >close: err= 2020/01/19 06:02:46 INFO : open-test-file: Removed from cache 2020/01/19 06:02:46 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE, perm=-rw-rw-rw- 2020/01/19 06:02:46 DEBUG : open-test-file: Open: flags=O_RDONLY|O_CREATE 2020/01/19 06:02:46 DEBUG : open-test-file(0xc000127580): Opening cached copy with flags=O_RDONLY|O_CREATE 2020/01/19 06:02:46 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:46 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:46 DEBUG : open-test-file(0xc000127580): close: 2020/01/19 06:02:46 DEBUG : open-test-file(0xc000127580): >close: err= 2020/01/19 06:02:46 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:46 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:46 DEBUG : open-test-file(0xc0001275c0): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:46 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:46 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:46 DEBUG : open-test-file(0xc0001275c0): close: 2020/01/19 06:02:46 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:46 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:47 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:47 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:47 INFO : open-test-file: Copied (new) 2020/01/19 06:02:47 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:47 DEBUG : open-test-file(0xc0001275c0): >close: err= 2020/01/19 06:02:47 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE, perm=-rw-rw-rw- 2020/01/19 06:02:47 DEBUG : open-test-file: Open: flags=O_RDONLY|O_CREATE 2020/01/19 06:02:47 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:47 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:47 DEBUG : open-test-file: Size and modification time the same (differ by 844.666206ms, within tolerance 1s) 2020/01/19 06:02:47 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:47 DEBUG : open-test-file(0xc000127a80): Opened existing cached copy with flags=O_RDONLY|O_CREATE 2020/01/19 06:02:47 DEBUG : open-test-file(0xc000127a80): close: 2020/01/19 06:02:47 DEBUG : open-test-file(0xc000127a80): >close: err= 2020/01/19 06:02:47 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:47 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:47 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:47 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:47 DEBUG : open-test-file: Size and modification time the same (differ by 844.666206ms, within tolerance 1s) 2020/01/19 06:02:47 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:47 DEBUG : open-test-file(0xc000127ac0): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:47 DEBUG : open-test-file(0xc000127ac0): close: 2020/01/19 06:02:47 DEBUG : open-test-file(0xc000127ac0): >close: err= 2020/01/19 06:02:47 INFO : open-test-file: Removed from cache 2020/01/19 06:02:47 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:47 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:47 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:47 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:47 DEBUG : open-test-file(0xc00047e280): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:47 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:47 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:47 DEBUG : open-test-file(0xc00047e280): close: 2020/01/19 06:02:47 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:47 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:48 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:48 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:48 INFO : open-test-file: Copied (new) 2020/01/19 06:02:48 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:48 DEBUG : open-test-file(0xc00047e280): >close: err= 2020/01/19 06:02:48 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:48 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:48 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:48 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:48 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:48 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:48 DEBUG : open-test-file: Size and modification time the same (differ by 716.679516ms, within tolerance 1s) 2020/01/19 06:02:48 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:48 DEBUG : open-test-file(0xc000126140): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:48 DEBUG : open-test-file(0xc000126140): close: 2020/01/19 06:02:48 DEBUG : open-test-file(0xc000126140): >close: err= 2020/01/19 06:02:48 INFO : open-test-file: Removed from cache 2020/01/19 06:02:48 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:02:48 DEBUG : open-test-file: Open: flags=O_RDONLY|O_CREATE|O_SYNC 2020/01/19 06:02:48 DEBUG : open-test-file(0xc000362340): Opening cached copy with flags=O_RDONLY|O_CREATE|O_SYNC 2020/01/19 06:02:48 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:48 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:48 DEBUG : open-test-file(0xc000362340): close: 2020/01/19 06:02:48 DEBUG : open-test-file(0xc000362340): >close: err= 2020/01/19 06:02:48 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:48 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:48 DEBUG : open-test-file(0xc0003623c0): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:48 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:48 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:48 DEBUG : open-test-file(0xc0003623c0): close: 2020/01/19 06:02:48 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:48 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:49 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:49 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:49 INFO : open-test-file: Copied (new) 2020/01/19 06:02:49 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:49 DEBUG : open-test-file(0xc0003623c0): >close: err= 2020/01/19 06:02:49 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:02:49 DEBUG : open-test-file: Open: flags=O_RDONLY|O_CREATE|O_SYNC 2020/01/19 06:02:49 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:49 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:49 DEBUG : open-test-file: Size and modification time the same (differ by 696.694474ms, within tolerance 1s) 2020/01/19 06:02:49 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:49 DEBUG : open-test-file(0xc000362d80): Opened existing cached copy with flags=O_RDONLY|O_CREATE|O_SYNC 2020/01/19 06:02:49 DEBUG : open-test-file(0xc000362d80): close: 2020/01/19 06:02:49 DEBUG : open-test-file(0xc000362d80): >close: err= 2020/01/19 06:02:49 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:49 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:49 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:49 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:49 DEBUG : open-test-file: Size and modification time the same (differ by 696.694474ms, within tolerance 1s) 2020/01/19 06:02:49 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:49 DEBUG : open-test-file(0xc000363000): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:49 DEBUG : open-test-file(0xc000363000): close: 2020/01/19 06:02:49 DEBUG : open-test-file(0xc000363000): >close: err= 2020/01/19 06:02:49 INFO : open-test-file: Removed from cache 2020/01/19 06:02:49 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:49 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:49 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:49 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:49 DEBUG : open-test-file(0xc0001261c0): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:49 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:49 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:49 DEBUG : open-test-file(0xc0001261c0): close: 2020/01/19 06:02:49 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:49 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:50 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:50 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:50 INFO : open-test-file: Copied (new) 2020/01/19 06:02:50 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:50 DEBUG : open-test-file(0xc0001261c0): >close: err= 2020/01/19 06:02:50 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:50 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:50 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:50 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:50 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:50 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:50 DEBUG : open-test-file: Size and modification time the same (differ by 672.709371ms, within tolerance 1s) 2020/01/19 06:02:50 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:50 DEBUG : open-test-file(0xc0001266c0): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:50 DEBUG : open-test-file(0xc0001266c0): close: 2020/01/19 06:02:50 DEBUG : open-test-file(0xc0001266c0): >close: err= 2020/01/19 06:02:50 INFO : open-test-file: Removed from cache 2020/01/19 06:02:50 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_EXCL, perm=-rw-rw-rw- 2020/01/19 06:02:50 DEBUG : open-test-file: Open: flags=O_RDONLY|O_CREATE|O_EXCL 2020/01/19 06:02:50 DEBUG : open-test-file(0xc000126780): Opening cached copy with flags=O_RDONLY|O_CREATE|O_EXCL 2020/01/19 06:02:50 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:50 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:50 DEBUG : open-test-file(0xc000126780): close: 2020/01/19 06:02:50 DEBUG : open-test-file(0xc000126780): >close: err= 2020/01/19 06:02:50 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:50 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:50 DEBUG : open-test-file(0xc000126800): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:50 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:50 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:50 DEBUG : open-test-file(0xc000126800): close: 2020/01/19 06:02:50 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:50 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:50 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:51 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:51 INFO : open-test-file: Copied (new) 2020/01/19 06:02:51 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:51 DEBUG : open-test-file(0xc000126800): >close: err= 2020/01/19 06:02:51 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_EXCL, perm=-rw-rw-rw- 2020/01/19 06:02:51 DEBUG : open-test-file: Open: flags=O_RDONLY|O_CREATE|O_EXCL 2020/01/19 06:02:51 ERROR : open-test-file: File.openRW failed: file already exists 2020/01/19 06:02:51 DEBUG : open-test-file: >Open: fd=, err=file already exists 2020/01/19 06:02:51 DEBUG : open-test-file: >OpenFile: fd=, err=file already exists 2020/01/19 06:02:51 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:51 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:51 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:51 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:51 DEBUG : open-test-file: Size and modification time the same (differ by 604.723596ms, within tolerance 1s) 2020/01/19 06:02:51 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:51 DEBUG : open-test-file(0xc000170e80): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:51 DEBUG : open-test-file(0xc000170e80): close: 2020/01/19 06:02:51 DEBUG : open-test-file(0xc000170e80): >close: err= 2020/01/19 06:02:51 INFO : open-test-file: Removed from cache 2020/01/19 06:02:51 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_EXCL|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:51 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:51 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:51 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:51 DEBUG : open-test-file(0xc000171280): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:51 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:51 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:51 DEBUG : open-test-file(0xc000171280): close: 2020/01/19 06:02:51 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:51 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:51 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:52 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:52 INFO : open-test-file: Copied (new) 2020/01/19 06:02:52 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:52 DEBUG : open-test-file(0xc000171280): >close: err= 2020/01/19 06:02:52 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_EXCL|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:52 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:52 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:52 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:52 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:52 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:52 DEBUG : open-test-file: Size and modification time the same (differ by 488.737089ms, within tolerance 1s) 2020/01/19 06:02:52 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:52 DEBUG : open-test-file(0xc000126980): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:52 DEBUG : open-test-file(0xc000126980): close: 2020/01/19 06:02:52 DEBUG : open-test-file(0xc000126980): >close: err= 2020/01/19 06:02:52 INFO : open-test-file: Removed from cache 2020/01/19 06:02:52 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_EXCL|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:02:52 DEBUG : open-test-file: Open: flags=O_RDONLY|O_CREATE|O_EXCL|O_SYNC 2020/01/19 06:02:52 DEBUG : open-test-file(0xc000171f00): Opening cached copy with flags=O_RDONLY|O_CREATE|O_EXCL|O_SYNC 2020/01/19 06:02:52 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:52 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:52 DEBUG : open-test-file(0xc000171f00): close: 2020/01/19 06:02:52 DEBUG : open-test-file(0xc000171f00): >close: err= 2020/01/19 06:02:52 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:52 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:52 DEBUG : open-test-file(0xc000171fc0): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:52 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:52 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:52 DEBUG : open-test-file(0xc000171fc0): close: 2020/01/19 06:02:52 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:52 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:52 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:52 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:52 INFO : open-test-file: Copied (new) 2020/01/19 06:02:52 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:52 DEBUG : open-test-file(0xc000171fc0): >close: err= 2020/01/19 06:02:52 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_EXCL|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:02:52 DEBUG : open-test-file: Open: flags=O_RDONLY|O_CREATE|O_EXCL|O_SYNC 2020/01/19 06:02:52 ERROR : open-test-file: File.openRW failed: file already exists 2020/01/19 06:02:52 DEBUG : open-test-file: >Open: fd=, err=file already exists 2020/01/19 06:02:52 DEBUG : open-test-file: >OpenFile: fd=, err=file already exists 2020/01/19 06:02:52 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:52 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:52 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:52 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:52 DEBUG : open-test-file: Size and modification time the same (differ by 384.750765ms, within tolerance 1s) 2020/01/19 06:02:52 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:52 DEBUG : open-test-file(0xc000126e80): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:52 DEBUG : open-test-file(0xc000126e80): close: 2020/01/19 06:02:52 DEBUG : open-test-file(0xc000126e80): >close: err= 2020/01/19 06:02:53 INFO : open-test-file: Removed from cache 2020/01/19 06:02:53 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_EXCL|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:53 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:53 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:53 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:53 DEBUG : open-test-file(0xc000126f40): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:53 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:53 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:53 DEBUG : open-test-file(0xc000126f40): close: 2020/01/19 06:02:53 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:53 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:53 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:54 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:54 INFO : open-test-file: Copied (new) 2020/01/19 06:02:54 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:54 DEBUG : open-test-file(0xc000126f40): >close: err= 2020/01/19 06:02:54 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_CREATE|O_EXCL|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:54 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:54 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:54 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:54 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:54 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:54 DEBUG : open-test-file: Size and modification time the same (differ by 596.769264ms, within tolerance 1s) 2020/01/19 06:02:54 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:54 DEBUG : open-test-file(0xc000080300): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:54 DEBUG : open-test-file(0xc000080300): close: 2020/01/19 06:02:54 DEBUG : open-test-file(0xc000080300): >close: err= 2020/01/19 06:02:54 INFO : open-test-file: Removed from cache 2020/01/19 06:02:54 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND, perm=-rw-rw-rw- 2020/01/19 06:02:54 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:02:54 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:54 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:54 DEBUG : open-test-file(0xc000127040): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:54 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:54 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:54 DEBUG : open-test-file(0xc000127040): close: 2020/01/19 06:02:54 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:54 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:54 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:55 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:55 INFO : open-test-file: Copied (new) 2020/01/19 06:02:55 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:55 DEBUG : open-test-file(0xc000127040): >close: err= 2020/01/19 06:02:55 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND, perm=-rw-rw-rw- 2020/01/19 06:02:55 DEBUG : open-test-file: Open: flags=O_RDONLY|O_APPEND 2020/01/19 06:02:55 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:55 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:55 DEBUG : open-test-file: Size and modification time the same (differ by 496.783002ms, within tolerance 1s) 2020/01/19 06:02:55 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:55 DEBUG : open-test-file(0xc000127500): Opened existing cached copy with flags=O_RDONLY|O_APPEND 2020/01/19 06:02:55 DEBUG : open-test-file(0xc000127500): close: 2020/01/19 06:02:55 DEBUG : open-test-file(0xc000127500): >close: err= 2020/01/19 06:02:55 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:55 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:55 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:55 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:55 DEBUG : open-test-file: Size and modification time the same (differ by 496.783002ms, within tolerance 1s) 2020/01/19 06:02:55 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:55 DEBUG : open-test-file(0xc000127540): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:55 DEBUG : open-test-file(0xc000127540): close: 2020/01/19 06:02:55 DEBUG : open-test-file(0xc000127540): >close: err= 2020/01/19 06:02:55 INFO : open-test-file: Removed from cache 2020/01/19 06:02:55 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:55 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:55 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:55 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:55 DEBUG : open-test-file(0xc0001275c0): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:55 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:55 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:55 DEBUG : open-test-file(0xc0001275c0): close: 2020/01/19 06:02:55 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:55 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:55 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:55 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:55 INFO : open-test-file: Copied (new) 2020/01/19 06:02:55 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:55 DEBUG : open-test-file(0xc0001275c0): >close: err= 2020/01/19 06:02:55 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:55 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:55 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:55 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:55 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:55 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:55 DEBUG : open-test-file: Size and modification time the same (differ by 356.796128ms, within tolerance 1s) 2020/01/19 06:02:55 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:55 DEBUG : open-test-file(0xc000127ac0): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:55 DEBUG : open-test-file(0xc000127ac0): close: 2020/01/19 06:02:55 DEBUG : open-test-file(0xc000127ac0): >close: err= 2020/01/19 06:02:56 INFO : open-test-file: Removed from cache 2020/01/19 06:02:56 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:02:56 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:02:56 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:56 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:56 DEBUG : open-test-file(0xc000127c40): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:56 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:56 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:56 DEBUG : open-test-file(0xc000127c40): close: 2020/01/19 06:02:56 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:56 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:56 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:56 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:56 INFO : open-test-file: Copied (new) 2020/01/19 06:02:56 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:56 DEBUG : open-test-file(0xc000127c40): >close: err= 2020/01/19 06:02:56 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:02:56 DEBUG : open-test-file: Open: flags=O_RDONLY|O_APPEND|O_SYNC 2020/01/19 06:02:56 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:56 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:56 DEBUG : open-test-file: Size and modification time the same (differ by 252.809805ms, within tolerance 1s) 2020/01/19 06:02:56 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:56 DEBUG : open-test-file(0xc000127e00): Opened existing cached copy with flags=O_RDONLY|O_APPEND|O_SYNC 2020/01/19 06:02:56 DEBUG : open-test-file(0xc000127e00): close: 2020/01/19 06:02:56 DEBUG : open-test-file(0xc000127e00): >close: err= 2020/01/19 06:02:56 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:56 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:56 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:56 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:56 DEBUG : open-test-file: Size and modification time the same (differ by 252.809805ms, within tolerance 1s) 2020/01/19 06:02:56 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:56 DEBUG : open-test-file(0xc000127e80): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:56 DEBUG : open-test-file(0xc000127e80): close: 2020/01/19 06:02:56 DEBUG : open-test-file(0xc000127e80): >close: err= 2020/01/19 06:02:57 INFO : open-test-file: Removed from cache 2020/01/19 06:02:57 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:57 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:57 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:57 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:57 DEBUG : open-test-file(0xc000127f40): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:57 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:57 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:57 DEBUG : open-test-file(0xc000127f40): close: 2020/01/19 06:02:57 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:57 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:57 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:57 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:57 INFO : open-test-file: Copied (new) 2020/01/19 06:02:57 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:57 DEBUG : open-test-file(0xc000127f40): >close: err= 2020/01/19 06:02:57 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:57 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:57 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:57 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:57 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:57 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:57 DEBUG : open-test-file: Size and modification time the same (differ by 128.823175ms, within tolerance 1s) 2020/01/19 06:02:57 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:57 DEBUG : open-test-file(0xc0005ec2c0): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:57 DEBUG : open-test-file(0xc0005ec2c0): close: 2020/01/19 06:02:57 DEBUG : open-test-file(0xc0005ec2c0): >close: err= 2020/01/19 06:02:58 INFO : open-test-file: Removed from cache 2020/01/19 06:02:58 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_EXCL, perm=-rw-rw-rw- 2020/01/19 06:02:58 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:02:58 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:58 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:58 DEBUG : open-test-file(0xc00047e800): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:58 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:58 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:58 DEBUG : open-test-file(0xc00047e800): close: 2020/01/19 06:02:58 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:58 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:58 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:58 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:58 INFO : open-test-file: Copied (new) 2020/01/19 06:02:58 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:58 DEBUG : open-test-file(0xc00047e800): >close: err= 2020/01/19 06:02:58 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_EXCL, perm=-rw-rw-rw- 2020/01/19 06:02:58 DEBUG : open-test-file: Open: flags=O_RDONLY|O_APPEND|O_EXCL 2020/01/19 06:02:58 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:58 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:58 DEBUG : open-test-file: Size and modification time the same (differ by 44.837156ms, within tolerance 1s) 2020/01/19 06:02:58 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:58 DEBUG : open-test-file(0xc000552680): Opened existing cached copy with flags=O_RDONLY|O_APPEND|O_EXCL 2020/01/19 06:02:58 DEBUG : open-test-file(0xc000552680): close: 2020/01/19 06:02:58 DEBUG : open-test-file(0xc000552680): >close: err= 2020/01/19 06:02:58 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:58 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:58 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:58 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:58 DEBUG : open-test-file: Size and modification time the same (differ by 44.837156ms, within tolerance 1s) 2020/01/19 06:02:58 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:58 DEBUG : open-test-file(0xc000552700): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:58 DEBUG : open-test-file(0xc000552700): close: 2020/01/19 06:02:58 DEBUG : open-test-file(0xc000552700): >close: err= 2020/01/19 06:02:58 INFO : open-test-file: Removed from cache 2020/01/19 06:02:58 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_EXCL|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:58 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:58 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:58 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:58 DEBUG : open-test-file(0xc0005ec380): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:58 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:58 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:58 DEBUG : open-test-file(0xc0005ec380): close: 2020/01/19 06:02:58 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:58 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:02:59 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:02:59 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:02:59 INFO : open-test-file: Copied (new) 2020/01/19 06:02:59 DEBUG : open-test-file: transferred to remote 2020/01/19 06:02:59 DEBUG : open-test-file(0xc0005ec380): >close: err= 2020/01/19 06:02:59 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_EXCL|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:02:59 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:02:59 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:02:59 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:02:59 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:59 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:59 DEBUG : open-test-file: Size and modification time the same (differ by 952.851016ms, within tolerance 1s) 2020/01/19 06:02:59 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:02:59 DEBUG : open-test-file(0xc0005ec500): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:02:59 DEBUG : open-test-file(0xc0005ec500): close: 2020/01/19 06:02:59 DEBUG : open-test-file(0xc0005ec500): >close: err= 2020/01/19 06:02:59 INFO : open-test-file: Removed from cache 2020/01/19 06:02:59 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_EXCL|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:02:59 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:02:59 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:02:59 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:02:59 DEBUG : open-test-file(0xc000170a40): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:02:59 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:02:59 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:02:59 DEBUG : open-test-file(0xc000170a40): close: 2020/01/19 06:02:59 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:02:59 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:00 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:00 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:00 INFO : open-test-file: Copied (new) 2020/01/19 06:03:00 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:00 DEBUG : open-test-file(0xc000170a40): >close: err= 2020/01/19 06:03:00 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_EXCL|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:03:00 DEBUG : open-test-file: Open: flags=O_RDONLY|O_APPEND|O_EXCL|O_SYNC 2020/01/19 06:03:00 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:00 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:00 DEBUG : open-test-file: Size and modification time the same (differ by 872.865059ms, within tolerance 1s) 2020/01/19 06:03:00 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:00 DEBUG : open-test-file(0xc000171900): Opened existing cached copy with flags=O_RDONLY|O_APPEND|O_EXCL|O_SYNC 2020/01/19 06:03:00 DEBUG : open-test-file(0xc000171900): close: 2020/01/19 06:03:00 DEBUG : open-test-file(0xc000171900): >close: err= 2020/01/19 06:03:00 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:00 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:00 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:00 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:00 DEBUG : open-test-file: Size and modification time the same (differ by 872.865059ms, within tolerance 1s) 2020/01/19 06:03:00 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:00 DEBUG : open-test-file(0xc000171cc0): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:00 DEBUG : open-test-file(0xc000171cc0): close: 2020/01/19 06:03:00 DEBUG : open-test-file(0xc000171cc0): >close: err= 2020/01/19 06:03:00 INFO : open-test-file: Removed from cache 2020/01/19 06:03:00 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_EXCL|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:00 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:03:00 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:00 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:00 DEBUG : open-test-file(0xc000171e40): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:00 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:00 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:00 DEBUG : open-test-file(0xc000171e40): close: 2020/01/19 06:03:00 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:00 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:01 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:01 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:01 INFO : open-test-file: Copied (new) 2020/01/19 06:03:01 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:01 DEBUG : open-test-file(0xc000171e40): >close: err= 2020/01/19 06:03:01 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_EXCL|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:01 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:03:01 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:01 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:01 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:01 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:01 DEBUG : open-test-file: Size and modification time the same (differ by 776.878857ms, within tolerance 1s) 2020/01/19 06:03:01 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:01 DEBUG : open-test-file(0xc000126400): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:01 DEBUG : open-test-file(0xc000126400): close: 2020/01/19 06:03:01 DEBUG : open-test-file(0xc000126400): >close: err= 2020/01/19 06:03:01 INFO : open-test-file: Removed from cache 2020/01/19 06:03:01 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_CREATE, perm=-rw-rw-rw- 2020/01/19 06:03:01 DEBUG : open-test-file: Open: flags=O_RDONLY|O_APPEND|O_CREATE 2020/01/19 06:03:01 DEBUG : open-test-file(0xc0000803c0): Opening cached copy with flags=O_RDONLY|O_APPEND|O_CREATE 2020/01/19 06:03:01 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:01 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:01 DEBUG : open-test-file(0xc0000803c0): close: 2020/01/19 06:03:01 DEBUG : open-test-file(0xc0000803c0): >close: err= 2020/01/19 06:03:01 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:01 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:01 DEBUG : open-test-file(0xc000080540): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:01 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:01 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:01 DEBUG : open-test-file(0xc000080540): close: 2020/01/19 06:03:01 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:01 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:02 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:02 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:02 INFO : open-test-file: Copied (new) 2020/01/19 06:03:02 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:02 DEBUG : open-test-file(0xc000080540): >close: err= 2020/01/19 06:03:02 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_CREATE, perm=-rw-rw-rw- 2020/01/19 06:03:02 DEBUG : open-test-file: Open: flags=O_RDONLY|O_APPEND|O_CREATE 2020/01/19 06:03:02 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:02 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:02 DEBUG : open-test-file: Size and modification time the same (differ by 656.892289ms, within tolerance 1s) 2020/01/19 06:03:02 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:02 DEBUG : open-test-file(0xc000126740): Opened existing cached copy with flags=O_RDONLY|O_APPEND|O_CREATE 2020/01/19 06:03:02 DEBUG : open-test-file(0xc000126740): close: 2020/01/19 06:03:02 DEBUG : open-test-file(0xc000126740): >close: err= 2020/01/19 06:03:02 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:02 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:02 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:02 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:02 DEBUG : open-test-file: Size and modification time the same (differ by 656.892289ms, within tolerance 1s) 2020/01/19 06:03:02 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:02 DEBUG : open-test-file(0xc0001267c0): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:02 DEBUG : open-test-file(0xc0001267c0): close: 2020/01/19 06:03:02 DEBUG : open-test-file(0xc0001267c0): >close: err= 2020/01/19 06:03:02 INFO : open-test-file: Removed from cache 2020/01/19 06:03:02 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_CREATE|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:02 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:03:02 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:02 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:02 DEBUG : open-test-file(0xc000126880): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:02 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:02 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:02 DEBUG : open-test-file(0xc000126880): close: 2020/01/19 06:03:02 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:02 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:03 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:03 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:03 INFO : open-test-file: Copied (new) 2020/01/19 06:03:03 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:03 DEBUG : open-test-file(0xc000126880): >close: err= 2020/01/19 06:03:03 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_CREATE|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:03 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:03:03 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:03 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:03 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:03 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:03 DEBUG : open-test-file: Size and modification time the same (differ by 880.910972ms, within tolerance 1s) 2020/01/19 06:03:03 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:03 DEBUG : open-test-file(0xc000126d80): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:03 DEBUG : open-test-file(0xc000126d80): close: 2020/01/19 06:03:03 DEBUG : open-test-file(0xc000126d80): >close: err= 2020/01/19 06:03:04 INFO : open-test-file: Removed from cache 2020/01/19 06:03:04 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_CREATE|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:03:04 DEBUG : open-test-file: Open: flags=O_RDONLY|O_APPEND|O_CREATE|O_SYNC 2020/01/19 06:03:04 DEBUG : open-test-file(0xc000362340): Opening cached copy with flags=O_RDONLY|O_APPEND|O_CREATE|O_SYNC 2020/01/19 06:03:04 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:04 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:04 DEBUG : open-test-file(0xc000362340): close: 2020/01/19 06:03:04 DEBUG : open-test-file(0xc000362340): >close: err= 2020/01/19 06:03:04 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:04 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:04 DEBUG : open-test-file(0xc0003623c0): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:04 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:04 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:04 DEBUG : open-test-file(0xc0003623c0): close: 2020/01/19 06:03:04 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:04 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:04 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:04 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:04 INFO : open-test-file: Copied (new) 2020/01/19 06:03:04 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:04 DEBUG : open-test-file(0xc0003623c0): >close: err= 2020/01/19 06:03:04 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_CREATE|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:03:04 DEBUG : open-test-file: Open: flags=O_RDONLY|O_APPEND|O_CREATE|O_SYNC 2020/01/19 06:03:04 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:04 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:04 DEBUG : open-test-file: Size and modification time the same (differ by 96.929532ms, within tolerance 1s) 2020/01/19 06:03:04 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:04 DEBUG : open-test-file(0xc000127180): Opened existing cached copy with flags=O_RDONLY|O_APPEND|O_CREATE|O_SYNC 2020/01/19 06:03:04 DEBUG : open-test-file(0xc000127180): close: 2020/01/19 06:03:04 DEBUG : open-test-file(0xc000127180): >close: err= 2020/01/19 06:03:04 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:04 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:04 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:04 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:04 DEBUG : open-test-file: Size and modification time the same (differ by 96.929532ms, within tolerance 1s) 2020/01/19 06:03:04 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:04 DEBUG : open-test-file(0xc000127200): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:04 DEBUG : open-test-file(0xc000127200): close: 2020/01/19 06:03:04 DEBUG : open-test-file(0xc000127200): >close: err= 2020/01/19 06:03:05 INFO : open-test-file: Removed from cache 2020/01/19 06:03:05 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_CREATE|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:05 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:03:05 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:05 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:05 DEBUG : open-test-file(0xc000127280): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:05 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:05 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:05 DEBUG : open-test-file(0xc000127280): close: 2020/01/19 06:03:05 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:05 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:05 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:05 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:05 INFO : open-test-file: Copied (new) 2020/01/19 06:03:05 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:05 DEBUG : open-test-file(0xc000127280): >close: err= 2020/01/19 06:03:05 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_CREATE|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:05 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:03:05 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:05 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:05 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:05 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:05 DEBUG : open-test-file: Size and modification time the same (differ by 260.947298ms, within tolerance 1s) 2020/01/19 06:03:05 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:05 DEBUG : open-test-file(0xc000127800): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:05 DEBUG : open-test-file(0xc000127800): close: 2020/01/19 06:03:05 DEBUG : open-test-file(0xc000127800): >close: err= 2020/01/19 06:03:06 INFO : open-test-file: Removed from cache 2020/01/19 06:03:06 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_CREATE|O_EXCL, perm=-rw-rw-rw- 2020/01/19 06:03:06 DEBUG : open-test-file: Open: flags=O_RDONLY|O_APPEND|O_CREATE|O_EXCL 2020/01/19 06:03:06 DEBUG : open-test-file(0xc0001278c0): Opening cached copy with flags=O_RDONLY|O_APPEND|O_CREATE|O_EXCL 2020/01/19 06:03:06 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:06 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:06 DEBUG : open-test-file(0xc0001278c0): close: 2020/01/19 06:03:06 DEBUG : open-test-file(0xc0001278c0): >close: err= 2020/01/19 06:03:06 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:06 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:06 DEBUG : open-test-file(0xc000127940): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:06 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:06 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:06 DEBUG : open-test-file(0xc000127940): close: 2020/01/19 06:03:06 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:06 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:06 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:06 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:06 INFO : open-test-file: Copied (new) 2020/01/19 06:03:06 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:06 DEBUG : open-test-file(0xc000127940): >close: err= 2020/01/19 06:03:06 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_CREATE|O_EXCL, perm=-rw-rw-rw- 2020/01/19 06:03:06 DEBUG : open-test-file: Open: flags=O_RDONLY|O_APPEND|O_CREATE|O_EXCL 2020/01/19 06:03:06 ERROR : open-test-file: File.openRW failed: file already exists 2020/01/19 06:03:06 DEBUG : open-test-file: >Open: fd=, err=file already exists 2020/01/19 06:03:06 DEBUG : open-test-file: >OpenFile: fd=, err=file already exists 2020/01/19 06:03:06 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:06 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:06 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:06 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:06 DEBUG : open-test-file: Size and modification time the same (differ by 168.961159ms, within tolerance 1s) 2020/01/19 06:03:06 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:06 DEBUG : open-test-file(0xc00047e780): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:06 DEBUG : open-test-file(0xc00047e780): close: 2020/01/19 06:03:06 DEBUG : open-test-file(0xc00047e780): >close: err= 2020/01/19 06:03:07 INFO : open-test-file: Removed from cache 2020/01/19 06:03:07 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_CREATE|O_EXCL|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:07 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:03:07 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:07 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:07 DEBUG : open-test-file(0xc000362b00): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:07 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:07 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:07 DEBUG : open-test-file(0xc000362b00): close: 2020/01/19 06:03:07 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:07 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:07 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:07 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:07 INFO : open-test-file: Copied (new) 2020/01/19 06:03:07 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:07 DEBUG : open-test-file(0xc000362b00): >close: err= 2020/01/19 06:03:07 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_CREATE|O_EXCL|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:07 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:03:07 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:07 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:07 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:07 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:07 DEBUG : open-test-file: Size and modification time the same (differ by 68.974896ms, within tolerance 1s) 2020/01/19 06:03:07 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:07 DEBUG : open-test-file(0xc00047e880): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:07 DEBUG : open-test-file(0xc00047e880): close: 2020/01/19 06:03:07 DEBUG : open-test-file(0xc00047e880): >close: err= 2020/01/19 06:03:07 INFO : open-test-file: Removed from cache 2020/01/19 06:03:07 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_CREATE|O_EXCL|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:03:07 DEBUG : open-test-file: Open: flags=O_RDONLY|O_APPEND|O_CREATE|O_EXCL|O_SYNC 2020/01/19 06:03:07 DEBUG : open-test-file(0xc00047e940): Opening cached copy with flags=O_RDONLY|O_APPEND|O_CREATE|O_EXCL|O_SYNC 2020/01/19 06:03:07 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:07 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:07 DEBUG : open-test-file(0xc00047e940): close: 2020/01/19 06:03:07 DEBUG : open-test-file(0xc00047e940): >close: err= 2020/01/19 06:03:07 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:07 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:07 DEBUG : open-test-file(0xc00047e9c0): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:07 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:07 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:07 DEBUG : open-test-file(0xc00047e9c0): close: 2020/01/19 06:03:07 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:07 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:08 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:08 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:08 INFO : open-test-file: Copied (new) 2020/01/19 06:03:08 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:08 DEBUG : open-test-file(0xc00047e9c0): >close: err= 2020/01/19 06:03:08 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_CREATE|O_EXCL|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:03:08 DEBUG : open-test-file: Open: flags=O_RDONLY|O_APPEND|O_CREATE|O_EXCL|O_SYNC 2020/01/19 06:03:08 ERROR : open-test-file: File.openRW failed: file already exists 2020/01/19 06:03:08 DEBUG : open-test-file: >Open: fd=, err=file already exists 2020/01/19 06:03:08 DEBUG : open-test-file: >OpenFile: fd=, err=file already exists 2020/01/19 06:03:08 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:08 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:08 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:08 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:08 DEBUG : open-test-file: Size and modification time the same (differ by 980.988816ms, within tolerance 1s) 2020/01/19 06:03:08 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:08 DEBUG : open-test-file(0xc000363a40): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:08 DEBUG : open-test-file(0xc000363a40): close: 2020/01/19 06:03:08 DEBUG : open-test-file(0xc000363a40): >close: err= 2020/01/19 06:03:08 INFO : open-test-file: Removed from cache 2020/01/19 06:03:08 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_CREATE|O_EXCL|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:08 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:03:08 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:08 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:08 DEBUG : open-test-file(0xc000127e80): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:08 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:08 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:08 DEBUG : open-test-file(0xc000127e80): close: 2020/01/19 06:03:08 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:08 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:09 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:09 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:09 INFO : open-test-file: Copied (new) 2020/01/19 06:03:09 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:09 DEBUG : open-test-file(0xc000127e80): >close: err= 2020/01/19 06:03:09 DEBUG : open-test-file: OpenFile: flags=O_RDONLY|O_APPEND|O_CREATE|O_EXCL|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:09 DEBUG : open-test-file: >OpenFile: fd=, err=invalid argument 2020/01/19 06:03:09 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:09 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:09 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:09 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:09 DEBUG : open-test-file: Size and modification time the same (differ by 869.002371ms, within tolerance 1s) 2020/01/19 06:03:09 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:09 DEBUG : open-test-file(0xc00047eb40): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:09 DEBUG : open-test-file(0xc00047eb40): close: 2020/01/19 06:03:09 DEBUG : open-test-file(0xc00047eb40): >close: err= 2020/01/19 06:03:09 INFO : open-test-file: Removed from cache 2020/01/19 06:03:09 DEBUG : open-test-file: OpenFile: flags=O_WRONLY, perm=-rw-rw-rw- 2020/01/19 06:03:09 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:03:09 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:09 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:09 DEBUG : open-test-file(0xc0005ec180): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:09 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:09 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:09 DEBUG : open-test-file(0xc0005ec180): close: 2020/01/19 06:03:09 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:09 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:10 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:10 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:10 INFO : open-test-file: Copied (new) 2020/01/19 06:03:10 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:10 DEBUG : open-test-file(0xc0005ec180): >close: err= 2020/01/19 06:03:10 DEBUG : open-test-file: OpenFile: flags=O_WRONLY, perm=-rw-rw-rw- 2020/01/19 06:03:10 DEBUG : open-test-file: Open: flags=O_WRONLY 2020/01/19 06:03:10 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:10 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:10 DEBUG : open-test-file: Size and modification time the same (differ by 825.016963ms, within tolerance 1s) 2020/01/19 06:03:10 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:10 DEBUG : open-test-file(0xc000718000): Opened existing cached copy with flags=O_WRONLY 2020/01/19 06:03:10 DEBUG : open-test-file(0xc000718000): close: 2020/01/19 06:03:10 DEBUG : open-test-file: Modification times differ by -1.405025816s: 2020-01-19 06:03:10.405025816 +0000 UTC, 2020-01-19 06:03:09 +0000 UTC 2020/01/19 06:03:10 DEBUG : open-test-file: SHA-1 = c43a17390bfb39fea55dda4ee9c2da6838d17125 (Local file system at /home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-jefitaz6luwiyuk6lolehom0) 2020/01/19 06:03:10 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d (One drive root 'rclone-test-jefitaz6luwiyuk6lolehom0') 2020/01/19 06:03:10 DEBUG : open-test-file: SHA-1 differ 2020/01/19 06:03:10 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:10 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:11 DEBUG : open-test-file: SHA-1 = c43a17390bfb39fea55dda4ee9c2da6838d17125 OK 2020/01/19 06:03:11 INFO : open-test-file: Copied (replaced existing) 2020/01/19 06:03:11 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:11 DEBUG : open-test-file(0xc000718000): >close: err= 2020/01/19 06:03:11 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:11 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:11 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:11 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:11 DEBUG : open-test-file: Size and modification time the same (differ by 405.025816ms, within tolerance 1s) 2020/01/19 06:03:11 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:11 DEBUG : open-test-file(0xc0007185c0): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:11 DEBUG : open-test-file(0xc0007185c0): close: 2020/01/19 06:03:11 DEBUG : open-test-file(0xc0007185c0): >close: err= 2020/01/19 06:03:11 INFO : open-test-file: Removed from cache 2020/01/19 06:03:11 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:11 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:03:11 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:11 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:11 DEBUG : open-test-file(0xc0005ec540): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:11 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:11 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:11 DEBUG : open-test-file(0xc0005ec540): close: 2020/01/19 06:03:11 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:11 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:11 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:12 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:12 INFO : open-test-file: Copied (new) 2020/01/19 06:03:12 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:12 DEBUG : open-test-file(0xc0005ec540): >close: err= 2020/01/19 06:03:12 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:12 DEBUG : open-test-file: Open: flags=O_WRONLY|O_TRUNC 2020/01/19 06:03:12 DEBUG : open-test-file(0xc00047ee40): Opening cached copy with flags=O_WRONLY|O_TRUNC 2020/01/19 06:03:12 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:12 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:12 DEBUG : open-test-file(0xc00047ee40): close: 2020/01/19 06:03:12 DEBUG : open-test-file: Sizes differ (src 3 vs dst 5) 2020/01/19 06:03:12 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:12 DEBUG : open-test-file: Uploading segment 0/3 size 3 2020/01/19 06:03:12 DEBUG : open-test-file: SHA-1 = 2499da6f5e54b5dfb00e20c687819f9a7cba3d62 OK 2020/01/19 06:03:12 INFO : open-test-file: Copied (replaced existing) 2020/01/19 06:03:12 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:12 DEBUG : open-test-file(0xc00047ee40): >close: err= 2020/01/19 06:03:12 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:12 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:12 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:12 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:12 DEBUG : open-test-file: Size and modification time the same (differ by 17.050421ms, within tolerance 1s) 2020/01/19 06:03:12 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:12 DEBUG : open-test-file(0xc0007c0180): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:12 DEBUG : open-test-file(0xc0007c0180): close: 2020/01/19 06:03:12 DEBUG : open-test-file(0xc0007c0180): >close: err= 2020/01/19 06:03:12 INFO : open-test-file: Removed from cache 2020/01/19 06:03:12 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:03:12 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:03:12 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:12 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:12 DEBUG : open-test-file(0xc000362000): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:12 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:12 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:12 DEBUG : open-test-file(0xc000362000): close: 2020/01/19 06:03:12 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:12 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:13 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:13 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:13 INFO : open-test-file: Copied (new) 2020/01/19 06:03:13 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:13 DEBUG : open-test-file(0xc000362000): >close: err= 2020/01/19 06:03:13 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:03:13 DEBUG : open-test-file: Open: flags=O_WRONLY|O_SYNC 2020/01/19 06:03:13 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:13 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:13 DEBUG : open-test-file: Size and modification time the same (differ by 941.064525ms, within tolerance 1s) 2020/01/19 06:03:13 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:13 DEBUG : open-test-file(0xc000362240): Opened existing cached copy with flags=O_WRONLY|O_SYNC 2020/01/19 06:03:13 DEBUG : open-test-file(0xc000362240): close: 2020/01/19 06:03:13 DEBUG : open-test-file: Modification times differ by -1.501073073s: 2020-01-19 06:03:13.501073073 +0000 UTC, 2020-01-19 06:03:12 +0000 UTC 2020/01/19 06:03:13 DEBUG : open-test-file: SHA-1 = c43a17390bfb39fea55dda4ee9c2da6838d17125 (Local file system at /home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-jefitaz6luwiyuk6lolehom0) 2020/01/19 06:03:13 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d (One drive root 'rclone-test-jefitaz6luwiyuk6lolehom0') 2020/01/19 06:03:13 DEBUG : open-test-file: SHA-1 differ 2020/01/19 06:03:13 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:14 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:14 DEBUG : open-test-file: SHA-1 = c43a17390bfb39fea55dda4ee9c2da6838d17125 OK 2020/01/19 06:03:14 INFO : open-test-file: Copied (replaced existing) 2020/01/19 06:03:14 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:14 DEBUG : open-test-file(0xc000362240): >close: err= 2020/01/19 06:03:14 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:14 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:14 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:14 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:14 DEBUG : open-test-file: Size and modification time the same (differ by 501.073073ms, within tolerance 1s) 2020/01/19 06:03:14 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:14 DEBUG : open-test-file(0xc000170b80): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:14 DEBUG : open-test-file(0xc000170b80): close: 2020/01/19 06:03:14 DEBUG : open-test-file(0xc000170b80): >close: err= 2020/01/19 06:03:14 INFO : open-test-file: Removed from cache 2020/01/19 06:03:14 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:14 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:03:14 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:14 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:14 DEBUG : open-test-file(0xc0001261c0): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:14 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:14 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:14 DEBUG : open-test-file(0xc0001261c0): close: 2020/01/19 06:03:14 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:14 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:15 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:15 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:15 INFO : open-test-file: Copied (new) 2020/01/19 06:03:15 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:15 DEBUG : open-test-file(0xc0001261c0): >close: err= 2020/01/19 06:03:15 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:15 DEBUG : open-test-file: Open: flags=O_WRONLY|O_SYNC|O_TRUNC 2020/01/19 06:03:15 DEBUG : open-test-file(0xc000126400): Opening cached copy with flags=O_WRONLY|O_SYNC|O_TRUNC 2020/01/19 06:03:15 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:15 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:16 DEBUG : open-test-file(0xc000126400): close: 2020/01/19 06:03:16 DEBUG : open-test-file: Sizes differ (src 3 vs dst 5) 2020/01/19 06:03:16 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:16 DEBUG : open-test-file: Uploading segment 0/3 size 3 2020/01/19 06:03:16 DEBUG : open-test-file: SHA-1 = 2499da6f5e54b5dfb00e20c687819f9a7cba3d62 OK 2020/01/19 06:03:16 INFO : open-test-file: Copied (replaced existing) 2020/01/19 06:03:16 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:16 DEBUG : open-test-file(0xc000126400): >close: err= 2020/01/19 06:03:16 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:16 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:16 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:16 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:16 DEBUG : open-test-file: Size and modification time the same (differ by 841.10879ms, within tolerance 1s) 2020/01/19 06:03:16 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:16 DEBUG : open-test-file(0xc0001269c0): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:16 DEBUG : open-test-file(0xc0001269c0): close: 2020/01/19 06:03:16 DEBUG : open-test-file(0xc0001269c0): >close: err= 2020/01/19 06:03:17 INFO : open-test-file: Removed from cache 2020/01/19 06:03:17 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_EXCL, perm=-rw-rw-rw- 2020/01/19 06:03:17 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:03:17 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:17 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:17 DEBUG : open-test-file(0xc000170c40): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:17 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:17 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:17 DEBUG : open-test-file(0xc000170c40): close: 2020/01/19 06:03:17 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:17 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:17 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:17 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:17 INFO : open-test-file: Copied (new) 2020/01/19 06:03:17 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:17 DEBUG : open-test-file(0xc000170c40): >close: err= 2020/01/19 06:03:17 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_EXCL, perm=-rw-rw-rw- 2020/01/19 06:03:17 DEBUG : open-test-file: Open: flags=O_WRONLY|O_EXCL 2020/01/19 06:03:17 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:17 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:17 DEBUG : open-test-file: Size and modification time the same (differ by 113.128206ms, within tolerance 1s) 2020/01/19 06:03:17 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:17 DEBUG : open-test-file(0xc000363940): Opened existing cached copy with flags=O_WRONLY|O_EXCL 2020/01/19 06:03:17 DEBUG : open-test-file(0xc000363940): close: 2020/01/19 06:03:17 DEBUG : open-test-file: Size and modification time the same (differ by -745.137852ms, within tolerance 1s) 2020/01/19 06:03:17 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:17 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:17 DEBUG : open-test-file(0xc000363940): >close: err= 2020/01/19 06:03:17 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:17 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:17 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:17 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:17 DEBUG : open-test-file: Size and modification time the same (differ by 745.137852ms, within tolerance 1s) 2020/01/19 06:03:17 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:17 DEBUG : open-test-file(0xc000363980): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:17 DEBUG : open-test-file(0xc000363980): close: 2020/01/19 06:03:17 DEBUG : open-test-file(0xc000363980): >close: err= 2020/01/19 06:03:18 INFO : open-test-file: Removed from cache 2020/01/19 06:03:18 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_EXCL|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:18 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:03:18 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:18 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:18 DEBUG : open-test-file(0xc000363a00): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:18 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:18 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:18 DEBUG : open-test-file(0xc000363a00): close: 2020/01/19 06:03:18 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:18 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:18 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:18 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:18 INFO : open-test-file: Copied (new) 2020/01/19 06:03:18 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:18 DEBUG : open-test-file(0xc000363a00): >close: err= 2020/01/19 06:03:18 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_EXCL|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:18 DEBUG : open-test-file: Open: flags=O_WRONLY|O_EXCL|O_TRUNC 2020/01/19 06:03:18 DEBUG : open-test-file(0xc000171f80): Opening cached copy with flags=O_WRONLY|O_EXCL|O_TRUNC 2020/01/19 06:03:18 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:18 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:18 DEBUG : open-test-file(0xc000171f80): close: 2020/01/19 06:03:18 DEBUG : open-test-file: Sizes differ (src 3 vs dst 5) 2020/01/19 06:03:18 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:19 DEBUG : open-test-file: Uploading segment 0/3 size 3 2020/01/19 06:03:19 DEBUG : open-test-file: SHA-1 = 2499da6f5e54b5dfb00e20c687819f9a7cba3d62 OK 2020/01/19 06:03:19 INFO : open-test-file: Copied (replaced existing) 2020/01/19 06:03:19 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:19 DEBUG : open-test-file(0xc000171f80): >close: err= 2020/01/19 06:03:19 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:19 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:19 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:19 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:19 DEBUG : open-test-file: Size and modification time the same (differ by 653.151712ms, within tolerance 1s) 2020/01/19 06:03:19 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:19 DEBUG : open-test-file(0xc000126d40): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:19 DEBUG : open-test-file(0xc000126d40): close: 2020/01/19 06:03:19 DEBUG : open-test-file(0xc000126d40): >close: err= 2020/01/19 06:03:19 INFO : open-test-file: Removed from cache 2020/01/19 06:03:19 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_EXCL|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:03:19 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:03:19 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:19 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:19 DEBUG : open-test-file(0xc0007c0380): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:19 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:19 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:19 DEBUG : open-test-file(0xc0007c0380): close: 2020/01/19 06:03:19 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:19 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:20 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:20 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:20 INFO : open-test-file: Copied (new) 2020/01/19 06:03:20 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:20 DEBUG : open-test-file(0xc0007c0380): >close: err= 2020/01/19 06:03:20 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_EXCL|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:03:20 DEBUG : open-test-file: Open: flags=O_WRONLY|O_EXCL|O_SYNC 2020/01/19 06:03:20 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:20 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:20 DEBUG : open-test-file: Size and modification time the same (differ by 913.170945ms, within tolerance 1s) 2020/01/19 06:03:20 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:20 DEBUG : open-test-file(0xc0007c0540): Opened existing cached copy with flags=O_WRONLY|O_EXCL|O_SYNC 2020/01/19 06:03:20 DEBUG : open-test-file(0xc0007c0540): close: 2020/01/19 06:03:20 DEBUG : open-test-file: Modification times differ by -1.489179737s: 2020-01-19 06:03:20.489179737 +0000 UTC, 2020-01-19 06:03:19 +0000 UTC 2020/01/19 06:03:20 DEBUG : open-test-file: SHA-1 = c43a17390bfb39fea55dda4ee9c2da6838d17125 (Local file system at /home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-jefitaz6luwiyuk6lolehom0) 2020/01/19 06:03:20 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d (One drive root 'rclone-test-jefitaz6luwiyuk6lolehom0') 2020/01/19 06:03:20 DEBUG : open-test-file: SHA-1 differ 2020/01/19 06:03:20 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:21 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:22 DEBUG : open-test-file: SHA-1 = c43a17390bfb39fea55dda4ee9c2da6838d17125 OK 2020/01/19 06:03:22 INFO : open-test-file: Copied (replaced existing) 2020/01/19 06:03:22 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:22 DEBUG : open-test-file(0xc0007c0540): >close: err= 2020/01/19 06:03:22 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:22 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:22 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:22 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:22 DEBUG : open-test-file: Size and modification time the same (differ by 489.179737ms, within tolerance 1s) 2020/01/19 06:03:22 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:22 DEBUG : open-test-file(0xc00047e9c0): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:22 DEBUG : open-test-file(0xc00047e9c0): close: 2020/01/19 06:03:22 DEBUG : open-test-file(0xc00047e9c0): >close: err= 2020/01/19 06:03:25 INFO : open-test-file: Removed from cache 2020/01/19 06:03:25 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_EXCL|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:25 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:03:25 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:25 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:25 DEBUG : open-test-file(0xc0007c07c0): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:25 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:25 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:25 DEBUG : open-test-file(0xc0007c07c0): close: 2020/01/19 06:03:25 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:25 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:26 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:26 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:26 INFO : open-test-file: Copied (new) 2020/01/19 06:03:26 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:26 DEBUG : open-test-file(0xc0007c07c0): >close: err= 2020/01/19 06:03:26 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_EXCL|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:26 DEBUG : open-test-file: Open: flags=O_WRONLY|O_EXCL|O_SYNC|O_TRUNC 2020/01/19 06:03:26 DEBUG : open-test-file(0xc00047ed80): Opening cached copy with flags=O_WRONLY|O_EXCL|O_SYNC|O_TRUNC 2020/01/19 06:03:26 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:26 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:26 DEBUG : open-test-file(0xc00047ed80): close: 2020/01/19 06:03:26 DEBUG : open-test-file: Sizes differ (src 3 vs dst 5) 2020/01/19 06:03:26 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:27 DEBUG : open-test-file: Uploading segment 0/3 size 3 2020/01/19 06:03:27 DEBUG : open-test-file: SHA-1 = 2499da6f5e54b5dfb00e20c687819f9a7cba3d62 OK 2020/01/19 06:03:27 INFO : open-test-file: Copied (replaced existing) 2020/01/19 06:03:27 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:27 DEBUG : open-test-file(0xc00047ed80): >close: err= 2020/01/19 06:03:27 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:27 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:27 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:27 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:27 DEBUG : open-test-file: Size and modification time the same (differ by 553.272298ms, within tolerance 1s) 2020/01/19 06:03:27 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:27 DEBUG : open-test-file(0xc00047f240): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:27 DEBUG : open-test-file(0xc00047f240): close: 2020/01/19 06:03:27 DEBUG : open-test-file(0xc00047f240): >close: err= 2020/01/19 06:03:28 INFO : open-test-file: Removed from cache 2020/01/19 06:03:28 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rw-rw-rw- 2020/01/19 06:03:28 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:28 DEBUG : open-test-file(0xc0007c0a80): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:28 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:28 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:28 DEBUG : open-test-file(0xc0007c0a80): close: 2020/01/19 06:03:28 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:28 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:28 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:29 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:29 INFO : open-test-file: Copied (new) 2020/01/19 06:03:29 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:29 DEBUG : open-test-file(0xc0007c0a80): >close: err= 2020/01/19 06:03:29 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:29 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:29 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:29 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:29 DEBUG : open-test-file: Size and modification time the same (differ by 69.295438ms, within tolerance 1s) 2020/01/19 06:03:29 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:29 DEBUG : open-test-file(0xc00047f4c0): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:29 DEBUG : open-test-file(0xc00047f4c0): close: 2020/01/19 06:03:29 DEBUG : open-test-file: Modification times differ by -1.073310763s: 2020-01-19 06:03:29.073310763 +0000 UTC, 2020-01-19 06:03:28 +0000 UTC 2020/01/19 06:03:29 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:29 ERROR : open-test-file: Failed to set modification time: resourceModified: ETag does not match current item's value 2020/01/19 06:03:29 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:29 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:29 DEBUG : open-test-file(0xc00047f4c0): >close: err= 2020/01/19 06:03:29 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rw-rw-rw- 2020/01/19 06:03:29 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:29 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:29 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:29 DEBUG : open-test-file: Modification times differ by 1.073310763s: 2020-01-19 06:03:28 +0000 UTC, 2020-01-19 06:03:29.073310763 +0000 UTC 2020/01/19 06:03:29 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:29 INFO : open-test-file: Updated modification time in destination 2020/01/19 06:03:29 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:29 DEBUG : open-test-file(0xc00047f7c0): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:29 DEBUG : open-test-file(0xc00047f7c0): close: 2020/01/19 06:03:29 DEBUG : open-test-file: Modification times differ by -1.457316624s: 2020-01-19 06:03:29.457316624 +0000 UTC, 2020-01-19 06:03:28 +0000 UTC 2020/01/19 06:03:29 DEBUG : open-test-file: SHA-1 = c43a17390bfb39fea55dda4ee9c2da6838d17125 (Local file system at /home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-jefitaz6luwiyuk6lolehom0) 2020/01/19 06:03:29 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d (One drive root 'rclone-test-jefitaz6luwiyuk6lolehom0') 2020/01/19 06:03:29 DEBUG : open-test-file: SHA-1 differ 2020/01/19 06:03:29 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:29 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:30 DEBUG : open-test-file: SHA-1 = c43a17390bfb39fea55dda4ee9c2da6838d17125 OK 2020/01/19 06:03:30 INFO : open-test-file: Copied (replaced existing) 2020/01/19 06:03:30 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:30 DEBUG : open-test-file(0xc00047f7c0): >close: err= 2020/01/19 06:03:30 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:30 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:30 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:30 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:30 DEBUG : open-test-file: Size and modification time the same (differ by 457.316624ms, within tolerance 1s) 2020/01/19 06:03:30 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:30 DEBUG : open-test-file(0xc00047fe40): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:30 DEBUG : open-test-file(0xc00047fe40): close: 2020/01/19 06:03:30 DEBUG : open-test-file(0xc00047fe40): >close: err= 2020/01/19 06:03:30 INFO : open-test-file: Removed from cache 2020/01/19 06:03:30 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:30 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE|O_TRUNC 2020/01/19 06:03:30 DEBUG : open-test-file(0xc0007c0c80): Opening cached copy with flags=O_WRONLY|O_CREATE|O_TRUNC 2020/01/19 06:03:30 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:30 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:30 DEBUG : open-test-file(0xc0007c0c80): close: 2020/01/19 06:03:30 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:30 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:30 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:31 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:31 INFO : open-test-file: Copied (new) 2020/01/19 06:03:31 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:31 DEBUG : open-test-file(0xc0007c0c80): >close: err= 2020/01/19 06:03:31 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:31 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:31 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:31 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:31 DEBUG : open-test-file: Size and modification time the same (differ by 329.329935ms, within tolerance 1s) 2020/01/19 06:03:31 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:31 DEBUG : open-test-file(0xc0005ec040): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:31 DEBUG : open-test-file(0xc0005ec040): close: 2020/01/19 06:03:31 DEBUG : open-test-file: Modification times differ by -1.385346054s: 2020-01-19 06:03:31.385346054 +0000 UTC, 2020-01-19 06:03:30 +0000 UTC 2020/01/19 06:03:31 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:31 INFO : open-test-file: Updated modification time in destination 2020/01/19 06:03:31 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:31 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:31 DEBUG : open-test-file(0xc0005ec040): >close: err= 2020/01/19 06:03:31 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:31 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE|O_TRUNC 2020/01/19 06:03:31 DEBUG : open-test-file(0xc000127840): Opening cached copy with flags=O_WRONLY|O_CREATE|O_TRUNC 2020/01/19 06:03:31 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:31 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:31 DEBUG : open-test-file(0xc000127840): close: 2020/01/19 06:03:31 DEBUG : open-test-file: Sizes differ (src 3 vs dst 5) 2020/01/19 06:03:31 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:32 DEBUG : open-test-file: Uploading segment 0/3 size 3 2020/01/19 06:03:32 DEBUG : open-test-file: SHA-1 = 2499da6f5e54b5dfb00e20c687819f9a7cba3d62 OK 2020/01/19 06:03:32 INFO : open-test-file: Copied (replaced existing) 2020/01/19 06:03:32 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:32 DEBUG : open-test-file(0xc000127840): >close: err= 2020/01/19 06:03:32 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:32 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:32 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:32 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:32 DEBUG : open-test-file: Size and modification time the same (differ by 789.35222ms, within tolerance 1s) 2020/01/19 06:03:32 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:32 DEBUG : open-test-file(0xc000080200): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:32 DEBUG : open-test-file(0xc000080200): close: 2020/01/19 06:03:32 DEBUG : open-test-file(0xc000080200): >close: err= 2020/01/19 06:03:33 INFO : open-test-file: Removed from cache 2020/01/19 06:03:33 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:03:33 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE|O_SYNC 2020/01/19 06:03:33 DEBUG : open-test-file(0xc000080340): Opening cached copy with flags=O_WRONLY|O_CREATE|O_SYNC 2020/01/19 06:03:33 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:33 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:33 DEBUG : open-test-file(0xc000080340): close: 2020/01/19 06:03:33 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:33 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:34 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:34 DEBUG : open-test-file: updateTime: setting atime to 2020-01-19 06:03:34.189388855 +0000 UTC 2020/01/19 06:03:34 INFO : Cleaned the cache: objects 2 (was 2), total size 5 (was 0) 2020/01/19 06:03:34 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:34 INFO : open-test-file: Copied (new) 2020/01/19 06:03:34 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:34 DEBUG : open-test-file(0xc000080340): >close: err= 2020/01/19 06:03:34 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:34 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:34 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:34 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:34 DEBUG : open-test-file: Size and modification time the same (differ by 597.379818ms, within tolerance 1s) 2020/01/19 06:03:34 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:34 DEBUG : open-test-file(0xc00047e940): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:34 DEBUG : open-test-file(0xc00047e940): close: 2020/01/19 06:03:34 DEBUG : open-test-file: Modification times differ by -1.85339899s: 2020-01-19 06:03:34.85339899 +0000 UTC, 2020-01-19 06:03:33 +0000 UTC 2020/01/19 06:03:34 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:35 INFO : open-test-file: Updated modification time in destination 2020/01/19 06:03:35 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:35 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:35 DEBUG : open-test-file(0xc00047e940): >close: err= 2020/01/19 06:03:35 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:03:35 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE|O_SYNC 2020/01/19 06:03:35 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:35 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:35 DEBUG : open-test-file: Size and modification time the same (differ by 853.39899ms, within tolerance 1s) 2020/01/19 06:03:35 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:35 DEBUG : open-test-file(0xc0001714c0): Opened existing cached copy with flags=O_WRONLY|O_CREATE|O_SYNC 2020/01/19 06:03:35 DEBUG : open-test-file(0xc0001714c0): close: 2020/01/19 06:03:35 DEBUG : open-test-file: Modification times differ by -1.293405706s: 2020-01-19 06:03:35.293405706 +0000 UTC, 2020-01-19 06:03:34 +0000 UTC 2020/01/19 06:03:35 DEBUG : open-test-file: SHA-1 = c43a17390bfb39fea55dda4ee9c2da6838d17125 (Local file system at /home/rclone/.cache/rclone/vfs/TestOneDrive/rclone-test-jefitaz6luwiyuk6lolehom0) 2020/01/19 06:03:35 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d (One drive root 'rclone-test-jefitaz6luwiyuk6lolehom0') 2020/01/19 06:03:35 DEBUG : open-test-file: SHA-1 differ 2020/01/19 06:03:35 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:35 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:36 DEBUG : open-test-file: SHA-1 = c43a17390bfb39fea55dda4ee9c2da6838d17125 OK 2020/01/19 06:03:36 INFO : open-test-file: Copied (replaced existing) 2020/01/19 06:03:36 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:36 DEBUG : open-test-file(0xc0001714c0): >close: err= 2020/01/19 06:03:36 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:36 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:36 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:36 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:36 DEBUG : open-test-file: Size and modification time the same (differ by 293.405706ms, within tolerance 1s) 2020/01/19 06:03:36 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:36 DEBUG : open-test-file(0xc000362100): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:36 DEBUG : open-test-file(0xc000362100): close: 2020/01/19 06:03:36 DEBUG : open-test-file(0xc000362100): >close: err= 2020/01/19 06:03:36 INFO : open-test-file: Removed from cache 2020/01/19 06:03:36 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:36 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE|O_SYNC|O_TRUNC 2020/01/19 06:03:36 DEBUG : open-test-file(0xc00047ecc0): Opening cached copy with flags=O_WRONLY|O_CREATE|O_SYNC|O_TRUNC 2020/01/19 06:03:36 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:36 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:36 DEBUG : open-test-file(0xc00047ecc0): close: 2020/01/19 06:03:36 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:36 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:37 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:37 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:37 INFO : open-test-file: Copied (new) 2020/01/19 06:03:37 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:37 DEBUG : open-test-file(0xc00047ecc0): >close: err= 2020/01/19 06:03:37 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:37 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:37 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:37 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:37 DEBUG : open-test-file: Size and modification time the same (differ by 365.422069ms, within tolerance 1s) 2020/01/19 06:03:37 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:37 DEBUG : open-test-file(0xc00047ef80): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:37 DEBUG : open-test-file(0xc00047ef80): close: 2020/01/19 06:03:37 DEBUG : open-test-file: Modification times differ by -1.377437517s: 2020-01-19 06:03:37.377437517 +0000 UTC, 2020-01-19 06:03:36 +0000 UTC 2020/01/19 06:03:37 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:37 INFO : open-test-file: Updated modification time in destination 2020/01/19 06:03:37 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:37 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:37 DEBUG : open-test-file(0xc00047ef80): >close: err= 2020/01/19 06:03:37 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:37 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE|O_SYNC|O_TRUNC 2020/01/19 06:03:37 DEBUG : open-test-file(0xc00047f340): Opening cached copy with flags=O_WRONLY|O_CREATE|O_SYNC|O_TRUNC 2020/01/19 06:03:37 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:37 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:38 DEBUG : open-test-file(0xc00047f340): close: 2020/01/19 06:03:38 DEBUG : open-test-file: Sizes differ (src 3 vs dst 5) 2020/01/19 06:03:38 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:38 DEBUG : open-test-file: Uploading segment 0/3 size 3 2020/01/19 06:03:38 DEBUG : open-test-file: SHA-1 = 2499da6f5e54b5dfb00e20c687819f9a7cba3d62 OK 2020/01/19 06:03:38 INFO : open-test-file: Copied (replaced existing) 2020/01/19 06:03:38 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:38 DEBUG : open-test-file(0xc00047f340): >close: err= 2020/01/19 06:03:38 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:38 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:38 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:38 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:38 DEBUG : open-test-file: Size and modification time the same (differ by 797.443928ms, within tolerance 1s) 2020/01/19 06:03:38 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:38 DEBUG : open-test-file(0xc000126680): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:38 DEBUG : open-test-file(0xc000126680): close: 2020/01/19 06:03:38 DEBUG : open-test-file(0xc000126680): >close: err= 2020/01/19 06:03:39 INFO : open-test-file: Removed from cache 2020/01/19 06:03:39 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE|O_EXCL, perm=-rw-rw-rw- 2020/01/19 06:03:39 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE|O_EXCL 2020/01/19 06:03:39 DEBUG : open-test-file(0xc000126740): Opening cached copy with flags=O_WRONLY|O_CREATE|O_EXCL 2020/01/19 06:03:39 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:39 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:39 DEBUG : open-test-file(0xc000126740): close: 2020/01/19 06:03:39 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:39 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:40 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:40 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:40 INFO : open-test-file: Copied (new) 2020/01/19 06:03:40 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:40 DEBUG : open-test-file(0xc000126740): >close: err= 2020/01/19 06:03:40 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:40 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:40 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:40 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:40 DEBUG : open-test-file: Size and modification time the same (differ by 253.466153ms, within tolerance 1s) 2020/01/19 06:03:40 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:40 DEBUG : open-test-file(0xc000362d40): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:40 DEBUG : open-test-file(0xc000362d40): close: 2020/01/19 06:03:40 DEBUG : open-test-file: Modification times differ by -1.421483981s: 2020-01-19 06:03:40.421483981 +0000 UTC, 2020-01-19 06:03:39 +0000 UTC 2020/01/19 06:03:40 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:40 INFO : open-test-file: Updated modification time in destination 2020/01/19 06:03:40 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:40 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:40 DEBUG : open-test-file(0xc000362d40): >close: err= 2020/01/19 06:03:40 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE|O_EXCL, perm=-rw-rw-rw- 2020/01/19 06:03:40 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE|O_EXCL 2020/01/19 06:03:40 ERROR : open-test-file: File.openRW failed: file already exists 2020/01/19 06:03:40 DEBUG : open-test-file: >Open: fd=, err=file already exists 2020/01/19 06:03:40 DEBUG : open-test-file: >OpenFile: fd=, err=file already exists 2020/01/19 06:03:40 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:40 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:40 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:40 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:40 DEBUG : open-test-file: Size and modification time the same (differ by 421.483981ms, within tolerance 1s) 2020/01/19 06:03:40 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:40 DEBUG : open-test-file(0xc00047f740): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:40 DEBUG : open-test-file(0xc00047f740): close: 2020/01/19 06:03:40 DEBUG : open-test-file(0xc00047f740): >close: err= 2020/01/19 06:03:41 INFO : open-test-file: Removed from cache 2020/01/19 06:03:41 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE|O_EXCL|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:41 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE|O_EXCL|O_TRUNC 2020/01/19 06:03:41 DEBUG : open-test-file(0xc000126bc0): Opening cached copy with flags=O_WRONLY|O_CREATE|O_EXCL|O_TRUNC 2020/01/19 06:03:41 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:41 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:41 DEBUG : open-test-file(0xc000126bc0): close: 2020/01/19 06:03:41 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:41 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:41 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:42 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:42 INFO : open-test-file: Copied (new) 2020/01/19 06:03:42 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:42 DEBUG : open-test-file(0xc000126bc0): >close: err= 2020/01/19 06:03:42 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:42 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:42 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:42 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:42 DEBUG : open-test-file: Size and modification time the same (differ by 205.495949ms, within tolerance 1s) 2020/01/19 06:03:42 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:42 DEBUG : open-test-file(0xc000363800): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:42 DEBUG : open-test-file(0xc000363800): close: 2020/01/19 06:03:42 DEBUG : open-test-file: Modification times differ by -1.137510175s: 2020-01-19 06:03:42.137510175 +0000 UTC, 2020-01-19 06:03:41 +0000 UTC 2020/01/19 06:03:42 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:42 INFO : open-test-file: Updated modification time in destination 2020/01/19 06:03:42 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:42 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:42 DEBUG : open-test-file(0xc000363800): >close: err= 2020/01/19 06:03:42 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE|O_EXCL|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:42 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE|O_EXCL|O_TRUNC 2020/01/19 06:03:42 ERROR : open-test-file: File.openRW failed: file already exists 2020/01/19 06:03:42 DEBUG : open-test-file: >Open: fd=, err=file already exists 2020/01/19 06:03:42 DEBUG : open-test-file: >OpenFile: fd=, err=file already exists 2020/01/19 06:03:42 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:42 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:42 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:42 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:42 DEBUG : open-test-file: Size and modification time the same (differ by 137.510175ms, within tolerance 1s) 2020/01/19 06:03:42 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:42 DEBUG : open-test-file(0xc0001273c0): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:42 DEBUG : open-test-file(0xc0001273c0): close: 2020/01/19 06:03:42 DEBUG : open-test-file(0xc0001273c0): >close: err= 2020/01/19 06:03:43 INFO : open-test-file: Removed from cache 2020/01/19 06:03:43 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE|O_EXCL|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:03:43 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE|O_EXCL|O_SYNC 2020/01/19 06:03:43 DEBUG : open-test-file(0xc0001274c0): Opening cached copy with flags=O_WRONLY|O_CREATE|O_EXCL|O_SYNC 2020/01/19 06:03:43 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:43 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:43 DEBUG : open-test-file(0xc0001274c0): close: 2020/01/19 06:03:43 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:43 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:43 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:44 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:44 INFO : open-test-file: Copied (new) 2020/01/19 06:03:44 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:44 DEBUG : open-test-file(0xc0001274c0): >close: err= 2020/01/19 06:03:44 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:44 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:44 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:44 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:44 DEBUG : open-test-file: Size and modification time the same (differ by 165.525867ms, within tolerance 1s) 2020/01/19 06:03:44 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:44 DEBUG : open-test-file(0xc000127dc0): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:44 DEBUG : open-test-file(0xc000127dc0): close: 2020/01/19 06:03:44 DEBUG : open-test-file: Modification times differ by -1.093540032s: 2020-01-19 06:03:44.093540032 +0000 UTC, 2020-01-19 06:03:43 +0000 UTC 2020/01/19 06:03:44 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:44 INFO : open-test-file: Updated modification time in destination 2020/01/19 06:03:44 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:44 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:44 DEBUG : open-test-file(0xc000127dc0): >close: err= 2020/01/19 06:03:44 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE|O_EXCL|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:03:44 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE|O_EXCL|O_SYNC 2020/01/19 06:03:44 ERROR : open-test-file: File.openRW failed: file already exists 2020/01/19 06:03:44 DEBUG : open-test-file: >Open: fd=, err=file already exists 2020/01/19 06:03:44 DEBUG : open-test-file: >OpenFile: fd=, err=file already exists 2020/01/19 06:03:44 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:44 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:44 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:44 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:44 DEBUG : open-test-file: Size and modification time the same (differ by 93.540032ms, within tolerance 1s) 2020/01/19 06:03:44 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:44 DEBUG : open-test-file(0xc0007c01c0): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:44 DEBUG : open-test-file(0xc0007c01c0): close: 2020/01/19 06:03:44 DEBUG : open-test-file(0xc0007c01c0): >close: err= 2020/01/19 06:03:44 INFO : open-test-file: Removed from cache 2020/01/19 06:03:44 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE|O_EXCL|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:44 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE|O_EXCL|O_SYNC|O_TRUNC 2020/01/19 06:03:44 DEBUG : open-test-file(0xc000363b80): Opening cached copy with flags=O_WRONLY|O_CREATE|O_EXCL|O_SYNC|O_TRUNC 2020/01/19 06:03:44 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:44 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:45 DEBUG : open-test-file(0xc000363b80): close: 2020/01/19 06:03:45 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:45 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:45 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:45 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:45 INFO : open-test-file: Copied (new) 2020/01/19 06:03:45 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:45 DEBUG : open-test-file(0xc000363b80): >close: err= 2020/01/19 06:03:45 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:45 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:45 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:45 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:45 DEBUG : open-test-file: Size and modification time the same (differ by 905.552427ms, within tolerance 1s) 2020/01/19 06:03:45 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:45 DEBUG : open-test-file(0xc0007c0380): Opened existing cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:45 DEBUG : open-test-file(0xc0007c0380): close: 2020/01/19 06:03:45 DEBUG : open-test-file: Modification times differ by -1.693564455s: 2020-01-19 06:03:45.693564455 +0000 UTC, 2020-01-19 06:03:44 +0000 UTC 2020/01/19 06:03:45 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:46 INFO : open-test-file: Updated modification time in destination 2020/01/19 06:03:46 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:46 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:46 DEBUG : open-test-file(0xc0007c0380): >close: err= 2020/01/19 06:03:46 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE|O_EXCL|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:46 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE|O_EXCL|O_SYNC|O_TRUNC 2020/01/19 06:03:46 ERROR : open-test-file: File.openRW failed: file already exists 2020/01/19 06:03:46 DEBUG : open-test-file: >Open: fd=, err=file already exists 2020/01/19 06:03:46 DEBUG : open-test-file: >OpenFile: fd=, err=file already exists 2020/01/19 06:03:46 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:46 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:46 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:46 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:46 DEBUG : open-test-file: Size and modification time the same (differ by 693.564455ms, within tolerance 1s) 2020/01/19 06:03:46 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:46 DEBUG : open-test-file(0xc0005ec680): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:46 DEBUG : open-test-file(0xc0005ec680): close: 2020/01/19 06:03:46 DEBUG : open-test-file(0xc0005ec680): >close: err= 2020/01/19 06:03:46 INFO : open-test-file: Removed from cache 2020/01/19 06:03:46 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_APPEND, perm=-rw-rw-rw- 2020/01/19 06:03:46 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:03:46 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:46 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:46 DEBUG : open-test-file(0xc0005ec6c0): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:46 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:46 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:46 DEBUG : open-test-file(0xc0005ec6c0): close: 2020/01/19 06:03:46 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:46 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:46 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:47 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:47 INFO : open-test-file: Copied (new) 2020/01/19 06:03:47 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:47 DEBUG : open-test-file(0xc0005ec6c0): >close: err= 2020/01/19 06:03:47 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_APPEND, perm=-rw-rw-rw- 2020/01/19 06:03:47 DEBUG : open-test-file: Open: flags=O_WRONLY|O_APPEND 2020/01/19 06:03:47 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:47 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:47 DEBUG : open-test-file: Size and modification time the same (differ by 521.577094ms, within tolerance 1s) 2020/01/19 06:03:47 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:47 DEBUG : open-test-file(0xc000363dc0): Opened existing cached copy with flags=O_WRONLY|O_APPEND 2020/01/19 06:03:47 DEBUG : open-test-file(0xc000363dc0): close: 2020/01/19 06:03:47 DEBUG : open-test-file: Sizes differ (src 8 vs dst 5) 2020/01/19 06:03:47 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:47 DEBUG : open-test-file: Uploading segment 0/8 size 8 2020/01/19 06:03:47 DEBUG : open-test-file: SHA-1 = 4bdb719e7a59ae117ac2aa7573d9fadfd83fc7cb OK 2020/01/19 06:03:47 INFO : open-test-file: Copied (replaced existing) 2020/01/19 06:03:47 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:47 DEBUG : open-test-file(0xc000363dc0): >close: err= 2020/01/19 06:03:47 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:47 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:47 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:47 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:47 DEBUG : open-test-file: Size and modification time the same (differ by 109.586069ms, within tolerance 1s) 2020/01/19 06:03:47 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:47 DEBUG : open-test-file(0xc0007c0940): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:47 DEBUG : open-test-file(0xc0007c0940): close: 2020/01/19 06:03:47 DEBUG : open-test-file(0xc0007c0940): >close: err= 2020/01/19 06:03:48 INFO : open-test-file: Removed from cache 2020/01/19 06:03:48 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_APPEND|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:48 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:03:48 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:48 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:48 DEBUG : open-test-file(0xc000126140): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:48 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:48 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:48 DEBUG : open-test-file(0xc000126140): close: 2020/01/19 06:03:48 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:48 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:48 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:48 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:48 INFO : open-test-file: Copied (new) 2020/01/19 06:03:48 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:48 DEBUG : open-test-file(0xc000126140): >close: err= 2020/01/19 06:03:48 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_APPEND|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:48 DEBUG : open-test-file: Open: flags=O_WRONLY|O_APPEND|O_TRUNC 2020/01/19 06:03:48 DEBUG : open-test-file(0xc000126600): Opening cached copy with flags=O_WRONLY|O_APPEND|O_TRUNC 2020/01/19 06:03:48 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:48 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:48 DEBUG : open-test-file(0xc000126600): close: 2020/01/19 06:03:48 DEBUG : open-test-file: Sizes differ (src 3 vs dst 5) 2020/01/19 06:03:48 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:49 DEBUG : open-test-file: Uploading segment 0/3 size 3 2020/01/19 06:03:49 DEBUG : open-test-file: SHA-1 = 2499da6f5e54b5dfb00e20c687819f9a7cba3d62 OK 2020/01/19 06:03:49 INFO : open-test-file: Copied (replaced existing) 2020/01/19 06:03:49 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:49 DEBUG : open-test-file(0xc000126600): >close: err= 2020/01/19 06:03:49 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:49 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:49 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:49 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:49 DEBUG : open-test-file: Size and modification time the same (differ by 881.613118ms, within tolerance 1s) 2020/01/19 06:03:49 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:49 DEBUG : open-test-file(0xc000126a40): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:49 DEBUG : open-test-file(0xc000126a40): close: 2020/01/19 06:03:49 DEBUG : open-test-file(0xc000126a40): >close: err= 2020/01/19 06:03:49 INFO : open-test-file: Removed from cache 2020/01/19 06:03:49 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_APPEND|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:03:49 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:03:49 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:49 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:49 DEBUG : open-test-file(0xc000080340): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:49 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:49 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:49 DEBUG : open-test-file(0xc000080340): close: 2020/01/19 06:03:49 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:49 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:50 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:50 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:50 INFO : open-test-file: Copied (new) 2020/01/19 06:03:50 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:50 DEBUG : open-test-file(0xc000080340): >close: err= 2020/01/19 06:03:50 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_APPEND|O_SYNC, perm=-rw-rw-rw- 2020/01/19 06:03:50 DEBUG : open-test-file: Open: flags=O_WRONLY|O_APPEND|O_SYNC 2020/01/19 06:03:50 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:50 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:50 DEBUG : open-test-file: Size and modification time the same (differ by 829.627589ms, within tolerance 1s) 2020/01/19 06:03:50 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:50 DEBUG : open-test-file(0xc0003636c0): Opened existing cached copy with flags=O_WRONLY|O_APPEND|O_SYNC 2020/01/19 06:03:51 DEBUG : open-test-file(0xc0003636c0): close: 2020/01/19 06:03:51 DEBUG : open-test-file: Sizes differ (src 8 vs dst 5) 2020/01/19 06:03:51 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:51 DEBUG : open-test-file: Uploading segment 0/8 size 8 2020/01/19 06:03:51 DEBUG : open-test-file: SHA-1 = 4bdb719e7a59ae117ac2aa7573d9fadfd83fc7cb OK 2020/01/19 06:03:51 INFO : open-test-file: Copied (replaced existing) 2020/01/19 06:03:51 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:51 DEBUG : open-test-file(0xc0003636c0): >close: err= 2020/01/19 06:03:51 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:51 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:51 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:51 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:51 DEBUG : open-test-file: Size and modification time the same (differ by 453.637113ms, within tolerance 1s) 2020/01/19 06:03:51 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:51 DEBUG : open-test-file(0xc000363c40): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:51 DEBUG : open-test-file(0xc000363c40): close: 2020/01/19 06:03:51 DEBUG : open-test-file(0xc000363c40): >close: err= 2020/01/19 06:03:52 INFO : open-test-file: Removed from cache 2020/01/19 06:03:52 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_APPEND|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:52 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:03:52 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:52 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:52 DEBUG : open-test-file(0xc000363d00): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:52 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:52 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:52 DEBUG : open-test-file(0xc000363d00): close: 2020/01/19 06:03:52 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:52 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:52 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:52 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:52 INFO : open-test-file: Copied (new) 2020/01/19 06:03:52 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:52 DEBUG : open-test-file(0xc000363d00): >close: err= 2020/01/19 06:03:52 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_APPEND|O_SYNC|O_TRUNC, perm=-rw-rw-rw- 2020/01/19 06:03:52 DEBUG : open-test-file: Open: flags=O_WRONLY|O_APPEND|O_SYNC|O_TRUNC 2020/01/19 06:03:52 DEBUG : open-test-file(0xc00047e400): Opening cached copy with flags=O_WRONLY|O_APPEND|O_SYNC|O_TRUNC 2020/01/19 06:03:52 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:52 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:52 DEBUG : open-test-file(0xc00047e400): close: 2020/01/19 06:03:52 DEBUG : open-test-file: Sizes differ (src 3 vs dst 5) 2020/01/19 06:03:52 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:53 DEBUG : open-test-file: Uploading segment 0/3 size 3 2020/01/19 06:03:53 DEBUG : open-test-file: SHA-1 = 2499da6f5e54b5dfb00e20c687819f9a7cba3d62 OK 2020/01/19 06:03:53 INFO : open-test-file: Copied (replaced existing) 2020/01/19 06:03:53 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:53 DEBUG : open-test-file(0xc00047e400): >close: err= 2020/01/19 06:03:53 DEBUG : open-test-file: OpenFile: flags=O_RDONLY, perm=---------- 2020/01/19 06:03:53 DEBUG : open-test-file: Open: flags=O_RDONLY 2020/01/19 06:03:53 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:53 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:53 DEBUG : open-test-file: Size and modification time the same (differ by 653.670696ms, within tolerance 1s) 2020/01/19 06:03:53 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:53 DEBUG : open-test-file(0xc00047e800): Opened existing cached copy with flags=O_RDONLY 2020/01/19 06:03:53 DEBUG : open-test-file(0xc00047e800): close: 2020/01/19 06:03:53 DEBUG : open-test-file(0xc00047e800): >close: err= 2020/01/19 06:03:54 INFO : open-test-file: Removed from cache 2020/01/19 06:03:54 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_APPEND|O_EXCL, perm=-rw-rw-rw- 2020/01/19 06:03:54 DEBUG : open-test-file: >OpenFile: fd=, err=file does not exist 2020/01/19 06:03:54 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/01/19 06:03:54 DEBUG : open-test-file: Open: flags=O_WRONLY|O_CREATE 2020/01/19 06:03:54 DEBUG : open-test-file(0xc000171440): Opening cached copy with flags=O_WRONLY|O_CREATE 2020/01/19 06:03:54 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:54 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:54 DEBUG : open-test-file(0xc000171440): close: 2020/01/19 06:03:54 DEBUG : open-test-file: Need to transfer - File not found at Destination 2020/01/19 06:03:54 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:54 DEBUG : open-test-file: Uploading segment 0/5 size 5 2020/01/19 06:03:54 DEBUG : open-test-file: SHA-1 = aaf4c61ddcc5e8a2dabede0f3b482cd9aea9434d OK 2020/01/19 06:03:54 INFO : open-test-file: Copied (new) 2020/01/19 06:03:54 DEBUG : open-test-file: transferred to remote 2020/01/19 06:03:54 DEBUG : open-test-file(0xc000171440): >close: err= 2020/01/19 06:03:54 DEBUG : open-test-file: OpenFile: flags=O_WRONLY|O_APPEND|O_EXCL, perm=-rw-rw-rw- 2020/01/19 06:03:54 DEBUG : open-test-file: Open: flags=O_WRONLY|O_APPEND|O_EXCL 2020/01/19 06:03:54 DEBUG : open-test-file: >Open: fd=open-test-file (rw), err= 2020/01/19 06:03:54 DEBUG : open-test-file: >OpenFile: fd=open-test-file (rw), err= 2020/01/19 06:03:54 DEBUG : open-test-file: Size and modification time the same (differ by 41.691883ms, within tolerance 1s) 2020/01/19 06:03:54 DEBUG : open-test-file: Unchanged skipping 2020/01/19 06:03:54 DEBUG : open-test-file(0xc0007c0180): Opened existing cached copy with flags=O_WRONLY|O_APPEND|O_EXCL 2020/01/19 06:03:54 DEBUG : open-test-file(0xc0007c0180): close: 2020/01/19 06:03:54 DEBUG : open-test-file: Sizes differ (src 8 vs dst 5) 2020/01/19 06:03:54 DEBUG : open-test-file: Starting multipart upload 2020/01/19 06:03:55 DEBUG : open-test-file: Uploading segment 0/8 size 8 2020/01/19 06:03:55 DEBUG : open-test-file: Error encountered during upload: resourceModified: ETag does not match current item's value 2020/01/19 06:03:55 DEBUG : open-test-file: Cancelling multipart upload 2020/01/19 06:03:55 ERROR : open-test-file: Failed to copy: resourceModified: ETag does not match current item's value 2020/01/19 06:03:55 ERROR : open-test-file(0xc0007c0180): failed to transfer file from cache to remote: resourceModified: ETag does not match current item's value 2020/01/19 06:03:55 DEBUG : open-test-file(0xc0007c0180): >close: err=failed to transfer file from cache to remote: resourceModified: ETag does not match current item's value 2020/01/19 06:03:55 DEBUG : cache cleaner exiting --- FAIL: TestRWFileHandleOpenTests (81.80s) run.go:176: Remote "One drive root 'rclone-test-jefitaz6luwiyuk6lolehom0'", Local "Local file system at /tmp/rclone076305184", Modify Window "1s" read_write_test.go:633: Error Trace: read_write_test.go:633 read_write_test.go:669 Error: Received unexpected error: resourceModified: ETag does not match current item's value failed to transfer file from cache to remote github.com/rclone/rclone/vfs.(*RWFileHandle).flushWrites /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write.go:294 github.com/rclone/rclone/vfs.(*RWFileHandle).close /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write.go:328 github.com/rclone/rclone/vfs.(*RWFileHandle).Close /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write.go:335 github.com/rclone/rclone/vfs.testRWFileHandleOpenTest /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write_test.go:632 github.com/rclone/rclone/vfs.TestRWFileHandleOpenTests /home/rclone/go/src/github.com/rclone/rclone/vfs/read_write_test.go:669 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_WRONLY|os.O_APPEND|os.O_EXCL FAIL 2020/01/19 06:03:56 DEBUG : One drive root 'rclone-test-jefitaz6luwiyuk6lolehom0': Purge remote "./vfs.test -test.v -test.timeout 30m0s -remote TestOneDrive: -verbose -test.run '^TestRWFileHandleOpenTests$'" - Finished ERROR in 1m24.50118286s (try 4/5): exit status 1: Failed [TestRWFileHandleOpenTests]