"./sync.test -test.v -test.timeout 1h0m0s -remote TestOneDriveBusiness: -verbose" - Starting (try 1/5) 2022/04/20 05:42:39 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5" 2022/04/20 05:42:39 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2022/04/20 05:42:40 DEBUG : Creating backend with remote "/tmp/rclone1468494239" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.02s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:42:42 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2022/04/20 05:42:42 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:42:42 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish --- PASS: TestCopyWithDryRun (3.18s) === RUN TestCopy run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:42:44 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:42:44 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:42:45 DEBUG : sub dir/hello world: Starting multipart upload 2022/04/20 05:42:46 DEBUG : sub dir/hello world: Uploading segment 0/11 size 11 2022/04/20 05:42:48 DEBUG : sub dir/hello world: quickxor = 6828031bd8f00610dce10d726b03190000000000 OK 2022/04/20 05:42:48 INFO : sub dir/hello world: Copied (new) --- PASS: TestCopy (8.46s) === RUN TestCopyMissingDirectory run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:42:52 DEBUG : Creating backend with remote "/non-existing" 2022/04/20 05:42:53 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2022/04/20 05:42:53 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:42:53 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish --- PASS: TestCopyMissingDirectory (1.78s) === RUN TestCopyNoTraverse run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:42:55 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:42:55 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:42:56 DEBUG : sub dir/hello world: Starting multipart upload 2022/04/20 05:42:57 DEBUG : sub dir/hello world: Uploading segment 0/11 size 11 2022/04/20 05:42:58 DEBUG : sub dir/hello world: quickxor = 6828031bd8f00610dce10d726b03190000000000 OK 2022/04/20 05:42:58 INFO : sub dir/hello world: Copied (new) --- PASS: TestCopyNoTraverse (7.52s) === RUN TestCopyCheckFirst run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:43:01 INFO : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Running all checks before starting transfers 2022/04/20 05:43:02 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:43:02 INFO : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Checks finished, now starting transfers 2022/04/20 05:43:02 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:43:03 DEBUG : sub dir/hello world: Starting multipart upload 2022/04/20 05:43:04 DEBUG : sub dir/hello world: Uploading segment 0/11 size 11 2022/04/20 05:43:04 DEBUG : sub dir/hello world: quickxor = 6828031bd8f00610dce10d726b03190000000000 OK 2022/04/20 05:43:04 INFO : sub dir/hello world: Copied (new) --- PASS: TestCopyCheckFirst (6.03s) === RUN TestSyncNoTraverse run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:43:07 ERROR : Ignoring --no-traverse with sync 2022/04/20 05:43:08 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:43:08 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:43:09 DEBUG : sub dir/hello world: Starting multipart upload 2022/04/20 05:43:09 DEBUG : sub dir/hello world: Uploading segment 0/11 size 11 2022/04/20 05:43:10 DEBUG : sub dir/hello world: quickxor = 6828031bd8f00610dce10d726b03190000000000 OK 2022/04/20 05:43:10 INFO : sub dir/hello world: Copied (new) 2022/04/20 05:43:10 DEBUG : Waiting for deletions to finish --- PASS: TestSyncNoTraverse (5.71s) === RUN TestCopyWithDepth run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:43:14 DEBUG : hello world2: Starting multipart upload 2022/04/20 05:43:14 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:43:14 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:43:14 DEBUG : hello world2: Uploading segment 0/12 size 12 2022/04/20 05:43:15 DEBUG : hello world2: quickxor = 6828031bd8f00610dce10d726c03196400000000 OK 2022/04/20 05:43:15 INFO : hello world2: Copied (new) --- PASS: TestCopyWithDepth (4.01s) === RUN TestCopyWithFilesFrom run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:43:17 DEBUG : hello world2: Excluded 2022/04/20 05:43:18 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:43:18 DEBUG : potato2: Starting multipart upload 2022/04/20 05:43:18 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:43:18 DEBUG : potato2: Uploading segment 0/11 size 11 2022/04/20 05:43:19 DEBUG : potato2: quickxor = 6828031bd8f00610dce10d726b03190000000000 OK 2022/04/20 05:43:19 INFO : potato2: Copied (new) --- PASS: TestCopyWithFilesFrom (3.38s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:43:21 DEBUG : potato2: Starting multipart upload 2022/04/20 05:43:21 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:43:21 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:43:22 DEBUG : potato2: Uploading segment 0/11 size 11 2022/04/20 05:43:23 DEBUG : potato2: quickxor = 6828031bd8f00610dce10d726b03190000000000 OK 2022/04/20 05:43:23 INFO : potato2: Copied (new) --- PASS: TestCopyWithFilesFromAndNoTraverse (3.07s) === RUN TestCopyEmptyDirectories run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:43:24 DEBUG : sub dir2: Making directory 2022/04/20 05:43:24 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:43:24 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:43:25 DEBUG : sub dir/hello world: Starting multipart upload 2022/04/20 05:43:25 DEBUG : sub dir/hello world: Uploading segment 0/11 size 11 2022/04/20 05:43:26 DEBUG : sub dir/hello world: quickxor = 6828031bd8f00610dce10d726b03190000000000 OK 2022/04/20 05:43:26 INFO : sub dir/hello world: Copied (new) 2022/04/20 05:43:26 DEBUG : sub dir2: Making directory 2022/04/20 05:43:26 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': copied 1 directories --- PASS: TestCopyEmptyDirectories (6.19s) === RUN TestMoveEmptyDirectories run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:43:30 DEBUG : sub dir2: Making directory 2022/04/20 05:43:30 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:43:30 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:43:31 DEBUG : sub dir/hello world: Starting multipart upload 2022/04/20 05:43:31 DEBUG : sub dir/hello world: Uploading segment 0/11 size 11 2022/04/20 05:43:32 DEBUG : sub dir/hello world: quickxor = 6828031bd8f00610dce10d726b03190000000000 OK 2022/04/20 05:43:32 INFO : sub dir/hello world: Copied (new) 2022/04/20 05:43:32 INFO : sub dir/hello world: Deleted 2022/04/20 05:43:32 DEBUG : sub dir: Making directory 2022/04/20 05:43:32 DEBUG : sub dir2: Making directory 2022/04/20 05:43:33 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': copied 2 directories --- PASS: TestMoveEmptyDirectories (7.91s) === RUN TestSyncEmptyDirectories run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:43:38 DEBUG : sub dir2: Making directory 2022/04/20 05:43:38 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:43:38 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:43:39 DEBUG : sub dir/hello world: Starting multipart upload 2022/04/20 05:43:40 DEBUG : sub dir/hello world: Uploading segment 0/11 size 11 2022/04/20 05:43:41 DEBUG : sub dir/hello world: quickxor = 6828031bd8f00610dce10d726b03190000000000 OK 2022/04/20 05:43:41 INFO : sub dir/hello world: Copied (new) 2022/04/20 05:43:41 DEBUG : sub dir2: Making directory 2022/04/20 05:43:42 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': copied 1 directories 2022/04/20 05:43:42 DEBUG : Waiting for deletions to finish --- PASS: TestSyncEmptyDirectories (8.55s) === RUN TestServerSideCopy run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:43:48 DEBUG : sub dir/hello world: Starting multipart upload 2022/04/20 05:43:48 DEBUG : sub dir/hello world: Uploading segment 0/11 size 11 2022/04/20 05:43:50 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-larevuh1hocokeb0xasiyoh8" sync_test.go:275: Server side copy (if possible) One drive root 'rclone-test-zirepet0zatoguz5parosak5' -> One drive root 'rclone-test-larevuh1hocokeb0xasiyoh8' 2022/04/20 05:43:52 DEBUG : One drive root 'rclone-test-larevuh1hocokeb0xasiyoh8': Waiting for checks to finish 2022/04/20 05:43:52 DEBUG : One drive root 'rclone-test-larevuh1hocokeb0xasiyoh8': Waiting for transfers to finish 2022/04/20 05:43:55 ERROR : sub dir/hello world: Failed to copy: nameAlreadyExists: The specified item name already exists. sync_test.go:278: Error Trace: sync_test.go:278 Error: Received unexpected error: nameAlreadyExists: The specified item name already exists. Test: TestServerSideCopy 2022/04/20 05:43:55 DEBUG : One drive root 'rclone-test-larevuh1hocokeb0xasiyoh8': Purge remote --- FAIL: TestServerSideCopy (12.70s) === RUN TestCopyAfterDelete run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:44:00 DEBUG : sub dir/hello world: Starting multipart upload 2022/04/20 05:44:01 DEBUG : sub dir/hello world: Uploading segment 0/11 size 11 2022/04/20 05:44:02 ERROR : : error listing: directory not found 2022/04/20 05:44:02 DEBUG : Local file system at /tmp/rclone1468494239: Making directory 2022/04/20 05:44:03 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:44:03 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish --- PASS: TestCopyAfterDelete (7.59s) === RUN TestCopyRedownload run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:44:07 DEBUG : sub dir/hello world: Starting multipart upload 2022/04/20 05:44:08 DEBUG : sub dir/hello world: Uploading segment 0/11 size 11 2022/04/20 05:44:11 DEBUG : Local file system at /tmp/rclone1468494239: Waiting for checks to finish 2022/04/20 05:44:11 DEBUG : Local file system at /tmp/rclone1468494239: Waiting for transfers to finish 2022/04/20 05:44:12 DEBUG : sub dir/hello world: quickxor = 6828031bd8f00610dce10d726b03190000000000 OK 2022/04/20 05:44:12 INFO : sub dir/hello world: Copied (new) --- PASS: TestCopyRedownload (7.89s) === RUN TestSyncBasedOnCheckSum run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:44:15 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:44:15 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:44:15 DEBUG : check sum: Starting multipart upload 2022/04/20 05:44:16 DEBUG : check sum: Uploading segment 0/1 size 1 2022/04/20 05:44:16 DEBUG : check sum: quickxor = 2d00000000000000000000000100000000000000 OK 2022/04/20 05:44:16 INFO : check sum: Copied (new) 2022/04/20 05:44:16 DEBUG : Waiting for deletions to finish 2022/04/20 05:44:17 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:44:17 DEBUG : check sum: quickxor = 2d00000000000000000000000100000000000000 OK 2022/04/20 05:44:17 DEBUG : check sum: Size and quickxor of src and dst objects identical 2022/04/20 05:44:17 DEBUG : check sum: Unchanged skipping 2022/04/20 05:44:17 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:44:17 DEBUG : Waiting for deletions to finish 2022/04/20 05:44:17 INFO : There was nothing to transfer --- PASS: TestSyncBasedOnCheckSum (4.72s) === RUN TestSyncSizeOnly run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:44:20 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:44:20 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:44:20 DEBUG : sizeonly: Starting multipart upload 2022/04/20 05:44:21 DEBUG : sizeonly: Uploading segment 0/6 size 6 2022/04/20 05:44:21 DEBUG : sizeonly: quickxor = 7078031dc2408737000000000600000000000000 OK 2022/04/20 05:44:21 INFO : sizeonly: Copied (new) 2022/04/20 05:44:21 DEBUG : Waiting for deletions to finish 2022/04/20 05:44:22 DEBUG : sizeonly: Sizes identical 2022/04/20 05:44:22 DEBUG : sizeonly: Unchanged skipping 2022/04/20 05:44:22 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:44:22 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:44:22 DEBUG : Waiting for deletions to finish 2022/04/20 05:44:22 INFO : There was nothing to transfer --- PASS: TestSyncSizeOnly (4.48s) === RUN TestSyncIgnoreSize run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:44:24 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:44:24 DEBUG : ignore-size: Starting multipart upload 2022/04/20 05:44:24 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:44:25 DEBUG : ignore-size: Uploading segment 0/8 size 8 2022/04/20 05:44:25 DEBUG : ignore-size: quickxor = 6378831be8500637d0610e000800000000000000 OK 2022/04/20 05:44:25 INFO : ignore-size: Copied (new) 2022/04/20 05:44:25 DEBUG : Waiting for deletions to finish 2022/04/20 05:44:26 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:44:26 DEBUG : ignore-size: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:44:26 DEBUG : ignore-size: Unchanged skipping 2022/04/20 05:44:26 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:44:26 DEBUG : Waiting for deletions to finish 2022/04/20 05:44:26 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreSize (4.52s) === RUN TestSyncIgnoreTimes run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:44:28 DEBUG : existing: Starting multipart upload 2022/04/20 05:44:29 DEBUG : existing: Uploading segment 0/6 size 6 2022/04/20 05:44:30 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:44:30 DEBUG : existing: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:44:30 DEBUG : existing: Unchanged skipping 2022/04/20 05:44:30 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:44:30 DEBUG : Waiting for deletions to finish 2022/04/20 05:44:30 INFO : There was nothing to transfer 2022/04/20 05:44:30 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:44:30 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2022/04/20 05:44:30 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:44:30 DEBUG : existing: Starting multipart upload 2022/04/20 05:44:31 DEBUG : existing: Uploading segment 0/6 size 6 2022/04/20 05:44:32 DEBUG : existing: quickxor = 7078031dc2408737000000000600000000000000 OK 2022/04/20 05:44:32 INFO : existing: Copied (replaced existing) 2022/04/20 05:44:32 DEBUG : Waiting for deletions to finish --- PASS: TestSyncIgnoreTimes (5.11s) === RUN TestSyncIgnoreExisting run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:44:34 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:44:34 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:44:34 DEBUG : existing: Starting multipart upload 2022/04/20 05:44:35 DEBUG : existing: Uploading segment 0/6 size 6 2022/04/20 05:44:35 DEBUG : existing: quickxor = 7078031dc2408737000000000600000000000000 OK 2022/04/20 05:44:35 INFO : existing: Copied (new) 2022/04/20 05:44:35 DEBUG : Waiting for deletions to finish 2022/04/20 05:44:36 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:44:36 DEBUG : existing: Destination exists, skipping 2022/04/20 05:44:36 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:44:36 DEBUG : Waiting for deletions to finish 2022/04/20 05:44:36 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreExisting (4.06s) === RUN TestSyncIgnoreErrors run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:44:38 DEBUG : b/potato: Starting multipart upload 2022/04/20 05:44:39 DEBUG : b/potato: Uploading segment 0/21 size 21 2022/04/20 05:44:41 DEBUG : c/non empty space: Starting multipart upload 2022/04/20 05:44:41 DEBUG : c/non empty space: Uploading segment 0/5 size 5 2022/04/20 05:44:42 DEBUG : d: Making directory 2022/04/20 05:44:45 DEBUG : c/non empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 05:44:45 DEBUG : c/non empty space: Unchanged skipping 2022/04/20 05:44:45 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:44:45 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:44:45 DEBUG : a/potato2: Starting multipart upload 2022/04/20 05:44:46 DEBUG : a/potato2: Uploading segment 0/60 size 60 2022/04/20 05:44:46 DEBUG : a/potato2: quickxor = 4001dad296b6b4a52d6d694b67dad296b6b4a52d OK 2022/04/20 05:44:46 INFO : a/potato2: Copied (new) 2022/04/20 05:44:46 DEBUG : Waiting for deletions to finish 2022/04/20 05:44:47 INFO : b/potato: Deleted 2022/04/20 05:44:47 INFO : d: Removing directory 2022/04/20 05:44:47 INFO : b: Removing directory 2022/04/20 05:44:48 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': deleted 2 directories --- PASS: TestSyncIgnoreErrors (14.36s) === RUN TestSyncAfterChangingModtimeOnly run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:44:52 DEBUG : empty space: Starting multipart upload 2022/04/20 05:44:52 DEBUG : empty space: Uploading segment 0/1 size 1 2022/04/20 05:44:54 DEBUG : empty space: Modification times differ by -95456h54m53.123456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06 +0000 UTC 2022/04/20 05:44:54 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:44:54 DEBUG : empty space: quickxor = 2d00000000000000000000000100000000000000 OK 2022/04/20 05:44:54 NOTICE: empty space: Skipped update modification time as --dry-run is set (size 1) 2022/04/20 05:44:54 DEBUG : empty space: Unchanged skipping 2022/04/20 05:44:54 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:44:54 DEBUG : Waiting for deletions to finish 2022/04/20 05:44:54 INFO : There was nothing to transfer 2022/04/20 05:44:54 DEBUG : empty space: Modification times differ by -95456h54m53.123456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06 +0000 UTC 2022/04/20 05:44:54 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:44:54 DEBUG : empty space: quickxor = 2d00000000000000000000000100000000000000 OK 2022/04/20 05:44:55 INFO : empty space: Updated modification time in destination 2022/04/20 05:44:55 DEBUG : empty space: Unchanged skipping 2022/04/20 05:44:55 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:44:55 DEBUG : Waiting for deletions to finish 2022/04/20 05:44:55 INFO : There was nothing to transfer --- PASS: TestSyncAfterChangingModtimeOnly (4.13s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:44:56 DEBUG : empty space: Starting multipart upload 2022/04/20 05:44:57 DEBUG : empty space: Uploading segment 0/1 size 1 2022/04/20 05:44:58 DEBUG : empty space: Modification times differ by -95456h54m53.123456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06 +0000 UTC 2022/04/20 05:44:58 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:44:58 DEBUG : empty space: quickxor = 2d00000000000000000000000100000000000000 OK 2022/04/20 05:44:58 DEBUG : empty space: Unchanged skipping 2022/04/20 05:44:58 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:44:58 DEBUG : Waiting for deletions to finish 2022/04/20 05:44:58 INFO : There was nothing to transfer --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (3.97s) === RUN TestSyncDoesntUpdateModtime run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:45:00 DEBUG : foo: Starting multipart upload 2022/04/20 05:45:00 DEBUG : foo: Uploading segment 0/3 size 3 2022/04/20 05:45:02 DEBUG : foo: Modification times differ by -95456h54m53.123456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06 +0000 UTC 2022/04/20 05:45:02 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:45:02 DEBUG : foo: quickxor = 6678c31b00000000000000000300000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:45:02 DEBUG : foo: quickxor = 6208831c00000000000000000300000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:45:02 DEBUG : foo: quickxor differ 2022/04/20 05:45:02 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:45:02 DEBUG : foo: Starting multipart upload 2022/04/20 05:45:02 DEBUG : foo: Uploading segment 0/3 size 3 2022/04/20 05:45:03 DEBUG : foo: quickxor = 6678c31b00000000000000000300000000000000 OK 2022/04/20 05:45:03 INFO : foo: Copied (replaced existing) 2022/04/20 05:45:03 DEBUG : Waiting for deletions to finish --- PASS: TestSyncDoesntUpdateModtime (4.00s) === RUN TestSyncAfterAddingAFile run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:45:04 DEBUG : empty space: Starting multipart upload 2022/04/20 05:45:04 DEBUG : empty space: Uploading segment 0/1 size 1 2022/04/20 05:45:06 DEBUG : potato: Starting multipart upload 2022/04/20 05:45:06 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 05:45:06 DEBUG : empty space: Unchanged skipping 2022/04/20 05:45:06 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:45:06 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:45:06 DEBUG : potato: Uploading segment 0/60 size 60 2022/04/20 05:45:07 DEBUG : potato: quickxor = 4001dad296b6b4a52d6d694b67dad296b6b4a52d OK 2022/04/20 05:45:07 INFO : potato: Copied (new) 2022/04/20 05:45:07 DEBUG : Waiting for deletions to finish --- PASS: TestSyncAfterAddingAFile (4.82s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:45:09 DEBUG : potato: Starting multipart upload 2022/04/20 05:45:09 DEBUG : potato: Uploading segment 0/60 size 60 2022/04/20 05:45:11 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:45:11 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2022/04/20 05:45:11 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:45:11 DEBUG : potato: Starting multipart upload 2022/04/20 05:45:11 DEBUG : potato: Uploading segment 0/21 size 21 2022/04/20 05:45:12 DEBUG : potato: quickxor = d26463389bd86e62ce010462bd031d40308730b4 OK 2022/04/20 05:45:12 INFO : potato: Copied (replaced existing) 2022/04/20 05:45:12 DEBUG : Waiting for deletions to finish --- PASS: TestSyncAfterChangingFilesSizeOnly (4.61s) === RUN TestSyncAfterChangingContentsOnly run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:45:13 DEBUG : potato: Starting multipart upload 2022/04/20 05:45:14 DEBUG : potato: Uploading segment 0/21 size 21 2022/04/20 05:45:15 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC 2022/04/20 05:45:15 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:45:15 DEBUG : potato: quickxor = f2606230dad02c724c010442bd02154030852034 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:45:15 DEBUG : potato: quickxor = d26463389bd86e62ce010462bd031d40308730b4 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:45:15 DEBUG : potato: quickxor differ 2022/04/20 05:45:15 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:45:15 DEBUG : potato: Starting multipart upload 2022/04/20 05:45:15 DEBUG : potato: Uploading segment 0/21 size 21 2022/04/20 05:45:16 DEBUG : potato: quickxor = f2606230dad02c724c010442bd02154030852034 OK 2022/04/20 05:45:16 INFO : potato: Copied (replaced existing) 2022/04/20 05:45:16 DEBUG : Waiting for deletions to finish --- PASS: TestSyncAfterChangingContentsOnly (3.58s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:45:17 DEBUG : potato: Starting multipart upload 2022/04/20 05:45:17 DEBUG : potato: Uploading segment 0/21 size 21 2022/04/20 05:45:18 DEBUG : empty space: Starting multipart upload 2022/04/20 05:45:19 DEBUG : empty space: Uploading segment 0/1 size 1 2022/04/20 05:45:20 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2022/04/20 05:45:20 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:45:20 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 05:45:20 DEBUG : empty space: Unchanged skipping 2022/04/20 05:45:20 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:45:20 DEBUG : Waiting for deletions to finish 2022/04/20 05:45:20 NOTICE: potato: Skipped delete as --dry-run is set (size 21) --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (4.66s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:45:21 DEBUG : potato: Starting multipart upload 2022/04/20 05:45:22 DEBUG : potato: Uploading segment 0/21 size 21 2022/04/20 05:45:23 DEBUG : empty space: Starting multipart upload 2022/04/20 05:45:23 DEBUG : empty space: Uploading segment 0/1 size 1 2022/04/20 05:45:24 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:45:24 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 05:45:24 DEBUG : empty space: Unchanged skipping 2022/04/20 05:45:24 DEBUG : potato2: Starting multipart upload 2022/04/20 05:45:24 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:45:25 DEBUG : potato2: Uploading segment 0/60 size 60 2022/04/20 05:45:26 DEBUG : potato2: quickxor = 4001dad296b6b4a52d6d694b67dad296b6b4a52d OK 2022/04/20 05:45:26 INFO : potato2: Copied (new) 2022/04/20 05:45:26 DEBUG : Waiting for deletions to finish 2022/04/20 05:45:26 INFO : potato: Deleted --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (5.83s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:45:28 DEBUG : b/potato: Starting multipart upload 2022/04/20 05:45:29 DEBUG : b/potato: Uploading segment 0/21 size 21 2022/04/20 05:45:30 DEBUG : c/non empty space: Starting multipart upload 2022/04/20 05:45:31 DEBUG : c/non empty space: Uploading segment 0/5 size 5 2022/04/20 05:45:31 DEBUG : d: Making directory 2022/04/20 05:45:32 DEBUG : d/e: Making directory 2022/04/20 05:45:34 DEBUG : c/non empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 05:45:34 DEBUG : c/non empty space: Unchanged skipping 2022/04/20 05:45:34 DEBUG : a/potato2: Starting multipart upload 2022/04/20 05:45:34 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:45:34 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:45:35 DEBUG : a/potato2: Uploading segment 0/60 size 60 2022/04/20 05:45:36 DEBUG : a/potato2: quickxor = 4001dad296b6b4a52d6d694b67dad296b6b4a52d OK 2022/04/20 05:45:36 INFO : a/potato2: Copied (new) 2022/04/20 05:45:36 DEBUG : Waiting for deletions to finish 2022/04/20 05:45:36 INFO : b/potato: Deleted 2022/04/20 05:45:36 INFO : d/e: Removing directory 2022/04/20 05:45:37 INFO : d: Removing directory 2022/04/20 05:45:38 INFO : b: Removing directory 2022/04/20 05:45:38 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': deleted 3 directories --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (13.43s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:45:41 DEBUG : b/potato: Starting multipart upload 2022/04/20 05:45:42 DEBUG : b/potato: Uploading segment 0/21 size 21 2022/04/20 05:45:43 DEBUG : c/non empty space: Starting multipart upload 2022/04/20 05:45:44 DEBUG : c/non empty space: Uploading segment 0/5 size 5 2022/04/20 05:45:44 DEBUG : d: Making directory 2022/04/20 05:45:47 DEBUG : c/non empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 05:45:47 DEBUG : c/non empty space: Unchanged skipping 2022/04/20 05:45:48 DEBUG : a/potato2: Starting multipart upload 2022/04/20 05:45:48 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:45:48 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:45:48 DEBUG : a/potato2: Uploading segment 0/60 size 60 2022/04/20 05:45:49 DEBUG : a/potato2: quickxor = 4001dad296b6b4a52d6d694b67dad296b6b4a52d OK 2022/04/20 05:45:49 INFO : a/potato2: Copied (new) 2022/04/20 05:45:49 ERROR : One drive root 'rclone-test-zirepet0zatoguz5parosak5': not deleting files as there were IO errors 2022/04/20 05:45:49 ERROR : One drive root 'rclone-test-zirepet0zatoguz5parosak5': not deleting directories as there were IO errors --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (12.25s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:45:53 DEBUG : potato: Starting multipart upload 2022/04/20 05:45:54 DEBUG : potato: Uploading segment 0/21 size 21 2022/04/20 05:45:54 DEBUG : empty space: Starting multipart upload 2022/04/20 05:45:55 DEBUG : empty space: Uploading segment 0/1 size 1 2022/04/20 05:45:56 DEBUG : Waiting for deletions to finish 2022/04/20 05:45:56 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:45:56 DEBUG : potato2: Starting multipart upload 2022/04/20 05:45:56 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 05:45:56 DEBUG : empty space: Unchanged skipping 2022/04/20 05:45:56 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:45:57 INFO : potato: Deleted 2022/04/20 05:45:57 DEBUG : potato2: Uploading segment 0/60 size 60 2022/04/20 05:45:57 DEBUG : potato2: quickxor = 4001dad296b6b4a52d6d694b67dad296b6b4a52d OK 2022/04/20 05:45:57 INFO : potato2: Copied (new) --- PASS: TestSyncDeleteDuring (5.65s) === RUN TestSyncDeleteBefore run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:45:59 DEBUG : potato: Starting multipart upload 2022/04/20 05:45:59 DEBUG : potato: Uploading segment 0/21 size 21 2022/04/20 05:46:00 DEBUG : empty space: Starting multipart upload 2022/04/20 05:46:01 DEBUG : empty space: Uploading segment 0/1 size 1 2022/04/20 05:46:02 DEBUG : Waiting for deletions to finish 2022/04/20 05:46:03 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:46:03 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:46:03 INFO : potato: Deleted 2022/04/20 05:46:04 DEBUG : potato2: Starting multipart upload 2022/04/20 05:46:04 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 05:46:04 DEBUG : empty space: Unchanged skipping 2022/04/20 05:46:04 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:46:04 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:46:04 DEBUG : potato2: Uploading segment 0/60 size 60 2022/04/20 05:46:05 DEBUG : potato2: quickxor = 4001dad296b6b4a52d6d694b67dad296b6b4a52d OK 2022/04/20 05:46:05 INFO : potato2: Copied (new) --- PASS: TestSyncDeleteBefore (8.73s) === RUN TestCopyDeleteBefore run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:46:07 DEBUG : potato: Starting multipart upload 2022/04/20 05:46:08 DEBUG : potato: Uploading segment 0/21 size 21 2022/04/20 05:46:10 DEBUG : potato2: Starting multipart upload 2022/04/20 05:46:10 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:46:10 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:46:11 DEBUG : potato2: Uploading segment 0/19 size 19 2022/04/20 05:46:11 DEBUG : potato2: quickxor = e9742354497b863ab0810d7913c118de00873494 OK 2022/04/20 05:46:11 INFO : potato2: Copied (new) --- PASS: TestCopyDeleteBefore (5.84s) === RUN TestSyncWithExclude run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:46:13 DEBUG : potato2: Starting multipart upload 2022/04/20 05:46:14 DEBUG : potato2: Uploading segment 0/60 size 60 2022/04/20 05:46:15 DEBUG : empty space: Starting multipart upload 2022/04/20 05:46:16 DEBUG : empty space: Uploading segment 0/1 size 1 2022/04/20 05:46:17 DEBUG : enormous: Excluded 2022/04/20 05:46:17 DEBUG : potato2: Excluded 2022/04/20 05:46:17 DEBUG : potato2: Excluded 2022/04/20 05:46:17 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 05:46:17 DEBUG : empty space: Unchanged skipping 2022/04/20 05:46:17 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:46:17 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:46:17 DEBUG : Waiting for deletions to finish 2022/04/20 05:46:17 INFO : There was nothing to transfer 2022/04/20 05:46:17 DEBUG : enormous: Excluded 2022/04/20 05:46:17 DEBUG : potato2: Excluded 2022/04/20 05:46:18 DEBUG : potato2: Excluded 2022/04/20 05:46:18 DEBUG : empty space: Size and modification time the same (differ by 123.456789ms, within tolerance 1s) 2022/04/20 05:46:18 DEBUG : empty space: Unchanged skipping 2022/04/20 05:46:18 DEBUG : Local file system at /tmp/rclone1468494239: Waiting for checks to finish 2022/04/20 05:46:18 DEBUG : Local file system at /tmp/rclone1468494239: Waiting for transfers to finish 2022/04/20 05:46:18 DEBUG : Waiting for deletions to finish 2022/04/20 05:46:18 INFO : There was nothing to transfer --- PASS: TestSyncWithExclude (6.46s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:46:20 DEBUG : potato2: Starting multipart upload 2022/04/20 05:46:20 DEBUG : potato2: Uploading segment 0/60 size 60 2022/04/20 05:46:21 DEBUG : empty space: Starting multipart upload 2022/04/20 05:46:22 DEBUG : empty space: Uploading segment 0/1 size 1 2022/04/20 05:46:23 DEBUG : enormous: Starting multipart upload 2022/04/20 05:46:24 DEBUG : enormous: Uploading segment 0/100 size 100 2022/04/20 05:46:25 DEBUG : enormous: Excluded 2022/04/20 05:46:25 DEBUG : potato2: Excluded 2022/04/20 05:46:25 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 05:46:25 DEBUG : empty space: Unchanged skipping 2022/04/20 05:46:25 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:46:25 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:46:25 DEBUG : Waiting for deletions to finish 2022/04/20 05:46:26 INFO : potato2: Deleted 2022/04/20 05:46:26 INFO : enormous: Deleted 2022/04/20 05:46:26 INFO : There was nothing to transfer 2022/04/20 05:46:27 DEBUG : empty space: Size and modification time the same (differ by 123.456789ms, within tolerance 1s) 2022/04/20 05:46:27 DEBUG : empty space: Unchanged skipping 2022/04/20 05:46:27 DEBUG : Local file system at /tmp/rclone1468494239: Waiting for checks to finish 2022/04/20 05:46:27 DEBUG : Local file system at /tmp/rclone1468494239: Waiting for transfers to finish 2022/04/20 05:46:27 DEBUG : Waiting for deletions to finish 2022/04/20 05:46:27 INFO : enormous: Deleted 2022/04/20 05:46:27 INFO : potato2: Deleted 2022/04/20 05:46:27 INFO : There was nothing to transfer --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.91s) === RUN TestSyncWithUpdateOlder run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:46:28 DEBUG : one: Starting multipart upload 2022/04/20 05:46:29 DEBUG : one: Uploading segment 0/3 size 3 2022/04/20 05:46:29 DEBUG : two: Starting multipart upload 2022/04/20 05:46:30 DEBUG : two: Uploading segment 0/3 size 3 2022/04/20 05:46:30 DEBUG : three: Starting multipart upload 2022/04/20 05:46:31 DEBUG : three: Uploading segment 0/5 size 5 2022/04/20 05:46:32 DEBUG : four: Starting multipart upload 2022/04/20 05:46:33 DEBUG : four: Uploading segment 0/8 size 8 2022/04/20 05:46:35 DEBUG : one: Destination is newer than source, skipping 2022/04/20 05:46:35 DEBUG : four: Sizes differ (src 4 vs dst 8) 2022/04/20 05:46:35 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:46:35 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2022/04/20 05:46:35 DEBUG : three: Sizes identical 2022/04/20 05:46:35 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2022/04/20 05:46:35 DEBUG : five: Starting multipart upload 2022/04/20 05:46:35 DEBUG : four: Starting multipart upload 2022/04/20 05:46:35 DEBUG : two: quickxor = 74b8c31b00000000000000000300000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:46:35 DEBUG : two: quickxor = 54b8c21300000000000000000300000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:46:35 DEBUG : two: quickxor differ 2022/04/20 05:46:35 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:46:35 DEBUG : two: Starting multipart upload 2022/04/20 05:46:35 DEBUG : five: Uploading segment 0/4 size 4 2022/04/20 05:46:35 DEBUG : two: Uploading segment 0/3 size 3 2022/04/20 05:46:35 DEBUG : four: Uploading segment 0/4 size 4 2022/04/20 05:46:36 DEBUG : five: quickxor = 6648831dca000000000000000400000000000000 OK 2022/04/20 05:46:36 INFO : five: Copied (new) 2022/04/20 05:46:36 DEBUG : two: quickxor = 74b8c31b00000000000000000300000000000000 OK 2022/04/20 05:46:36 INFO : two: Copied (replaced existing) 2022/04/20 05:46:36 DEBUG : four: quickxor = 6678431de4000000000000000400000000000000 OK 2022/04/20 05:46:36 INFO : four: Copied (replaced existing) 2022/04/20 05:46:36 DEBUG : Waiting for deletions to finish 2022/04/20 05:46:37 DEBUG : one: Destination is newer than source, skipping 2022/04/20 05:46:37 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:46:37 DEBUG : five: quickxor = 6648831dca000000000000000400000000000000 OK 2022/04/20 05:46:37 DEBUG : three: quickxor = 7440831cca500600000000000500000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:46:37 DEBUG : five: Size and quickxor of src and dst objects identical 2022/04/20 05:46:37 DEBUG : three: quickxor = 544082148a500400000000000500000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:46:37 DEBUG : five: Destination mod time is within 1s of source and files identical, skipping 2022/04/20 05:46:37 DEBUG : three: quickxor differ 2022/04/20 05:46:37 DEBUG : three: Destination mod time is within 1s of source but files differ, transferring 2022/04/20 05:46:37 DEBUG : three: Starting multipart upload 2022/04/20 05:46:37 DEBUG : two: quickxor = 74b8c31b00000000000000000300000000000000 OK 2022/04/20 05:46:37 DEBUG : two: Size and quickxor of src and dst objects identical 2022/04/20 05:46:37 DEBUG : two: Destination mod time is within 1s of source and files identical, skipping 2022/04/20 05:46:37 DEBUG : four: quickxor = 6678431de4000000000000000400000000000000 OK 2022/04/20 05:46:37 DEBUG : four: Size and quickxor of src and dst objects identical 2022/04/20 05:46:37 DEBUG : four: Destination mod time is within 1s of source and files identical, skipping 2022/04/20 05:46:37 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:46:38 DEBUG : three: Uploading segment 0/5 size 5 2022/04/20 05:46:39 DEBUG : three: quickxor = 7440831cca500600000000000500000000000000 OK 2022/04/20 05:46:39 INFO : three: Copied (replaced existing) 2022/04/20 05:46:39 DEBUG : Waiting for deletions to finish --- PASS: TestSyncWithUpdateOlder (13.63s) === RUN TestSyncWithMaxDuration sync_test.go:1009: Skipping test on non local remote --- SKIP: TestSyncWithMaxDuration (0.00s) === RUN TestSyncWithTrackRenames run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" sync_test.go:1058: Can track renames: true 2022/04/20 05:46:42 INFO : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Making map for --track-renames 2022/04/20 05:46:42 INFO : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Finished making map for --track-renames 2022/04/20 05:46:42 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:46:42 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for renames to finish 2022/04/20 05:46:42 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:46:42 DEBUG : potato: Starting multipart upload 2022/04/20 05:46:42 DEBUG : yam: Starting multipart upload 2022/04/20 05:46:43 DEBUG : yam: Uploading segment 0/11 size 11 2022/04/20 05:46:43 DEBUG : potato: Uploading segment 0/14 size 14 2022/04/20 05:46:43 DEBUG : yam: quickxor = 5908431b40308437b8810e657b031d0000000000 OK 2022/04/20 05:46:43 INFO : yam: Copied (new) 2022/04/20 05:46:43 DEBUG : potato: quickxor = 5078031dc24087378060086f7e031dcae0063a00 OK 2022/04/20 05:46:43 INFO : potato: Copied (new) 2022/04/20 05:46:43 DEBUG : Waiting for deletions to finish 2022/04/20 05:46:44 INFO : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Making map for --track-renames 2022/04/20 05:46:44 DEBUG : potato: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:46:44 DEBUG : potato: Unchanged skipping 2022/04/20 05:46:44 INFO : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Finished making map for --track-renames 2022/04/20 05:46:44 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:46:44 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for renames to finish 2022/04/20 05:46:46 INFO : yam: Moved (server-side) to: yaml 2022/04/20 05:46:46 INFO : yaml: Renamed from "yam" 2022/04/20 05:46:46 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:46:46 DEBUG : Waiting for deletions to finish 2022/04/20 05:46:46 INFO : There was nothing to transfer --- PASS: TestSyncWithTrackRenames (6.75s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" sync_test.go:1127: Can track renames: true 2022/04/20 05:46:48 INFO : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Making map for --track-renames 2022/04/20 05:46:48 INFO : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Finished making map for --track-renames 2022/04/20 05:46:48 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:46:48 DEBUG : potato: Starting multipart upload 2022/04/20 05:46:48 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for renames to finish 2022/04/20 05:46:48 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:46:48 DEBUG : yam: Starting multipart upload 2022/04/20 05:46:49 DEBUG : potato: Uploading segment 0/14 size 14 2022/04/20 05:46:49 DEBUG : yam: Uploading segment 0/11 size 11 2022/04/20 05:46:50 DEBUG : potato: quickxor = 5078031dc24087378060086f7e031dcae0063a00 OK 2022/04/20 05:46:50 INFO : potato: Copied (new) 2022/04/20 05:46:50 DEBUG : yam: quickxor = 5908431b40308437b8810e657b031d0000000000 OK 2022/04/20 05:46:50 INFO : yam: Copied (new) 2022/04/20 05:46:50 DEBUG : Waiting for deletions to finish 2022/04/20 05:46:51 DEBUG : potato: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:46:51 DEBUG : potato: Unchanged skipping 2022/04/20 05:46:51 INFO : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Making map for --track-renames 2022/04/20 05:46:51 INFO : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Finished making map for --track-renames 2022/04/20 05:46:51 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:46:51 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for renames to finish 2022/04/20 05:46:51 INFO : yam: Moved (server-side) to: yaml 2022/04/20 05:46:51 INFO : yaml: Renamed from "yam" 2022/04/20 05:46:51 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:46:51 DEBUG : Waiting for deletions to finish 2022/04/20 05:46:51 INFO : There was nothing to transfer --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.14s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" sync_test.go:1163: Can track renames: true 2022/04/20 05:46:54 INFO : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Making map for --track-renames 2022/04/20 05:46:54 INFO : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Finished making map for --track-renames 2022/04/20 05:46:54 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:46:54 DEBUG : potato: Starting multipart upload 2022/04/20 05:46:54 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for renames to finish 2022/04/20 05:46:54 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:46:54 DEBUG : potato: Uploading segment 0/14 size 14 2022/04/20 05:46:54 DEBUG : sub/yam: Starting multipart upload 2022/04/20 05:46:55 DEBUG : potato: quickxor = 5078031dc24087378060086f7e031dcae0063a00 OK 2022/04/20 05:46:55 INFO : potato: Copied (new) 2022/04/20 05:46:55 DEBUG : sub/yam: Uploading segment 0/11 size 11 2022/04/20 05:46:55 DEBUG : sub/yam: quickxor = 5908431b40308437b8810e657b031d0000000000 OK 2022/04/20 05:46:55 INFO : sub/yam: Copied (new) 2022/04/20 05:46:55 DEBUG : Waiting for deletions to finish 2022/04/20 05:46:57 DEBUG : potato: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:46:57 DEBUG : potato: Unchanged skipping 2022/04/20 05:46:57 INFO : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Making map for --track-renames 2022/04/20 05:46:57 INFO : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Finished making map for --track-renames 2022/04/20 05:46:57 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:46:57 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for renames to finish 2022/04/20 05:47:00 INFO : sub/yam: Moved (server-side) to: yam 2022/04/20 05:47:00 INFO : yam: Renamed from "sub/yam" 2022/04/20 05:47:00 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:47:00 DEBUG : Waiting for deletions to finish 2022/04/20 05:47:00 INFO : There was nothing to transfer fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1180 Error: Should be true Test: TestSyncWithTrackRenamesStrategyLeaf Messages: listing wrong, want potato (14), yam (11) got potato (14), sub/yam (11) fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1180 Error: Should be true Test: TestSyncWithTrackRenamesStrategyLeaf Messages: Unexpected file "sub/yam" fstest.go:204: Not found "yam" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1180 Error: Not equal: expected: 0 actual : 1 Test: TestSyncWithTrackRenamesStrategyLeaf Messages: 1 objects not found --- FAIL: TestSyncWithTrackRenamesStrategyLeaf (19.15s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:47:13 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:47:13 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:47:14 DEBUG : sub dir/hello world: Starting multipart upload 2022/04/20 05:47:15 DEBUG : nested/sub dir/file: Starting multipart upload 2022/04/20 05:47:15 DEBUG : nested/sub dir/file: Uploading segment 0/6 size 6 2022/04/20 05:47:15 DEBUG : sub dir/hello world: Uploading segment 0/11 size 11 2022/04/20 05:47:16 DEBUG : nested/sub dir/file: quickxor = 6e28c31ce8500632000000000600000000000000 OK 2022/04/20 05:47:16 INFO : nested/sub dir/file: Copied (new) 2022/04/20 05:47:16 INFO : nested/sub dir/file: Deleted 2022/04/20 05:47:16 DEBUG : sub dir/hello world: quickxor = 6828031bd8f00610dce10d726b03190000000000 OK 2022/04/20 05:47:16 INFO : sub dir/hello world: Copied (new) 2022/04/20 05:47:16 INFO : sub dir/hello world: Deleted 2022/04/20 05:47:16 INFO : sub dir: Removing directory 2022/04/20 05:47:16 INFO : nested/sub dir: Removing directory 2022/04/20 05:47:16 INFO : nested: Removing directory 2022/04/20 05:47:16 DEBUG : Local file system at /tmp/rclone1468494239: deleted 3 directories --- PASS: TestMoveWithDeleteEmptySrcDirs (7.94s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:47:20 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:47:20 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:47:21 DEBUG : sub dir/hello world: Starting multipart upload 2022/04/20 05:47:22 DEBUG : sub dir/hello world: Uploading segment 0/11 size 11 2022/04/20 05:47:22 DEBUG : sub dir/hello world: quickxor = 6828031bd8f00610dce10d726b03190000000000 OK 2022/04/20 05:47:22 INFO : sub dir/hello world: Copied (new) 2022/04/20 05:47:22 INFO : sub dir/hello world: Deleted 2022/04/20 05:47:23 DEBUG : nested/sub dir/file: Starting multipart upload 2022/04/20 05:47:23 DEBUG : nested/sub dir/file: Uploading segment 0/6 size 6 2022/04/20 05:47:24 DEBUG : nested/sub dir/file: quickxor = 6e28c31ce8500632000000000600000000000000 OK 2022/04/20 05:47:24 INFO : nested/sub dir/file: Copied (new) 2022/04/20 05:47:24 INFO : nested/sub dir/file: Deleted --- PASS: TestMoveWithoutDeleteEmptySrcDirs (7.37s) === RUN TestMoveWithIgnoreExisting run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:47:28 DEBUG : existing: Starting multipart upload 2022/04/20 05:47:28 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:47:28 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:47:28 DEBUG : existing-b: Starting multipart upload 2022/04/20 05:47:29 DEBUG : existing-b: Uploading segment 0/6 size 6 2022/04/20 05:47:29 DEBUG : existing: Uploading segment 0/6 size 6 2022/04/20 05:47:29 DEBUG : existing-b: quickxor = 7478431bc2408737000000000600000000000000 OK 2022/04/20 05:47:29 INFO : existing-b: Copied (new) 2022/04/20 05:47:29 INFO : existing-b: Deleted 2022/04/20 05:47:29 DEBUG : existing: quickxor = 7078031dc2408737000000000600000000000000 OK 2022/04/20 05:47:29 INFO : existing: Copied (new) 2022/04/20 05:47:29 INFO : existing: Deleted 2022/04/20 05:47:30 DEBUG : existing: Destination exists, skipping 2022/04/20 05:47:30 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2022/04/20 05:47:30 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:47:30 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:47:30 INFO : There was nothing to transfer --- PASS: TestMoveWithIgnoreExisting (3.70s) === RUN TestServerSideMove run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:47:31 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-vasuqoz0tupubiy7fewider6" 2022/04/20 05:47:32 DEBUG : potato2: Starting multipart upload 2022/04/20 05:47:33 DEBUG : potato2: Uploading segment 0/60 size 60 2022/04/20 05:47:33 DEBUG : empty space: Starting multipart upload 2022/04/20 05:47:34 DEBUG : empty space: Uploading segment 0/1 size 1 2022/04/20 05:47:35 DEBUG : potato3: Starting multipart upload 2022/04/20 05:47:35 DEBUG : potato3: Uploading segment 0/68 size 68 sync_test.go:1215: Server side move (if possible) One drive root 'rclone-test-zirepet0zatoguz5parosak5' -> One drive root 'rclone-test-vasuqoz0tupubiy7fewider6' 2022/04/20 05:47:37 DEBUG : empty space: Starting multipart upload 2022/04/20 05:47:37 DEBUG : empty space: Uploading segment 0/1 size 1 2022/04/20 05:47:38 DEBUG : potato3: Starting multipart upload 2022/04/20 05:47:39 DEBUG : potato3: Uploading segment 0/60 size 60 2022/04/20 05:47:40 DEBUG : One drive root 'rclone-test-vasuqoz0tupubiy7fewider6': Using server-side directory move 2022/04/20 05:47:40 INFO : One drive root 'rclone-test-vasuqoz0tupubiy7fewider6': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2022/04/20 05:47:40 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1s) 2022/04/20 05:47:40 DEBUG : empty space: Unchanged skipping 2022/04/20 05:47:40 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2022/04/20 05:47:40 DEBUG : One drive root 'rclone-test-vasuqoz0tupubiy7fewider6': Waiting for checks to finish 2022/04/20 05:47:40 INFO : potato3: Deleted 2022/04/20 05:47:40 INFO : empty space: Deleted 2022/04/20 05:47:40 DEBUG : One drive root 'rclone-test-vasuqoz0tupubiy7fewider6': Waiting for transfers to finish 2022/04/20 05:47:40 INFO : potato2: Moved (server-side) 2022/04/20 05:47:40 INFO : potato3: Moved (server-side) 2022/04/20 05:47:40 INFO : There was nothing to transfer fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1230 sync_test.go:1367 Error: Should be true Test: TestServerSideMove Messages: listing wrong, want got potato2 (60), potato3 (68) fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1230 sync_test.go:1367 Error: Should be true Test: TestServerSideMove Messages: Unexpected file "potato2" fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1230 sync_test.go:1367 Error: Should be true Test: TestServerSideMove Messages: Unexpected file "potato3" fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:357 sync_test.go:1237 sync_test.go:1367 Error: Should be true Test: TestServerSideMove Messages: listing wrong, want empty space (1), potato2 (60), potato3 (68) got empty space (1) fstest.go:204: Not found "potato3" fstest.go:204: Not found "potato2" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:357 sync_test.go:1237 sync_test.go:1367 Error: Not equal: expected: 0 actual : 2 Test: TestServerSideMove Messages: 2 objects not found 2022/04/20 05:47:58 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-yebaxeb2witeyek1fejivem2" 2022/04/20 05:47:59 DEBUG : One drive root 'rclone-test-yebaxeb2witeyek1fejivem2': Using server-side directory move 2022/04/20 05:48:00 INFO : One drive root 'rclone-test-yebaxeb2witeyek1fejivem2': Server side directory move succeeded fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:357 sync_test.go:1258 sync_test.go:1367 Error: Should be true Test: TestServerSideMove Messages: listing wrong, want empty space (1), potato2 (60), potato3 (68) got empty space (1) fstest.go:204: Not found "potato2" fstest.go:204: Not found "potato3" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:357 sync_test.go:1258 sync_test.go:1367 Error: Not equal: expected: 0 actual : 2 Test: TestServerSideMove Messages: 2 objects not found 2022/04/20 05:48:09 ERROR : : error listing: directory not found 2022/04/20 05:48:09 DEBUG : One drive root 'rclone-test-yebaxeb2witeyek1fejivem2': Purge remote 2022/04/20 05:48:09 DEBUG : One drive root 'rclone-test-vasuqoz0tupubiy7fewider6': Purge remote 2022/04/20 05:48:10 purge failed: directory not found --- FAIL: TestServerSideMove (39.94s) === RUN TestServerSideMoveWithFilter run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:48:11 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-kabudun1febebir0nawotil7" 2022/04/20 05:48:12 DEBUG : potato2: Starting multipart upload 2022/04/20 05:48:12 DEBUG : potato2: Uploading segment 0/60 size 60 2022/04/20 05:48:13 DEBUG : empty space: Starting multipart upload 2022/04/20 05:48:14 DEBUG : empty space: Uploading segment 0/1 size 1 2022/04/20 05:48:14 DEBUG : potato3: Starting multipart upload 2022/04/20 05:48:15 DEBUG : potato3: Uploading segment 0/68 size 68 sync_test.go:1215: Server side move (if possible) One drive root 'rclone-test-zirepet0zatoguz5parosak5' -> One drive root 'rclone-test-kabudun1febebir0nawotil7' 2022/04/20 05:48:17 DEBUG : empty space: Starting multipart upload 2022/04/20 05:48:17 DEBUG : empty space: Uploading segment 0/1 size 1 2022/04/20 05:48:18 DEBUG : potato3: Starting multipart upload 2022/04/20 05:48:18 DEBUG : potato3: Uploading segment 0/60 size 60 2022/04/20 05:48:20 DEBUG : empty space: Excluded 2022/04/20 05:48:20 DEBUG : empty space: Excluded 2022/04/20 05:48:20 DEBUG : One drive root 'rclone-test-kabudun1febebir0nawotil7': Waiting for checks to finish 2022/04/20 05:48:20 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2022/04/20 05:48:20 DEBUG : One drive root 'rclone-test-kabudun1febebir0nawotil7': Waiting for transfers to finish 2022/04/20 05:48:20 INFO : potato2: Moved (server-side) 2022/04/20 05:48:20 INFO : potato3: Deleted 2022/04/20 05:48:20 INFO : potato3: Moved (server-side) 2022/04/20 05:48:20 INFO : There was nothing to transfer fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1228 sync_test.go:1381 Error: Should be true Test: TestServerSideMoveWithFilter Messages: listing wrong, want empty space (1) got empty space (1), potato2 (60), potato3 (68) fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1228 sync_test.go:1381 Error: Should be true Test: TestServerSideMoveWithFilter Messages: Unexpected file "potato2" fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1228 sync_test.go:1381 Error: Should be true Test: TestServerSideMoveWithFilter Messages: Unexpected file "potato3" fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:357 sync_test.go:1237 sync_test.go:1381 Error: Should be true Test: TestServerSideMoveWithFilter Messages: listing wrong, want empty space (1), potato2 (60), potato3 (68) got empty space (1) fstest.go:204: Not found "potato2" fstest.go:204: Not found "potato3" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:357 sync_test.go:1237 sync_test.go:1381 Error: Not equal: expected: 0 actual : 2 Test: TestServerSideMoveWithFilter Messages: 2 objects not found 2022/04/20 05:48:39 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-fulasaw2qujevus6yuzabad4" 2022/04/20 05:48:42 DEBUG : empty space: Excluded 2022/04/20 05:48:42 DEBUG : One drive root 'rclone-test-fulasaw2qujevus6yuzabad4': Waiting for checks to finish 2022/04/20 05:48:42 DEBUG : One drive root 'rclone-test-fulasaw2qujevus6yuzabad4': Waiting for transfers to finish 2022/04/20 05:48:42 INFO : There was nothing to transfer 2022/04/20 05:48:43 ERROR : : error listing: directory not found fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache 2022/04/20 05:48:44 ERROR : : error listing: directory not found fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache 2022/04/20 05:48:47 ERROR : : error listing: directory not found fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:357 sync_test.go:1255 sync_test.go:1381 Error: Should be true Test: TestServerSideMoveWithFilter Messages: listing wrong, want potato2 (60), potato3 (68) got fstest.go:204: Not found "potato2" fstest.go:204: Not found "potato3" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:357 sync_test.go:1255 sync_test.go:1381 Error: Not equal: expected: 0 actual : 2 Test: TestServerSideMoveWithFilter Messages: 2 objects not found 2022/04/20 05:48:51 DEBUG : One drive root 'rclone-test-fulasaw2qujevus6yuzabad4': Purge remote 2022/04/20 05:48:52 purge failed: directory not found 2022/04/20 05:48:52 DEBUG : One drive root 'rclone-test-kabudun1febebir0nawotil7': Purge remote --- FAIL: TestServerSideMoveWithFilter (43.39s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:48:55 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-tequpij6kinivuc2fapuvoz9" 2022/04/20 05:48:56 DEBUG : potato2: Starting multipart upload 2022/04/20 05:48:57 DEBUG : potato2: Uploading segment 0/60 size 60 2022/04/20 05:48:57 DEBUG : empty space: Starting multipart upload 2022/04/20 05:48:58 DEBUG : empty space: Uploading segment 0/1 size 1 2022/04/20 05:48:59 DEBUG : potato3: Starting multipart upload 2022/04/20 05:49:00 DEBUG : potato3: Uploading segment 0/68 size 68 2022/04/20 05:49:00 DEBUG : tomatoDir: Making directory sync_test.go:1215: Server side move (if possible) One drive root 'rclone-test-zirepet0zatoguz5parosak5' -> One drive root 'rclone-test-tequpij6kinivuc2fapuvoz9' 2022/04/20 05:49:03 DEBUG : empty space: Starting multipart upload 2022/04/20 05:49:05 DEBUG : empty space: Uploading segment 0/1 size 1 2022/04/20 05:49:05 DEBUG : potato3: Starting multipart upload 2022/04/20 05:49:06 DEBUG : potato3: Uploading segment 0/60 size 60 2022/04/20 05:49:07 DEBUG : One drive root 'rclone-test-tequpij6kinivuc2fapuvoz9': Using server-side directory move 2022/04/20 05:49:07 INFO : One drive root 'rclone-test-tequpij6kinivuc2fapuvoz9': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2022/04/20 05:49:08 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1s) 2022/04/20 05:49:08 DEBUG : empty space: Unchanged skipping 2022/04/20 05:49:08 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2022/04/20 05:49:08 INFO : potato3: Deleted 2022/04/20 05:49:08 DEBUG : One drive root 'rclone-test-tequpij6kinivuc2fapuvoz9': Waiting for checks to finish 2022/04/20 05:49:08 INFO : potato3: Moved (server-side) 2022/04/20 05:49:08 INFO : empty space: Deleted 2022/04/20 05:49:08 DEBUG : One drive root 'rclone-test-tequpij6kinivuc2fapuvoz9': Waiting for transfers to finish 2022/04/20 05:49:08 INFO : potato2: Moved (server-side) 2022/04/20 05:49:08 INFO : tomatoDir: Removing directory 2022/04/20 05:49:09 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': deleted 1 directories 2022/04/20 05:49:09 INFO : There was nothing to transfer fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1230 sync_test.go:1389 Error: Should be true Test: TestServerSideMoveDeleteEmptySourceDirs Messages: listing wrong, want got potato2 (60), potato3 (68) fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1230 sync_test.go:1389 Error: Should be true Test: TestServerSideMoveDeleteEmptySourceDirs Messages: Unexpected file "potato2" fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1230 sync_test.go:1389 Error: Should be true Test: TestServerSideMoveDeleteEmptySourceDirs Messages: Unexpected file "potato3" fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 run.go:362 sync_test.go:1234 sync_test.go:1389 Error: Should be true Test: TestServerSideMoveDeleteEmptySourceDirs Messages: listing wrong, want got potato2 (60), potato3 (68) fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 run.go:362 sync_test.go:1234 sync_test.go:1389 Error: Should be true Test: TestServerSideMoveDeleteEmptySourceDirs Messages: Unexpected file "potato2" fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 run.go:362 sync_test.go:1234 sync_test.go:1389 Error: Should be true Test: TestServerSideMoveDeleteEmptySourceDirs Messages: Unexpected file "potato3" fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:357 sync_test.go:1237 sync_test.go:1389 Error: Should be true Test: TestServerSideMoveDeleteEmptySourceDirs Messages: listing wrong, want empty space (1), potato2 (60), potato3 (68) got empty space (1) fstest.go:204: Not found "potato2" fstest.go:204: Not found "potato3" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:357 sync_test.go:1237 sync_test.go:1389 Error: Not equal: expected: 0 actual : 2 Test: TestServerSideMoveDeleteEmptySourceDirs Messages: 2 objects not found 2022/04/20 05:49:36 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-rozugap8dadudec3rihuvej3" 2022/04/20 05:49:37 DEBUG : tomatoDir: Making directory 2022/04/20 05:49:38 DEBUG : One drive root 'rclone-test-rozugap8dadudec3rihuvej3': Using server-side directory move 2022/04/20 05:49:39 INFO : One drive root 'rclone-test-rozugap8dadudec3rihuvej3': Server side directory move succeeded fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:357 sync_test.go:1258 sync_test.go:1389 Error: Should be true Test: TestServerSideMoveDeleteEmptySourceDirs Messages: listing wrong, want empty space (1), potato2 (60), potato3 (68) got empty space (1) fstest.go:204: Not found "potato2" fstest.go:204: Not found "potato3" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:357 sync_test.go:1258 sync_test.go:1389 Error: Not equal: expected: 0 actual : 2 Test: TestServerSideMoveDeleteEmptySourceDirs Messages: 2 objects not found 2022/04/20 05:49:49 ERROR : : error listing: directory not found 2022/04/20 05:49:49 ERROR : : error listing: directory not found 2022/04/20 05:49:49 DEBUG : One drive root 'rclone-test-rozugap8dadudec3rihuvej3': Purge remote 2022/04/20 05:49:49 DEBUG : One drive root 'rclone-test-tequpij6kinivuc2fapuvoz9': Purge remote 2022/04/20 05:49:50 purge failed: directory not found --- FAIL: TestServerSideMoveDeleteEmptySourceDirs (56.37s) === RUN TestServerSideMoveOverlap run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" sync_test.go:1399: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.51s) === RUN TestSyncOverlap run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:49:51 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5/rclone-sync-test" --- PASS: TestSyncOverlap (2.17s) === RUN TestSyncCompareDest run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:49:54 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5/dst" 2022/04/20 05:49:55 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5/CompareDest" 2022/04/20 05:49:58 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for checks to finish 2022/04/20 05:49:58 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for transfers to finish 2022/04/20 05:49:58 DEBUG : one: Starting multipart upload 2022/04/20 05:49:59 DEBUG : one: Uploading segment 0/3 size 3 2022/04/20 05:50:00 DEBUG : one: quickxor = 6f70431900000000000000000300000000000000 OK 2022/04/20 05:50:00 INFO : one: Copied (new) 2022/04/20 05:50:00 DEBUG : Waiting for deletions to finish 2022/04/20 05:50:01 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for checks to finish 2022/04/20 05:50:02 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/04/20 05:50:02 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for transfers to finish 2022/04/20 05:50:02 DEBUG : one: Starting multipart upload 2022/04/20 05:50:02 DEBUG : one: Uploading segment 0/5 size 5 2022/04/20 05:50:03 DEBUG : one: quickxor = 6f704319e8200300000000000500000000000000 OK 2022/04/20 05:50:03 INFO : one: Copied (replaced existing) 2022/04/20 05:50:03 DEBUG : Waiting for deletions to finish 2022/04/20 05:50:03 DEBUG : dst/one: Starting multipart upload 2022/04/20 05:50:04 DEBUG : dst/one: Uploading segment 0/3 size 3 2022/04/20 05:50:05 DEBUG : CompareDest/one: Starting multipart upload 2022/04/20 05:50:06 DEBUG : CompareDest/one: Uploading segment 0/5 size 5 2022/04/20 05:50:07 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for checks to finish 2022/04/20 05:50:08 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 05:50:08 DEBUG : one: Destination found in --compare-dest, skipping 2022/04/20 05:50:08 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for transfers to finish 2022/04/20 05:50:08 DEBUG : Waiting for deletions to finish 2022/04/20 05:50:08 INFO : There was nothing to transfer 2022/04/20 05:50:09 DEBUG : CompareDest/two: Starting multipart upload 2022/04/20 05:50:09 DEBUG : CompareDest/two: Uploading segment 0/3 size 3 2022/04/20 05:50:12 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 05:50:12 DEBUG : two: Destination found in --compare-dest, skipping 2022/04/20 05:50:12 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for checks to finish 2022/04/20 05:50:13 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 05:50:13 DEBUG : one: Destination found in --compare-dest, skipping 2022/04/20 05:50:13 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for transfers to finish 2022/04/20 05:50:13 DEBUG : Waiting for deletions to finish 2022/04/20 05:50:13 INFO : There was nothing to transfer 2022/04/20 05:50:14 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 05:50:14 DEBUG : two: Destination found in --compare-dest, skipping 2022/04/20 05:50:14 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for checks to finish 2022/04/20 05:50:15 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 05:50:15 DEBUG : one: Destination found in --compare-dest, skipping 2022/04/20 05:50:15 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for transfers to finish 2022/04/20 05:50:15 DEBUG : Waiting for deletions to finish 2022/04/20 05:50:15 INFO : There was nothing to transfer 2022/04/20 05:50:17 DEBUG : two: Modification times differ by -120h0m0s: 2011-12-30 12:59:59 +0000 UTC, 2011-12-25 12:59:59 +0000 UTC 2022/04/20 05:50:17 DEBUG : two: quickxor = 74b8c31b00000000000000000300000000000000 OK 2022/04/20 05:50:17 DEBUG : two: Destination found in --compare-dest, skipping 2022/04/20 05:50:17 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for checks to finish 2022/04/20 05:50:18 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 05:50:18 DEBUG : one: Destination found in --compare-dest, skipping 2022/04/20 05:50:18 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for transfers to finish 2022/04/20 05:50:18 DEBUG : Waiting for deletions to finish 2022/04/20 05:50:18 INFO : There was nothing to transfer 2022/04/20 05:50:20 DEBUG : two: Sizes differ (src 5 vs dst 3) 2022/04/20 05:50:20 DEBUG : two: Starting multipart upload 2022/04/20 05:50:20 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for checks to finish 2022/04/20 05:50:20 DEBUG : two: Uploading segment 0/5 size 5 2022/04/20 05:50:20 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 05:50:20 DEBUG : one: Destination found in --compare-dest, skipping 2022/04/20 05:50:20 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for transfers to finish 2022/04/20 05:50:21 DEBUG : two: quickxor = 74b8c31be8300300000000000500000000000000 OK 2022/04/20 05:50:21 INFO : two: Copied (new) 2022/04/20 05:50:21 DEBUG : Waiting for deletions to finish --- PASS: TestSyncCompareDest (30.86s) === RUN TestSyncMultipleCompareDest run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:50:25 DEBUG : pre-dest1/1: Starting multipart upload 2022/04/20 05:50:26 DEBUG : pre-dest1/1: Uploading segment 0/1 size 1 2022/04/20 05:50:27 DEBUG : pre-dest2/2: Starting multipart upload 2022/04/20 05:50:28 DEBUG : pre-dest2/2: Uploading segment 0/1 size 1 2022/04/20 05:50:29 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5/dest" 2022/04/20 05:50:31 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5/pre-dest1" 2022/04/20 05:50:31 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5/pre-dest2" 2022/04/20 05:50:33 DEBUG : 1: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:50:33 DEBUG : 1: Destination found in --compare-dest, skipping 2022/04/20 05:50:34 DEBUG : 2: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:50:34 DEBUG : 2: Destination found in --compare-dest, skipping 2022/04/20 05:50:36 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dest': Waiting for checks to finish 2022/04/20 05:50:36 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dest': Waiting for transfers to finish 2022/04/20 05:50:36 DEBUG : 3: Starting multipart upload 2022/04/20 05:50:37 DEBUG : 3: Uploading segment 0/1 size 1 2022/04/20 05:50:38 DEBUG : 3: quickxor = 3300000000000000000000000100000000000000 OK 2022/04/20 05:50:38 INFO : 3: Copied (new) 2022/04/20 05:50:38 DEBUG : Waiting for deletions to finish --- PASS: TestSyncMultipleCompareDest (17.21s) === RUN TestSyncCopyDest run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:50:42 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5/dst" 2022/04/20 05:50:43 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5/CopyDest" 2022/04/20 05:50:46 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for checks to finish 2022/04/20 05:50:46 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for transfers to finish 2022/04/20 05:50:46 DEBUG : one: Starting multipart upload 2022/04/20 05:50:47 DEBUG : one: Uploading segment 0/3 size 3 2022/04/20 05:50:48 DEBUG : one: quickxor = 6f70431900000000000000000300000000000000 OK 2022/04/20 05:50:48 INFO : one: Copied (new) 2022/04/20 05:50:48 DEBUG : Waiting for deletions to finish 2022/04/20 05:50:49 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for checks to finish 2022/04/20 05:50:50 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/04/20 05:50:50 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for transfers to finish 2022/04/20 05:50:50 DEBUG : one: Starting multipart upload 2022/04/20 05:50:50 DEBUG : one: Uploading segment 0/5 size 5 2022/04/20 05:50:51 DEBUG : one: quickxor = 6f704319e8200300000000000500000000000000 OK 2022/04/20 05:50:51 INFO : one: Copied (replaced existing) 2022/04/20 05:50:51 DEBUG : Waiting for deletions to finish 2022/04/20 05:50:51 DEBUG : dst/one: Starting multipart upload 2022/04/20 05:50:52 DEBUG : dst/one: Uploading segment 0/3 size 3 2022/04/20 05:50:53 DEBUG : CopyDest/one: Starting multipart upload 2022/04/20 05:50:54 DEBUG : CopyDest/one: Uploading segment 0/5 size 5 2022/04/20 05:50:55 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5/BackupDir" 2022/04/20 05:50:57 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for checks to finish 2022/04/20 05:50:58 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 05:50:58 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/04/20 05:50:59 INFO : one: Moved (server-side) 2022/04/20 05:51:00 ERROR : one: Failed to copy: nameAlreadyExists: The specified item name already exists. 2022/04/20 05:51:00 ERROR : one: Destination found in --copy-dest, error copying 2022/04/20 05:51:00 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/04/20 05:51:00 INFO : one: Moved (server-side) 2022/04/20 05:51:00 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for transfers to finish 2022/04/20 05:51:00 DEBUG : one: Starting multipart upload 2022/04/20 05:51:01 DEBUG : one: Uploading segment 0/5 size 5 2022/04/20 05:51:02 DEBUG : one: quickxor = 6f704319e8200300000000000500000000000000 OK 2022/04/20 05:51:02 INFO : one: Copied (new) 2022/04/20 05:51:02 ERROR : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': not deleting files as there were IO errors 2022/04/20 05:51:02 ERROR : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': not deleting directories as there were IO errors sync_test.go:1648: Error Trace: sync_test.go:1648 Error: Received unexpected error: not deleting files as there were IO errors Test: TestSyncCopyDest --- FAIL: TestSyncCopyDest (22.53s) === RUN TestSyncBackupDir run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:51:05 DEBUG : dst/one: Starting multipart upload 2022/04/20 05:51:05 DEBUG : dst/one: Uploading segment 0/3 size 3 2022/04/20 05:51:06 DEBUG : dst/two: Starting multipart upload 2022/04/20 05:51:07 DEBUG : dst/two: Uploading segment 0/3 size 3 2022/04/20 05:51:07 DEBUG : dst/three.txt: Starting multipart upload 2022/04/20 05:51:08 DEBUG : dst/three.txt: Uploading segment 0/5 size 5 2022/04/20 05:51:09 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5/dst" 2022/04/20 05:51:10 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5/backup" 2022/04/20 05:51:12 DEBUG : one: Sizes differ (src 4 vs dst 3) 2022/04/20 05:51:12 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for checks to finish 2022/04/20 05:51:12 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:51:12 DEBUG : two: Unchanged skipping 2022/04/20 05:51:14 INFO : one: Moved (server-side) 2022/04/20 05:51:14 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for transfers to finish 2022/04/20 05:51:14 DEBUG : one: Starting multipart upload 2022/04/20 05:51:14 DEBUG : one: Uploading segment 0/4 size 4 2022/04/20 05:51:15 DEBUG : one: quickxor = 6f70431982000000000000000400000000000000 OK 2022/04/20 05:51:15 INFO : one: Copied (new) 2022/04/20 05:51:15 DEBUG : Waiting for deletions to finish 2022/04/20 05:51:16 INFO : three.txt: Moved (server-side) 2022/04/20 05:51:16 INFO : three.txt: Moved into backup dir fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1753 sync_test.go:1781 Error: Should be true Test: TestSyncBackupDir Messages: listing wrong, want backup/one (3), backup/three.txt (5), dst/one (4), dst/two (3) got dst/one (4), dst/three.txt (5), dst/two (3) fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1753 sync_test.go:1781 Error: Should be true Test: TestSyncBackupDir Messages: Unexpected file "dst/three.txt" fstest.go:204: Not found "backup/one" fstest.go:204: Not found "backup/three.txt" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1753 sync_test.go:1781 Error: Not equal: expected: 0 actual : 2 Test: TestSyncBackupDir Messages: 2 objects not found 2022/04/20 05:51:26 DEBUG : dst/three.txt: Starting multipart upload 2022/04/20 05:51:26 DEBUG : dst/three.txt: Uploading segment 0/6 size 6 fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1759 sync_test.go:1781 Error: Should be true Test: TestSyncBackupDir Messages: listing wrong, want backup/one (3), backup/three.txt (5), dst/one (4), dst/three.txt (6), dst/two (3) got dst/one (4), dst/three.txt (6), dst/two (3) fstest.go:204: Not found "backup/three.txt" fstest.go:204: Not found "backup/one" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1759 sync_test.go:1781 Error: Not equal: expected: 0 actual : 2 Test: TestSyncBackupDir Messages: 2 objects not found 2022/04/20 05:51:37 DEBUG : one: Sizes differ (src 5 vs dst 4) 2022/04/20 05:51:37 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:51:37 DEBUG : two: Unchanged skipping 2022/04/20 05:51:37 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for checks to finish 2022/04/20 05:51:38 INFO : one: Moved (server-side) 2022/04/20 05:51:38 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for transfers to finish 2022/04/20 05:51:38 DEBUG : one: Starting multipart upload 2022/04/20 05:51:38 DEBUG : one: Uploading segment 0/5 size 5 2022/04/20 05:51:39 DEBUG : one: quickxor = 6f70431984200400000000000500000000000000 OK 2022/04/20 05:51:39 INFO : one: Copied (new) 2022/04/20 05:51:39 DEBUG : Waiting for deletions to finish 2022/04/20 05:51:40 INFO : three.txt: Moved (server-side) 2022/04/20 05:51:40 INFO : three.txt: Moved into backup dir fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1778 sync_test.go:1781 Error: Should be true Test: TestSyncBackupDir Messages: listing wrong, want backup/one (4), backup/three.txt (6), dst/one (5), dst/two (3) got dst/one (5), dst/three.txt (6), dst/two (3) fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1778 sync_test.go:1781 Error: Should be true Test: TestSyncBackupDir Messages: Unexpected file "dst/three.txt" fstest.go:204: Not found "backup/three.txt" fstest.go:204: Not found "backup/one" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1778 sync_test.go:1781 Error: Not equal: expected: 0 actual : 2 Test: TestSyncBackupDir Messages: 2 objects not found --- FAIL: TestSyncBackupDir (48.72s) === RUN TestSyncBackupDirWithSuffix run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:51:54 DEBUG : dst/one: Starting multipart upload 2022/04/20 05:51:54 DEBUG : dst/one: Uploading segment 0/3 size 3 2022/04/20 05:51:55 DEBUG : dst/two: Starting multipart upload 2022/04/20 05:51:55 DEBUG : dst/two: Uploading segment 0/3 size 3 2022/04/20 05:51:56 DEBUG : dst/three.txt: Starting multipart upload 2022/04/20 05:51:56 DEBUG : dst/three.txt: Uploading segment 0/5 size 5 2022/04/20 05:51:58 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5/dst" 2022/04/20 05:51:59 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5/backup" 2022/04/20 05:52:01 DEBUG : one: Sizes differ (src 4 vs dst 3) 2022/04/20 05:52:01 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:52:01 DEBUG : two: Unchanged skipping 2022/04/20 05:52:01 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for checks to finish 2022/04/20 05:52:03 INFO : one: Moved (server-side) to: one.bak 2022/04/20 05:52:03 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for transfers to finish 2022/04/20 05:52:03 DEBUG : one: Starting multipart upload 2022/04/20 05:52:03 DEBUG : one: Uploading segment 0/4 size 4 2022/04/20 05:52:04 DEBUG : one: quickxor = 6f70431982000000000000000400000000000000 OK 2022/04/20 05:52:04 INFO : one: Copied (new) 2022/04/20 05:52:04 DEBUG : Waiting for deletions to finish 2022/04/20 05:52:05 INFO : three.txt: Moved (server-side) to: three.txt.bak 2022/04/20 05:52:05 INFO : three.txt: Moved into backup dir fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1753 sync_test.go:1784 Error: Should be true Test: TestSyncBackupDirWithSuffix Messages: listing wrong, want backup/one.bak (3), backup/three.txt.bak (5), dst/one (4), dst/two (3) got dst/one (4), dst/one.bak (3), dst/three.txt.bak (5), dst/two (3) fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1753 sync_test.go:1784 Error: Should be true Test: TestSyncBackupDirWithSuffix Messages: Unexpected file "dst/one.bak" fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1753 sync_test.go:1784 Error: Should be true Test: TestSyncBackupDirWithSuffix Messages: Unexpected file "dst/three.txt.bak" fstest.go:204: Not found "backup/three.txt.bak" fstest.go:204: Not found "backup/one.bak" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1753 sync_test.go:1784 Error: Not equal: expected: 0 actual : 2 Test: TestSyncBackupDirWithSuffix Messages: 2 objects not found 2022/04/20 05:52:15 DEBUG : dst/three.txt: Starting multipart upload 2022/04/20 05:52:16 DEBUG : dst/three.txt: Uploading segment 0/6 size 6 fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1759 sync_test.go:1784 Error: Should be true Test: TestSyncBackupDirWithSuffix Messages: listing wrong, want backup/one.bak (3), backup/three.txt.bak (5), dst/one (4), dst/three.txt (6), dst/two (3) got dst/one (4), dst/one.bak (3), dst/three.txt (6), dst/three.txt.bak (5), dst/two (3) fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1759 sync_test.go:1784 Error: Should be true Test: TestSyncBackupDirWithSuffix Messages: Unexpected file "dst/one.bak" fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1759 sync_test.go:1784 Error: Should be true Test: TestSyncBackupDirWithSuffix Messages: Unexpected file "dst/three.txt.bak" fstest.go:204: Not found "backup/one.bak" fstest.go:204: Not found "backup/three.txt.bak" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1759 sync_test.go:1784 Error: Not equal: expected: 0 actual : 2 Test: TestSyncBackupDirWithSuffix Messages: 2 objects not found 2022/04/20 05:52:26 DEBUG : one: Sizes differ (src 5 vs dst 4) 2022/04/20 05:52:26 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:52:26 DEBUG : two: Unchanged skipping 2022/04/20 05:52:26 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for checks to finish 2022/04/20 05:52:27 ERROR : one: Couldn't move: nameAlreadyExists: Name already exists 2022/04/20 05:52:27 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for transfers to finish 2022/04/20 05:52:27 ERROR : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': not deleting files as there were IO errors 2022/04/20 05:52:27 ERROR : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': not deleting directories as there were IO errors sync_test.go:1765: Error Trace: sync_test.go:1765 sync_test.go:1784 Error: Received unexpected error: nameAlreadyExists: Name already exists Test: TestSyncBackupDirWithSuffix --- FAIL: TestSyncBackupDirWithSuffix (37.02s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:52:31 DEBUG : dst/one: Starting multipart upload 2022/04/20 05:52:31 DEBUG : dst/one: Uploading segment 0/3 size 3 2022/04/20 05:52:32 DEBUG : dst/two: Starting multipart upload 2022/04/20 05:52:32 DEBUG : dst/two: Uploading segment 0/3 size 3 2022/04/20 05:52:33 DEBUG : dst/three.txt: Starting multipart upload 2022/04/20 05:52:34 DEBUG : dst/three.txt: Uploading segment 0/5 size 5 2022/04/20 05:52:35 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5/dst" 2022/04/20 05:52:36 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5/backup" 2022/04/20 05:52:38 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:52:38 DEBUG : two: Unchanged skipping 2022/04/20 05:52:38 DEBUG : one: Sizes differ (src 4 vs dst 3) 2022/04/20 05:52:38 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for checks to finish 2022/04/20 05:52:39 INFO : one: Moved (server-side) to: one-2019-01-01 2022/04/20 05:52:39 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for transfers to finish 2022/04/20 05:52:39 DEBUG : one: Starting multipart upload 2022/04/20 05:52:40 DEBUG : one: Uploading segment 0/4 size 4 2022/04/20 05:52:40 DEBUG : one: quickxor = 6f70431982000000000000000400000000000000 OK 2022/04/20 05:52:40 INFO : one: Copied (new) 2022/04/20 05:52:40 DEBUG : Waiting for deletions to finish 2022/04/20 05:52:41 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2022/04/20 05:52:41 INFO : three.txt: Moved into backup dir fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1753 sync_test.go:1787 Error: Should be true Test: TestSyncBackupDirWithSuffixKeepExtension Messages: listing wrong, want backup/one-2019-01-01 (3), backup/three-2019-01-01.txt (5), dst/one (4), dst/two (3) got dst/one (4), dst/one-2019-01-01 (3), dst/three-2019-01-01.txt (5), dst/two (3) fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1753 sync_test.go:1787 Error: Should be true Test: TestSyncBackupDirWithSuffixKeepExtension Messages: Unexpected file "dst/one-2019-01-01" fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1753 sync_test.go:1787 Error: Should be true Test: TestSyncBackupDirWithSuffixKeepExtension Messages: Unexpected file "dst/three-2019-01-01.txt" fstest.go:204: Not found "backup/three-2019-01-01.txt" fstest.go:204: Not found "backup/one-2019-01-01" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1753 sync_test.go:1787 Error: Not equal: expected: 0 actual : 2 Test: TestSyncBackupDirWithSuffixKeepExtension Messages: 2 objects not found 2022/04/20 05:52:52 DEBUG : dst/three.txt: Starting multipart upload 2022/04/20 05:52:52 DEBUG : dst/three.txt: Uploading segment 0/6 size 6 fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1759 sync_test.go:1787 Error: Should be true Test: TestSyncBackupDirWithSuffixKeepExtension Messages: listing wrong, want backup/one-2019-01-01 (3), backup/three-2019-01-01.txt (5), dst/one (4), dst/three.txt (6), dst/two (3) got dst/one (4), dst/one-2019-01-01 (3), dst/three-2019-01-01.txt (5), dst/three.txt (6), dst/two (3) fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1759 sync_test.go:1787 Error: Should be true Test: TestSyncBackupDirWithSuffixKeepExtension Messages: Unexpected file "dst/one-2019-01-01" fstest.go:192: Error Trace: fstest.go:192 fstest.go:309 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1759 sync_test.go:1787 Error: Should be true Test: TestSyncBackupDirWithSuffixKeepExtension Messages: Unexpected file "dst/three-2019-01-01.txt" fstest.go:204: Not found "backup/one-2019-01-01" fstest.go:204: Not found "backup/three-2019-01-01.txt" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:1759 sync_test.go:1787 Error: Not equal: expected: 0 actual : 2 Test: TestSyncBackupDirWithSuffixKeepExtension Messages: 2 objects not found 2022/04/20 05:53:03 DEBUG : one: Sizes differ (src 5 vs dst 4) 2022/04/20 05:53:03 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:53:03 DEBUG : two: Unchanged skipping 2022/04/20 05:53:03 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for checks to finish 2022/04/20 05:53:04 ERROR : one: Couldn't move: nameAlreadyExists: Name already exists 2022/04/20 05:53:04 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for transfers to finish 2022/04/20 05:53:04 ERROR : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': not deleting files as there were IO errors 2022/04/20 05:53:04 ERROR : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': not deleting directories as there were IO errors sync_test.go:1765: Error Trace: sync_test.go:1765 sync_test.go:1787 Error: Received unexpected error: nameAlreadyExists: Name already exists Test: TestSyncBackupDirWithSuffixKeepExtension --- FAIL: TestSyncBackupDirWithSuffixKeepExtension (37.61s) === RUN TestSyncBackupDirSuffixOnly run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:53:08 DEBUG : dst/one: Starting multipart upload 2022/04/20 05:53:09 DEBUG : dst/one: Uploading segment 0/3 size 3 2022/04/20 05:53:09 DEBUG : dst/two: Starting multipart upload 2022/04/20 05:53:10 DEBUG : dst/two: Uploading segment 0/3 size 3 2022/04/20 05:53:10 DEBUG : dst/three.txt: Starting multipart upload 2022/04/20 05:53:11 DEBUG : dst/three.txt: Uploading segment 0/5 size 5 2022/04/20 05:53:12 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5/dst" 2022/04/20 05:53:13 DEBUG : one: Sizes differ (src 4 vs dst 3) 2022/04/20 05:53:13 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:53:13 DEBUG : two: Unchanged skipping 2022/04/20 05:53:13 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for checks to finish 2022/04/20 05:53:14 INFO : one: Moved (server-side) to: one.bak 2022/04/20 05:53:14 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for transfers to finish 2022/04/20 05:53:14 DEBUG : one: Starting multipart upload 2022/04/20 05:53:15 DEBUG : one: Uploading segment 0/4 size 4 2022/04/20 05:53:15 DEBUG : one: quickxor = 6f70431982000000000000000400000000000000 OK 2022/04/20 05:53:15 INFO : one: Copied (new) 2022/04/20 05:53:15 DEBUG : Waiting for deletions to finish 2022/04/20 05:53:16 INFO : three.txt: Moved (server-side) to: three.txt.bak 2022/04/20 05:53:16 INFO : three.txt: Moved into backup dir 2022/04/20 05:53:17 DEBUG : dst/three.txt: Starting multipart upload 2022/04/20 05:53:18 DEBUG : dst/three.txt: Uploading segment 0/6 size 6 2022/04/20 05:53:19 DEBUG : one.bak: Excluded 2022/04/20 05:53:19 DEBUG : three.txt.bak: Excluded 2022/04/20 05:53:19 DEBUG : one: Sizes differ (src 5 vs dst 4) 2022/04/20 05:53:19 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:53:19 DEBUG : two: Unchanged skipping 2022/04/20 05:53:19 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for checks to finish 2022/04/20 05:53:20 INFO : one.bak: Deleted 2022/04/20 05:53:20 INFO : one: Moved (server-side) to: one.bak 2022/04/20 05:53:20 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5/dst': Waiting for transfers to finish 2022/04/20 05:53:20 DEBUG : one: Starting multipart upload 2022/04/20 05:53:21 DEBUG : one: Uploading segment 0/5 size 5 2022/04/20 05:53:21 DEBUG : one: quickxor = 6f70431984200400000000000500000000000000 OK 2022/04/20 05:53:21 INFO : one: Copied (new) 2022/04/20 05:53:21 DEBUG : Waiting for deletions to finish 2022/04/20 05:53:22 INFO : three.txt.bak: Deleted 2022/04/20 05:53:22 INFO : three.txt: Moved (server-side) to: three.txt.bak 2022/04/20 05:53:22 INFO : three.txt: Moved into backup dir --- PASS: TestSyncBackupDirSuffixOnly (18.61s) === RUN TestSyncSuffix run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:53:27 DEBUG : dst/one: Starting multipart upload 2022/04/20 05:53:27 DEBUG : dst/one: Uploading segment 0/3 size 3 2022/04/20 05:53:28 DEBUG : dst/two: Starting multipart upload 2022/04/20 05:53:29 DEBUG : dst/two: Uploading segment 0/3 size 3 2022/04/20 05:53:29 DEBUG : dst/three.txt: Starting multipart upload 2022/04/20 05:53:30 DEBUG : dst/three.txt: Uploading segment 0/5 size 5 2022/04/20 05:53:31 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5/dst" 2022/04/20 05:53:32 DEBUG : one: Sizes differ (src 4 vs dst 3) 2022/04/20 05:53:33 INFO : one: Moved (server-side) to: one.bak 2022/04/20 05:53:33 DEBUG : one: Starting multipart upload 2022/04/20 05:53:34 DEBUG : one: Uploading segment 0/4 size 4 2022/04/20 05:53:34 DEBUG : one: quickxor = 6f70431982000000000000000400000000000000 OK 2022/04/20 05:53:34 INFO : one: Copied (new) 2022/04/20 05:53:35 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:53:35 DEBUG : two: Unchanged skipping 2022/04/20 05:53:36 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2022/04/20 05:53:37 INFO : three.txt: Moved (server-side) to: three.txt.bak 2022/04/20 05:53:37 DEBUG : three.txt: Starting multipart upload 2022/04/20 05:53:37 DEBUG : three.txt: Uploading segment 0/6 size 6 2022/04/20 05:53:38 DEBUG : three.txt: quickxor = 7440831cca508620000000000600000000000000 OK 2022/04/20 05:53:38 INFO : three.txt: Copied (new) 2022/04/20 05:53:39 DEBUG : one: Sizes differ (src 5 vs dst 4) 2022/04/20 05:53:40 INFO : one.bak: Deleted 2022/04/20 05:53:41 INFO : one: Moved (server-side) to: one.bak 2022/04/20 05:53:41 DEBUG : one: Starting multipart upload 2022/04/20 05:53:41 DEBUG : one: Uploading segment 0/5 size 5 2022/04/20 05:53:42 DEBUG : one: quickxor = 6f70431984200400000000000500000000000000 OK 2022/04/20 05:53:42 INFO : one: Copied (new) 2022/04/20 05:53:43 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:53:43 DEBUG : two: Unchanged skipping 2022/04/20 05:53:43 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2022/04/20 05:53:44 INFO : three.txt.bak: Deleted 2022/04/20 05:53:44 INFO : three.txt: Moved (server-side) to: three.txt.bak 2022/04/20 05:53:44 DEBUG : three.txt: Starting multipart upload 2022/04/20 05:53:45 DEBUG : three.txt: Uploading segment 0/19 size 19 2022/04/20 05:53:46 DEBUG : three.txt: quickxor = 154aeacc8949062110210d66234319e4500637d0 OK 2022/04/20 05:53:46 INFO : three.txt: Copied (new) --- PASS: TestSyncSuffix (22.94s) === RUN TestSyncSuffixKeepExtension run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:53:50 DEBUG : dst/one: Starting multipart upload 2022/04/20 05:53:50 DEBUG : dst/one: Uploading segment 0/3 size 3 2022/04/20 05:53:51 DEBUG : dst/two: Starting multipart upload 2022/04/20 05:53:51 DEBUG : dst/two: Uploading segment 0/3 size 3 2022/04/20 05:53:52 DEBUG : dst/three.txt: Starting multipart upload 2022/04/20 05:53:52 DEBUG : dst/three.txt: Uploading segment 0/5 size 5 2022/04/20 05:53:54 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zirepet0zatoguz5parosak5/dst" 2022/04/20 05:53:55 DEBUG : one: Sizes differ (src 4 vs dst 3) 2022/04/20 05:53:56 INFO : one: Moved (server-side) to: one-2019-01-01 2022/04/20 05:53:56 DEBUG : one: Starting multipart upload 2022/04/20 05:53:57 DEBUG : one: Uploading segment 0/4 size 4 2022/04/20 05:53:57 DEBUG : one: quickxor = 6f70431982000000000000000400000000000000 OK 2022/04/20 05:53:57 INFO : one: Copied (new) 2022/04/20 05:53:58 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:53:58 DEBUG : two: Unchanged skipping 2022/04/20 05:53:58 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2022/04/20 05:53:59 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2022/04/20 05:53:59 DEBUG : three.txt: Starting multipart upload 2022/04/20 05:54:00 DEBUG : three.txt: Uploading segment 0/6 size 6 2022/04/20 05:54:00 DEBUG : three.txt: quickxor = 7440831cca508620000000000600000000000000 OK 2022/04/20 05:54:00 INFO : three.txt: Copied (new) 2022/04/20 05:54:02 DEBUG : one: Sizes differ (src 5 vs dst 4) 2022/04/20 05:54:03 INFO : one-2019-01-01: Deleted 2022/04/20 05:54:04 INFO : one: Moved (server-side) to: one-2019-01-01 2022/04/20 05:54:04 DEBUG : one: Starting multipart upload 2022/04/20 05:54:04 DEBUG : one: Uploading segment 0/5 size 5 2022/04/20 05:54:05 DEBUG : one: quickxor = 6f70431984200400000000000500000000000000 OK 2022/04/20 05:54:05 INFO : one: Copied (new) 2022/04/20 05:54:05 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:54:05 DEBUG : two: Unchanged skipping 2022/04/20 05:54:06 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2022/04/20 05:54:07 INFO : three-2019-01-01.txt: Deleted 2022/04/20 05:54:07 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2022/04/20 05:54:07 DEBUG : three.txt: Starting multipart upload 2022/04/20 05:54:08 DEBUG : three.txt: Uploading segment 0/19 size 19 2022/04/20 05:54:08 DEBUG : three.txt: quickxor = 154aeacc8949062110210d66234319e4500637d0 OK 2022/04/20 05:54:08 INFO : three.txt: Copied (new) --- PASS: TestSyncSuffixKeepExtension (21.96s) === RUN TestSyncUTFNorm run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:54:11 DEBUG : Testêé: Starting multipart upload 2022/04/20 05:54:12 DEBUG : Testêé: Uploading segment 0/18 size 18 2022/04/20 05:54:13 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2022/04/20 05:54:13 DEBUG : Testêé: Starting multipart upload 2022/04/20 05:54:13 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:54:13 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:54:13 DEBUG : Testêé: Uploading segment 0/14 size 14 2022/04/20 05:54:14 DEBUG : Testêé: quickxor = 5440431ae6008234cc0104610e011dca30073a00 OK 2022/04/20 05:54:14 INFO : Testêé: Copied (replaced existing) to: Testêé 2022/04/20 05:54:14 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (3.78s) === RUN TestSyncImmutable run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:54:15 DEBUG : existing: Starting multipart upload 2022/04/20 05:54:15 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:54:15 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:54:16 DEBUG : existing: Uploading segment 0/6 size 6 2022/04/20 05:54:16 DEBUG : existing: quickxor = 7078031dc2408737000000000600000000000000 OK 2022/04/20 05:54:16 INFO : existing: Copied (new) 2022/04/20 05:54:16 DEBUG : Waiting for deletions to finish 2022/04/20 05:54:17 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2022/04/20 05:54:17 ERROR : existing: Source and destination exist but do not match: immutable file modified 2022/04/20 05:54:17 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:54:17 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:54:17 ERROR : One drive root 'rclone-test-zirepet0zatoguz5parosak5': not deleting files as there were IO errors 2022/04/20 05:54:17 ERROR : One drive root 'rclone-test-zirepet0zatoguz5parosak5': not deleting directories as there were IO errors --- PASS: TestSyncImmutable (3.61s) === RUN TestSyncIgnoreCase run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" sync_test.go:1955: Skipping test as local or remote are case-insensitive --- SKIP: TestSyncIgnoreCase (0.54s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" sync_test.go:1989: This test only runs on local === RUN TestMaxTransfer/Soft run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" sync_test.go:1989: This test only runs on local === RUN TestMaxTransfer/Cautious run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" sync_test.go:1989: This test only runs on local --- PASS: TestMaxTransfer (1.58s) --- SKIP: TestMaxTransfer/Hard (0.53s) --- SKIP: TestMaxTransfer/Soft (0.52s) --- SKIP: TestMaxTransfer/Cautious (0.53s) === RUN TestSyncConcurrentDelete run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:54:21 DEBUG : both0: Starting multipart upload 2022/04/20 05:54:21 DEBUG : both0: Uploading segment 0/6 size 6 2022/04/20 05:54:22 DEBUG : only0: Starting multipart upload 2022/04/20 05:54:22 DEBUG : only0: Uploading segment 0/6 size 6 2022/04/20 05:54:23 DEBUG : both1: Starting multipart upload 2022/04/20 05:54:23 DEBUG : both1: Uploading segment 0/6 size 6 2022/04/20 05:54:24 DEBUG : only1: Starting multipart upload 2022/04/20 05:54:24 DEBUG : only1: Uploading segment 0/6 size 6 2022/04/20 05:54:25 DEBUG : both2: Starting multipart upload 2022/04/20 05:54:26 DEBUG : both2: Uploading segment 0/6 size 6 2022/04/20 05:54:26 DEBUG : only2: Starting multipart upload 2022/04/20 05:54:27 DEBUG : only2: Uploading segment 0/6 size 6 2022/04/20 05:54:27 DEBUG : both3: Starting multipart upload 2022/04/20 05:54:28 DEBUG : both3: Uploading segment 0/6 size 6 2022/04/20 05:54:28 DEBUG : only3: Starting multipart upload 2022/04/20 05:54:29 DEBUG : only3: Uploading segment 0/6 size 6 2022/04/20 05:54:29 DEBUG : both4: Starting multipart upload 2022/04/20 05:54:30 DEBUG : both4: Uploading segment 0/6 size 6 2022/04/20 05:54:31 DEBUG : only4: Starting multipart upload 2022/04/20 05:54:31 DEBUG : only4: Uploading segment 0/6 size 6 2022/04/20 05:54:32 DEBUG : both5: Starting multipart upload 2022/04/20 05:54:32 DEBUG : both5: Uploading segment 0/6 size 6 2022/04/20 05:54:33 DEBUG : only5: Starting multipart upload 2022/04/20 05:54:33 DEBUG : only5: Uploading segment 0/6 size 6 2022/04/20 05:54:34 DEBUG : both6: Starting multipart upload 2022/04/20 05:54:35 DEBUG : both6: Uploading segment 0/6 size 6 2022/04/20 05:54:35 DEBUG : only6: Starting multipart upload 2022/04/20 05:54:36 DEBUG : only6: Uploading segment 0/6 size 6 2022/04/20 05:54:36 DEBUG : both7: Starting multipart upload 2022/04/20 05:54:37 DEBUG : both7: Uploading segment 0/6 size 6 2022/04/20 05:54:37 DEBUG : only7: Starting multipart upload 2022/04/20 05:54:38 DEBUG : only7: Uploading segment 0/6 size 6 2022/04/20 05:54:39 DEBUG : both8: Starting multipart upload 2022/04/20 05:54:39 DEBUG : both8: Uploading segment 0/6 size 6 2022/04/20 05:54:40 DEBUG : only8: Starting multipart upload 2022/04/20 05:54:40 DEBUG : only8: Uploading segment 0/6 size 6 2022/04/20 05:54:41 DEBUG : both9: Starting multipart upload 2022/04/20 05:54:41 DEBUG : both9: Uploading segment 0/6 size 6 2022/04/20 05:54:42 DEBUG : only9: Starting multipart upload 2022/04/20 05:54:43 DEBUG : only9: Uploading segment 0/6 size 6 2022/04/20 05:54:43 DEBUG : both10: Starting multipart upload 2022/04/20 05:54:44 DEBUG : both10: Uploading segment 0/6 size 6 2022/04/20 05:54:44 DEBUG : only10: Starting multipart upload 2022/04/20 05:54:45 DEBUG : only10: Uploading segment 0/6 size 6 2022/04/20 05:54:45 DEBUG : both11: Starting multipart upload 2022/04/20 05:54:46 DEBUG : both11: Uploading segment 0/6 size 6 2022/04/20 05:54:47 DEBUG : only11: Starting multipart upload 2022/04/20 05:54:47 DEBUG : only11: Uploading segment 0/6 size 6 2022/04/20 05:54:48 DEBUG : both12: Starting multipart upload 2022/04/20 05:54:48 DEBUG : both12: Uploading segment 0/6 size 6 2022/04/20 05:54:49 DEBUG : only12: Starting multipart upload 2022/04/20 05:54:49 DEBUG : only12: Uploading segment 0/6 size 6 2022/04/20 05:54:50 DEBUG : both13: Starting multipart upload 2022/04/20 05:54:50 DEBUG : both13: Uploading segment 0/6 size 6 2022/04/20 05:54:51 DEBUG : only13: Starting multipart upload 2022/04/20 05:54:51 DEBUG : only13: Uploading segment 0/6 size 6 2022/04/20 05:54:52 DEBUG : both14: Starting multipart upload 2022/04/20 05:54:53 DEBUG : both14: Uploading segment 0/6 size 6 2022/04/20 05:54:53 DEBUG : only14: Starting multipart upload 2022/04/20 05:54:54 DEBUG : only14: Uploading segment 0/6 size 6 2022/04/20 05:54:54 DEBUG : both15: Starting multipart upload 2022/04/20 05:54:55 DEBUG : both15: Uploading segment 0/6 size 6 2022/04/20 05:54:55 DEBUG : only15: Starting multipart upload 2022/04/20 05:54:56 DEBUG : only15: Uploading segment 0/6 size 6 2022/04/20 05:54:57 DEBUG : both16: Starting multipart upload 2022/04/20 05:54:58 DEBUG : both16: Uploading segment 0/6 size 6 2022/04/20 05:54:58 DEBUG : only16: Starting multipart upload 2022/04/20 05:54:59 DEBUG : only16: Uploading segment 0/6 size 6 2022/04/20 05:54:59 DEBUG : both17: Starting multipart upload 2022/04/20 05:55:00 DEBUG : both17: Uploading segment 0/6 size 6 2022/04/20 05:55:01 DEBUG : only17: Starting multipart upload 2022/04/20 05:55:01 DEBUG : only17: Uploading segment 0/6 size 6 2022/04/20 05:55:02 DEBUG : both18: Starting multipart upload 2022/04/20 05:55:03 DEBUG : both18: Uploading segment 0/6 size 6 2022/04/20 05:55:03 DEBUG : only18: Starting multipart upload 2022/04/20 05:55:04 DEBUG : only18: Uploading segment 0/6 size 6 2022/04/20 05:55:05 DEBUG : both19: Starting multipart upload 2022/04/20 05:55:06 DEBUG : both19: Uploading segment 0/6 size 6 2022/04/20 05:55:06 DEBUG : only19: Starting multipart upload 2022/04/20 05:55:07 DEBUG : only19: Uploading segment 0/6 size 6 2022/04/20 05:55:09 DEBUG : both0: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both0: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both1: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both1: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both10: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both10: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both11: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both11: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both12: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both12: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both13: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both13: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both14: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both14: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both15: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both15: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both16: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both16: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both17: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both17: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both18: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both18: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both19: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both19: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both2: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both2: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both3: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both3: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both4: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both4: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both5: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both5: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both6: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both6: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both7: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both7: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both8: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both8: Unchanged skipping 2022/04/20 05:55:09 DEBUG : both9: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:55:09 DEBUG : both9: Unchanged skipping 2022/04/20 05:55:09 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:55:09 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:55:09 DEBUG : Waiting for deletions to finish 2022/04/20 05:55:09 INFO : only12: Deleted 2022/04/20 05:55:10 INFO : only16: Deleted 2022/04/20 05:55:10 INFO : only2: Deleted 2022/04/20 05:55:10 INFO : only18: Deleted 2022/04/20 05:55:10 INFO : only1: Deleted 2022/04/20 05:55:10 INFO : only3: Deleted 2022/04/20 05:55:10 INFO : only11: Deleted 2022/04/20 05:55:10 INFO : only19: Deleted 2022/04/20 05:55:10 INFO : only14: Deleted 2022/04/20 05:55:10 INFO : only4: Deleted 2022/04/20 05:55:10 INFO : only15: Deleted 2022/04/20 05:55:10 INFO : only5: Deleted 2022/04/20 05:55:10 INFO : only7: Deleted 2022/04/20 05:55:10 INFO : only8: Deleted 2022/04/20 05:55:10 INFO : only10: Deleted 2022/04/20 05:55:10 INFO : only13: Deleted 2022/04/20 05:55:11 INFO : only9: Deleted 2022/04/20 05:55:11 INFO : only0: Deleted 2022/04/20 05:55:11 INFO : only17: Deleted 2022/04/20 05:55:11 INFO : only6: Deleted 2022/04/20 05:55:11 INFO : There was nothing to transfer --- PASS: TestSyncConcurrentDelete (54.64s) === RUN TestSyncConcurrentTruncate run.go:181: Remote "One drive root 'rclone-test-zirepet0zatoguz5parosak5'", Local "Local file system at /tmp/rclone1468494239", Modify Window "1s" 2022/04/20 05:55:15 DEBUG : both0: Starting multipart upload 2022/04/20 05:55:16 DEBUG : both0: Uploading segment 0/6 size 6 2022/04/20 05:55:16 DEBUG : only0: Starting multipart upload 2022/04/20 05:55:17 DEBUG : only0: Uploading segment 0/6 size 6 2022/04/20 05:55:17 DEBUG : both1: Starting multipart upload 2022/04/20 05:55:18 DEBUG : both1: Uploading segment 0/6 size 6 2022/04/20 05:55:18 DEBUG : only1: Starting multipart upload 2022/04/20 05:55:19 DEBUG : only1: Uploading segment 0/6 size 6 2022/04/20 05:55:20 DEBUG : both2: Starting multipart upload 2022/04/20 05:55:20 DEBUG : both2: Uploading segment 0/6 size 6 2022/04/20 05:55:21 DEBUG : only2: Starting multipart upload 2022/04/20 05:55:22 DEBUG : only2: Uploading segment 0/6 size 6 2022/04/20 05:55:22 DEBUG : both3: Starting multipart upload 2022/04/20 05:55:23 DEBUG : both3: Uploading segment 0/6 size 6 2022/04/20 05:55:24 DEBUG : only3: Starting multipart upload 2022/04/20 05:55:24 DEBUG : only3: Uploading segment 0/6 size 6 2022/04/20 05:55:25 DEBUG : both4: Starting multipart upload 2022/04/20 05:55:26 DEBUG : both4: Uploading segment 0/6 size 6 2022/04/20 05:55:26 DEBUG : only4: Starting multipart upload 2022/04/20 05:55:27 DEBUG : only4: Uploading segment 0/6 size 6 2022/04/20 05:55:27 DEBUG : both5: Starting multipart upload 2022/04/20 05:55:28 DEBUG : both5: Uploading segment 0/6 size 6 2022/04/20 05:55:28 DEBUG : only5: Starting multipart upload 2022/04/20 05:55:29 DEBUG : only5: Uploading segment 0/6 size 6 2022/04/20 05:55:29 DEBUG : both6: Starting multipart upload 2022/04/20 05:55:30 DEBUG : both6: Uploading segment 0/6 size 6 2022/04/20 05:55:31 DEBUG : only6: Starting multipart upload 2022/04/20 05:55:31 DEBUG : only6: Uploading segment 0/6 size 6 2022/04/20 05:55:32 DEBUG : both7: Starting multipart upload 2022/04/20 05:55:33 DEBUG : both7: Uploading segment 0/6 size 6 2022/04/20 05:55:33 DEBUG : only7: Starting multipart upload 2022/04/20 05:55:34 DEBUG : only7: Uploading segment 0/6 size 6 2022/04/20 05:55:34 DEBUG : both8: Starting multipart upload 2022/04/20 05:55:35 DEBUG : both8: Uploading segment 0/6 size 6 2022/04/20 05:55:35 DEBUG : only8: Starting multipart upload 2022/04/20 05:55:36 DEBUG : only8: Uploading segment 0/6 size 6 2022/04/20 05:55:37 DEBUG : both9: Starting multipart upload 2022/04/20 05:55:37 DEBUG : both9: Uploading segment 0/6 size 6 2022/04/20 05:55:38 DEBUG : only9: Starting multipart upload 2022/04/20 05:55:38 DEBUG : only9: Uploading segment 0/6 size 6 2022/04/20 05:55:39 DEBUG : both10: Starting multipart upload 2022/04/20 05:55:40 DEBUG : both10: Uploading segment 0/6 size 6 2022/04/20 05:55:40 DEBUG : only10: Starting multipart upload 2022/04/20 05:55:41 DEBUG : only10: Uploading segment 0/6 size 6 2022/04/20 05:55:42 DEBUG : both11: Starting multipart upload 2022/04/20 05:55:42 DEBUG : both11: Uploading segment 0/6 size 6 2022/04/20 05:55:43 DEBUG : only11: Starting multipart upload 2022/04/20 05:55:43 DEBUG : only11: Uploading segment 0/6 size 6 2022/04/20 05:55:44 DEBUG : both12: Starting multipart upload 2022/04/20 05:55:44 DEBUG : both12: Uploading segment 0/6 size 6 2022/04/20 05:55:45 DEBUG : only12: Starting multipart upload 2022/04/20 05:55:46 DEBUG : only12: Uploading segment 0/6 size 6 2022/04/20 05:55:46 DEBUG : both13: Starting multipart upload 2022/04/20 05:55:47 DEBUG : both13: Uploading segment 0/6 size 6 2022/04/20 05:55:48 DEBUG : only13: Starting multipart upload 2022/04/20 05:55:48 DEBUG : only13: Uploading segment 0/6 size 6 2022/04/20 05:55:49 DEBUG : both14: Starting multipart upload 2022/04/20 05:55:50 DEBUG : both14: Uploading segment 0/6 size 6 2022/04/20 05:55:50 DEBUG : only14: Starting multipart upload 2022/04/20 05:55:52 DEBUG : only14: Uploading segment 0/6 size 6 2022/04/20 05:55:53 DEBUG : both15: Starting multipart upload 2022/04/20 05:55:53 DEBUG : both15: Uploading segment 0/6 size 6 2022/04/20 05:55:54 DEBUG : only15: Starting multipart upload 2022/04/20 05:55:55 DEBUG : only15: Uploading segment 0/6 size 6 2022/04/20 05:55:55 DEBUG : both16: Starting multipart upload 2022/04/20 05:55:56 DEBUG : both16: Uploading segment 0/6 size 6 2022/04/20 05:55:56 DEBUG : only16: Starting multipart upload 2022/04/20 05:55:57 DEBUG : only16: Uploading segment 0/6 size 6 2022/04/20 05:55:57 DEBUG : both17: Starting multipart upload 2022/04/20 05:55:58 DEBUG : both17: Uploading segment 0/6 size 6 2022/04/20 05:55:58 DEBUG : only17: Starting multipart upload 2022/04/20 05:55:59 DEBUG : only17: Uploading segment 0/6 size 6 2022/04/20 05:56:00 DEBUG : both18: Starting multipart upload 2022/04/20 05:56:00 DEBUG : both18: Uploading segment 0/6 size 6 2022/04/20 05:56:01 DEBUG : only18: Starting multipart upload 2022/04/20 05:56:01 DEBUG : only18: Uploading segment 0/6 size 6 2022/04/20 05:56:02 DEBUG : both19: Starting multipart upload 2022/04/20 05:56:02 DEBUG : both19: Uploading segment 0/6 size 6 2022/04/20 05:56:03 DEBUG : only19: Starting multipart upload 2022/04/20 05:56:03 DEBUG : only19: Uploading segment 0/6 size 6 2022/04/20 05:56:05 DEBUG : both0: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both0: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both1: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both1: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both10: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both10: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both11: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both11: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both12: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both12: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both13: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both13: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both14: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both14: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both15: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both15: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both16: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both16: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both17: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both17: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both18: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both18: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both19: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both19: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both2: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both2: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both3: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both3: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both4: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both4: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both5: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both5: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both6: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both6: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both7: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both7: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both8: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both8: Unchanged skipping 2022/04/20 05:56:05 DEBUG : both9: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/04/20 05:56:05 DEBUG : both9: Unchanged skipping 2022/04/20 05:56:05 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : only0: Starting singlepart upload 2022/04/20 05:56:05 DEBUG : only1: Starting singlepart upload 2022/04/20 05:56:05 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : only10: Starting singlepart upload 2022/04/20 05:56:05 DEBUG : only11: Starting singlepart upload 2022/04/20 05:56:05 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for checks to finish 2022/04/20 05:56:05 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2022/04/20 05:56:05 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Waiting for transfers to finish 2022/04/20 05:56:05 DEBUG : only1: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:05 DEBUG : only1: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:05 ERROR : only1: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:05 INFO : only1: Removing failed copy 2022/04/20 05:56:06 DEBUG : only0: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:06 DEBUG : only0: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:06 ERROR : only0: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:06 INFO : only0: Removing failed copy 2022/04/20 05:56:06 DEBUG : only11: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:06 DEBUG : only11: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:06 ERROR : only11: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:06 INFO : only11: Removing failed copy 2022/04/20 05:56:06 DEBUG : only12: Starting singlepart upload 2022/04/20 05:56:06 DEBUG : only13: Starting singlepart upload 2022/04/20 05:56:06 DEBUG : only14: Starting singlepart upload 2022/04/20 05:56:06 DEBUG : only10: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:06 DEBUG : only10: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:06 ERROR : only10: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:06 INFO : only10: Removing failed copy 2022/04/20 05:56:06 DEBUG : only15: Starting singlepart upload 2022/04/20 05:56:07 DEBUG : only12: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:07 DEBUG : only12: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:07 ERROR : only12: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:07 INFO : only12: Removing failed copy 2022/04/20 05:56:07 DEBUG : only13: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:07 DEBUG : only13: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:07 ERROR : only13: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:07 INFO : only13: Removing failed copy 2022/04/20 05:56:07 DEBUG : only14: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:07 DEBUG : only14: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:07 ERROR : only14: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:07 INFO : only14: Removing failed copy 2022/04/20 05:56:07 DEBUG : only16: Starting singlepart upload 2022/04/20 05:56:07 DEBUG : only17: Starting singlepart upload 2022/04/20 05:56:07 DEBUG : only18: Starting singlepart upload 2022/04/20 05:56:07 DEBUG : only15: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:07 DEBUG : only15: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:07 ERROR : only15: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:07 INFO : only15: Removing failed copy 2022/04/20 05:56:08 DEBUG : only19: Starting singlepart upload 2022/04/20 05:56:08 DEBUG : only16: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:08 DEBUG : only16: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:08 ERROR : only16: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:08 INFO : only16: Removing failed copy 2022/04/20 05:56:08 DEBUG : only2: Starting singlepart upload 2022/04/20 05:56:09 DEBUG : only18: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:09 DEBUG : only18: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:09 ERROR : only18: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:09 INFO : only18: Removing failed copy 2022/04/20 05:56:09 DEBUG : only19: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:09 DEBUG : only19: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:09 ERROR : only19: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:09 INFO : only19: Removing failed copy 2022/04/20 05:56:09 DEBUG : only3: Starting singlepart upload 2022/04/20 05:56:10 DEBUG : only17: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:10 DEBUG : only17: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:10 ERROR : only17: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:10 INFO : only17: Removing failed copy 2022/04/20 05:56:10 DEBUG : only2: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:10 DEBUG : only2: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:10 ERROR : only2: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:10 INFO : only2: Removing failed copy 2022/04/20 05:56:10 DEBUG : only4: Starting singlepart upload 2022/04/20 05:56:10 DEBUG : only5: Starting singlepart upload 2022/04/20 05:56:10 DEBUG : only6: Starting singlepart upload 2022/04/20 05:56:10 DEBUG : only3: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:10 DEBUG : only3: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:10 ERROR : only3: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:10 INFO : only3: Removing failed copy 2022/04/20 05:56:11 DEBUG : only7: Starting singlepart upload 2022/04/20 05:56:11 DEBUG : only5: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:11 DEBUG : only5: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:11 ERROR : only5: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:11 INFO : only5: Removing failed copy 2022/04/20 05:56:11 DEBUG : only4: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:11 DEBUG : only4: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:11 ERROR : only4: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:11 INFO : only4: Removing failed copy 2022/04/20 05:56:11 DEBUG : only6: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:11 DEBUG : only6: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:11 ERROR : only6: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:11 INFO : only6: Removing failed copy 2022/04/20 05:56:12 DEBUG : only9: Starting singlepart upload 2022/04/20 05:56:12 DEBUG : only8: Starting singlepart upload 2022/04/20 05:56:12 DEBUG : only7: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:12 DEBUG : only7: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:12 ERROR : only7: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:12 INFO : only7: Removing failed copy 2022/04/20 05:56:13 DEBUG : only9: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:13 DEBUG : only9: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:13 ERROR : only9: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:13 INFO : only9: Removing failed copy 2022/04/20 05:56:13 DEBUG : only8: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1468494239) 2022/04/20 05:56:13 DEBUG : only8: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-zirepet0zatoguz5parosak5') 2022/04/20 05:56:13 ERROR : only8: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2022/04/20 05:56:13 INFO : only8: Removing failed copy 2022/04/20 05:56:13 ERROR : One drive root 'rclone-test-zirepet0zatoguz5parosak5': not deleting files as there were IO errors 2022/04/20 05:56:13 ERROR : One drive root 'rclone-test-zirepet0zatoguz5parosak5': not deleting directories as there were IO errors sync_test.go:2056: Error Trace: sync_test.go:2056 sync_test.go:2066 Error: Received unexpected error: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" Test: TestSyncConcurrentTruncate Messages: Sync must not return a error sync_test.go:2057: Error Trace: sync_test.go:2057 sync_test.go:2066 Error: Should be false Test: TestSyncConcurrentTruncate Messages: Low level errors must not have happened fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:2058 sync_test.go:2066 Error: Should be true Test: TestSyncConcurrentTruncate Messages: listing wrong, want both0 (6), both1 (6), both10 (6), both11 (6), both12 (6), both13 (6), both14 (6), both15 (6), both16 (6), both17 (6), both18 (6), both19 (6), both2 (6), both3 (6), both4 (6), both5 (6), both6 (6), both7 (6), both8 (6), both9 (6), only0 (0), only1 (0), only10 (0), only11 (0), only12 (0), only13 (0), only14 (0), only15 (0), only16 (0), only17 (0), only18 (0), only19 (0), only2 (0), only3 (0), only4 (0), only5 (0), only6 (0), only7 (0), only8 (0), only9 (0) got both0 (6), both1 (6), both10 (6), both11 (6), both12 (6), both13 (6), both14 (6), both15 (6), both16 (6), both17 (6), both18 (6), both19 (6), both2 (6), both3 (6), both4 (6), both5 (6), both6 (6), both7 (6), both8 (6), both9 (6) fstest.go:204: Not found "only2" fstest.go:204: Not found "only11" fstest.go:204: Not found "only3" fstest.go:204: Not found "only12" fstest.go:204: Not found "only13" fstest.go:204: Not found "only0" fstest.go:204: Not found "only6" fstest.go:204: Not found "only7" fstest.go:204: Not found "only9" fstest.go:204: Not found "only15" fstest.go:204: Not found "only14" fstest.go:204: Not found "only18" fstest.go:204: Not found "only19" fstest.go:204: Not found "only10" fstest.go:204: Not found "only16" fstest.go:204: Not found "only1" fstest.go:204: Not found "only5" fstest.go:204: Not found "only8" fstest.go:204: Not found "only4" fstest.go:204: Not found "only17" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:2058 sync_test.go:2066 Error: Not equal: expected: 0 actual : 20 Test: TestSyncConcurrentTruncate Messages: 20 objects not found --- FAIL: TestSyncConcurrentTruncate (72.69s) FAIL 2022/04/20 05:56:28 DEBUG : One drive root 'rclone-test-zirepet0zatoguz5parosak5': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestOneDriveBusiness: -verbose" - Finished ERROR in 13m49.529885996s (try 1/5): exit status 1: Failed [TestServerSideCopy TestSyncWithTrackRenamesStrategyLeaf TestServerSideMove TestServerSideMoveWithFilter TestServerSideMoveDeleteEmptySourceDirs TestSyncCopyDest TestSyncBackupDir TestSyncBackupDirWithSuffix TestSyncBackupDirWithSuffixKeepExtension TestSyncConcurrentTruncate]