"./operations.test -test.v -test.timeout 1h0m0s -remote TestOneDriveBusiness: -verbose -test.run '^(TestCopyFileBackupDir|TestCopyFileCopyDest|TestDirMove|TestMoveFileBackupDir)$'" - Starting (try 4/5) 2022/04/20 06:45:45 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-qewolal8fegociy7sawazeh5" 2022/04/20 06:45:45 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2022/04/20 06:45:46 DEBUG : Creating backend with remote "/tmp/rclone187799435" === RUN TestMoveFileBackupDir run.go:181: Remote "One drive root 'rclone-test-qewolal8fegociy7sawazeh5'", Local "Local file system at /tmp/rclone187799435", Modify Window "1s" 2022/04/20 06:45:48 DEBUG : dst/file1: Starting multipart upload 2022/04/20 06:45:49 DEBUG : dst/file1: Uploading segment 0/18 size 18 2022/04/20 06:45:51 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-qewolal8fegociy7sawazeh5/backup" 2022/04/20 06:45:53 DEBUG : dst/file1: Sizes differ (src 14 vs dst 18) 2022/04/20 06:45:55 INFO : dst/file1: Moved (server-side) 2022/04/20 06:45:55 DEBUG : dst/file1: Starting multipart upload 2022/04/20 06:45:55 DEBUG : dst/file1: Uploading segment 0/14 size 14 2022/04/20 06:45:56 DEBUG : dst/file1: quickxor = 6648031bca1003108ce10d6eae4319dc40873900 OK 2022/04/20 06:45:56 INFO : dst/file1: Copied (new) 2022/04/20 06:45:56 INFO : dst/file1: Deleted 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 operations_test.go:929 Error: Should be true Test: TestMoveFileBackupDir Messages: listing wrong, want backup/dst/file1 (18), dst/file1 (14) got dst/file1 (14) fstest.go:204: Not found "backup/dst/file1" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 operations_test.go:929 Error: Not equal: expected: 0 actual : 1 Test: TestMoveFileBackupDir Messages: 1 objects not found --- FAIL: TestMoveFileBackupDir (23.21s) === RUN TestCopyFileBackupDir run.go:181: Remote "One drive root 'rclone-test-qewolal8fegociy7sawazeh5'", Local "Local file system at /tmp/rclone187799435", Modify Window "1s" 2022/04/20 06:46:10 DEBUG : dst/file1: Starting multipart upload 2022/04/20 06:46:10 DEBUG : dst/file1: Uploading segment 0/18 size 18 2022/04/20 06:46:12 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-qewolal8fegociy7sawazeh5/backup" 2022/04/20 06:46:14 DEBUG : dst/file1: Sizes differ (src 14 vs dst 18) 2022/04/20 06:46:16 INFO : dst/file1: Moved (server-side) 2022/04/20 06:46:16 DEBUG : dst/file1: Starting multipart upload 2022/04/20 06:46:16 DEBUG : dst/file1: Uploading segment 0/14 size 14 2022/04/20 06:46:17 DEBUG : dst/file1: quickxor = 6648031bca1003108ce10d6eae4319dc40873900 OK 2022/04/20 06:46:17 INFO : dst/file1: Copied (new) 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 operations_test.go:980 Error: Should be true Test: TestCopyFileBackupDir Messages: listing wrong, want backup/dst/file1 (18), dst/file1 (14) got dst/file1 (14) fstest.go:204: Not found "backup/dst/file1" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 operations_test.go:980 Error: Not equal: expected: 0 actual : 1 Test: TestCopyFileBackupDir Messages: 1 objects not found --- FAIL: TestCopyFileBackupDir (20.84s) === RUN TestCopyFileCopyDest run.go:181: Remote "One drive root 'rclone-test-qewolal8fegociy7sawazeh5'", Local "Local file system at /tmp/rclone187799435", Modify Window "1s" 2022/04/20 06:46:30 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-qewolal8fegociy7sawazeh5/dst" 2022/04/20 06:46:33 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-qewolal8fegociy7sawazeh5/CopyDest" 2022/04/20 06:46:35 DEBUG : one: Need to transfer - File not found at Destination 2022/04/20 06:46:36 DEBUG : one: Starting multipart upload 2022/04/20 06:46:37 DEBUG : one: Uploading segment 0/3 size 3 2022/04/20 06:46:37 DEBUG : one: quickxor = 6f70431900000000000000000300000000000000 OK 2022/04/20 06:46:37 INFO : one: Copied (new) 2022/04/20 06:46:40 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/04/20 06:46:40 DEBUG : one: Starting multipart upload 2022/04/20 06:46:40 DEBUG : one: Uploading segment 0/5 size 5 2022/04/20 06:46:41 DEBUG : one: quickxor = 6f704319e8200300000000000500000000000000 OK 2022/04/20 06:46:41 INFO : one: Copied (replaced existing) 2022/04/20 06:46:41 DEBUG : dst/one: Starting multipart upload 2022/04/20 06:46:42 DEBUG : dst/one: Uploading segment 0/3 size 3 2022/04/20 06:46:43 DEBUG : CopyDest/one: Starting multipart upload 2022/04/20 06:46:44 DEBUG : CopyDest/one: Uploading segment 0/5 size 5 2022/04/20 06:46:46 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-qewolal8fegociy7sawazeh5/BackupDir" 2022/04/20 06:46:48 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 06:46:48 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/04/20 06:46:49 INFO : one: Moved (server-side) 2022/04/20 06:46:50 ERROR : one: Failed to copy: nameAlreadyExists: The specified item name already exists. 2022/04/20 06:46:50 ERROR : one: Destination found in --copy-dest, error copying 2022/04/20 06:46:50 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/04/20 06:46:51 INFO : one: Moved (server-side) 2022/04/20 06:46:51 DEBUG : one: Starting multipart upload 2022/04/20 06:46:51 DEBUG : one: Uploading segment 0/5 size 5 2022/04/20 06:46:52 DEBUG : one: quickxor = 6f704319e8200300000000000500000000000000 OK 2022/04/20 06:46:52 INFO : one: Copied (new) 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 operations_test.go:1120 Error: Should be true Test: TestCopyFileCopyDest Messages: listing wrong, want BackupDir/one (3), CopyDest/one (5), dst/one (5) got CopyDest/one (5), dst/one (5) fstest.go:204: Not found "BackupDir/one" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 operations_test.go:1120 Error: Not equal: expected: 0 actual : 1 Test: TestCopyFileCopyDest Messages: 1 objects not found 2022/04/20 06:47:02 DEBUG : CopyDest/two: Starting multipart upload 2022/04/20 06:47:03 DEBUG : CopyDest/two: Uploading segment 0/3 size 3 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 operations_test.go:1126 Error: Should be true Test: TestCopyFileCopyDest Messages: listing wrong, want BackupDir/one (3), CopyDest/one (5), CopyDest/two (3), dst/one (5) got CopyDest/one (5), CopyDest/two (3), dst/one (5) fstest.go:204: Not found "BackupDir/one" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 operations_test.go:1126 Error: Not equal: expected: 0 actual : 1 Test: TestCopyFileCopyDest Messages: 1 objects not found 2022/04/20 06:47:14 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 06:47:15 ERROR : two: Failed to copy: nameAlreadyExists: The specified item name already exists. 2022/04/20 06:47:15 ERROR : two: Destination found in --copy-dest, error copying 2022/04/20 06:47:15 DEBUG : two: Need to transfer - File not found at Destination 2022/04/20 06:47:15 DEBUG : two: Starting multipart upload 2022/04/20 06:47:15 DEBUG : two: Uploading segment 0/3 size 3 2022/04/20 06:47:16 DEBUG : two: quickxor = 74b8c31b00000000000000000300000000000000 OK 2022/04/20 06:47:16 INFO : two: Copied (new) 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 operations_test.go:1135 Error: Should be true Test: TestCopyFileCopyDest Messages: listing wrong, want BackupDir/one (3), CopyDest/one (5), CopyDest/two (3), dst/one (5), dst/two (3) got CopyDest/one (5), CopyDest/two (3), dst/one (5), dst/two (3) fstest.go:204: Not found "BackupDir/one" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 operations_test.go:1135 Error: Not equal: expected: 0 actual : 1 Test: TestCopyFileCopyDest Messages: 1 objects not found 2022/04/20 06:47:27 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 06:47:27 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 06:47:27 DEBUG : two: Unchanged skipping 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 operations_test.go:1141 Error: Should be true Test: TestCopyFileCopyDest Messages: listing wrong, want BackupDir/one (3), CopyDest/one (5), CopyDest/two (3), dst/one (5), dst/two (3) got CopyDest/one (5), CopyDest/two (3), dst/one (5), dst/two (3) fstest.go:204: Not found "BackupDir/one" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 operations_test.go:1141 Error: Not equal: expected: 0 actual : 1 Test: TestCopyFileCopyDest Messages: 1 objects not found 2022/04/20 06:47:38 DEBUG : CopyDest/three: Starting multipart upload 2022/04/20 06:47:39 DEBUG : CopyDest/three: Uploading segment 0/5 size 5 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 operations_test.go:1146 Error: Should be true Test: TestCopyFileCopyDest Messages: listing wrong, want BackupDir/one (3), CopyDest/one (5), CopyDest/three (5), CopyDest/two (3), dst/one (5), dst/two (3) got CopyDest/one (5), CopyDest/three (5), CopyDest/two (3), dst/one (5), dst/two (3) fstest.go:204: Not found "BackupDir/one" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 operations_test.go:1146 Error: Not equal: expected: 0 actual : 1 Test: TestCopyFileCopyDest Messages: 1 objects not found 2022/04/20 06:47:50 DEBUG : three: Sizes differ (src 7 vs dst 5) 2022/04/20 06:47:50 DEBUG : three: Destination not found in --copy-dest 2022/04/20 06:47:50 DEBUG : three: Need to transfer - File not found at Destination 2022/04/20 06:47:50 DEBUG : three: Starting multipart upload 2022/04/20 06:47:51 DEBUG : three: Uploading segment 0/7 size 7 2022/04/20 06:47:51 DEBUG : three: quickxor = 7440831cca50063acc0000000700000000000000 OK 2022/04/20 06:47:51 INFO : three: Copied (new) 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 operations_test.go:1155 Error: Should be true Test: TestCopyFileCopyDest Messages: listing wrong, want BackupDir/one (3), CopyDest/one (5), CopyDest/three (5), CopyDest/two (3), dst/one (5), dst/three (7), dst/two (3) got CopyDest/one (5), CopyDest/three (5), CopyDest/two (3), dst/one (5), dst/three (7), dst/two (3) fstest.go:204: Not found "BackupDir/one" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 operations_test.go:1155 Error: Not equal: expected: 0 actual : 1 Test: TestCopyFileCopyDest Messages: 1 objects not found --- FAIL: TestCopyFileCopyDest (95.73s) === RUN TestDirMove run.go:181: Remote "One drive root 'rclone-test-qewolal8fegociy7sawazeh5'", Local "Local file system at /tmp/rclone187799435", Modify Window "1s" 2022/04/20 06:48:07 DEBUG : A1/one: Starting multipart upload 2022/04/20 06:48:08 DEBUG : A1/one: Uploading segment 0/3 size 3 2022/04/20 06:48:08 DEBUG : A1/two: Starting multipart upload 2022/04/20 06:48:09 DEBUG : A1/two: Uploading segment 0/3 size 3 2022/04/20 06:48:10 DEBUG : A1/B1/three: Starting multipart upload 2022/04/20 06:48:11 DEBUG : A1/B1/three: Uploading segment 0/5 size 5 2022/04/20 06:48:12 DEBUG : A1/B1/C1/four: Starting multipart upload 2022/04/20 06:48:12 DEBUG : A1/B1/C1/four: Uploading segment 0/4 size 4 2022/04/20 06:48:14 DEBUG : A1/B1/C2/five: Starting multipart upload 2022/04/20 06:48:14 DEBUG : A1/B1/C2/five: Uploading segment 0/4 size 4 2022/04/20 06:48:15 DEBUG : A1/B2: Making directory 2022/04/20 06:48:15 DEBUG : A1/B1/C3: Making directory 2022/04/20 06:48:28 INFO : A2/one: Moved (server-side) to: A3/one 2022/04/20 06:48:28 INFO : A2/two: Moved (server-side) to: A3/two 2022/04/20 06:48:28 INFO : A2/B1/three: Moved (server-side) to: A3/B1/three 2022/04/20 06:48:29 INFO : A2/B1/C2/five: Moved (server-side) to: A3/B1/C2/five 2022/04/20 06:48:29 INFO : A2/B1/C1/four: Moved (server-side) to: A3/B1/C1/four operations_test.go:1431: Error Trace: operations_test.go:1431 Error: Received unexpected error: RenameDir rmdir: directory not empty Test: TestDirMove --- FAIL: TestDirMove (32.60s) FAIL 2022/04/20 06:48:38 DEBUG : One drive root 'rclone-test-qewolal8fegociy7sawazeh5': Purge remote "./operations.test -test.v -test.timeout 1h0m0s -remote TestOneDriveBusiness: -verbose -test.run '^(TestCopyFileBackupDir|TestCopyFileCopyDest|TestDirMove|TestMoveFileBackupDir)$'" - Finished ERROR in 2m53.484406249s (try 4/5): exit status 1: Failed [TestMoveFileBackupDir TestCopyFileBackupDir TestCopyFileCopyDest TestDirMove]