"./operations.test -test.v -test.timeout 1h0m0s -remote TestOneDriveBusiness: -verbose -test.run '^(TestCopyFileBackupDir|TestCopyFileCopyDest|TestDirMove|TestMoveFileBackupDir)$'" - Starting (try 3/5) 2022/04/20 06:42:35 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zuyudux4foqorok9hatizap4" 2022/04/20 06:42:35 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2022/04/20 06:42:36 DEBUG : Creating backend with remote "/tmp/rclone2821158979" === RUN TestMoveFileBackupDir run.go:181: Remote "One drive root 'rclone-test-zuyudux4foqorok9hatizap4'", Local "Local file system at /tmp/rclone2821158979", Modify Window "1s" 2022/04/20 06:42:37 DEBUG : dst/file1: Starting multipart upload 2022/04/20 06:42:37 DEBUG : dst/file1: Uploading segment 0/18 size 18 2022/04/20 06:42:40 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zuyudux4foqorok9hatizap4/backup" 2022/04/20 06:42:41 DEBUG : dst/file1: Sizes differ (src 14 vs dst 18) 2022/04/20 06:42:44 INFO : dst/file1: Moved (server-side) 2022/04/20 06:42:44 DEBUG : dst/file1: Starting multipart upload 2022/04/20 06:42:44 DEBUG : dst/file1: Uploading segment 0/14 size 14 2022/04/20 06:42:45 DEBUG : dst/file1: quickxor = 6648031bca1003108ce10d6eae4319dc40873900 OK 2022/04/20 06:42:45 INFO : dst/file1: Copied (new) 2022/04/20 06:42:45 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 (22.58s) === RUN TestCopyFileBackupDir run.go:181: Remote "One drive root 'rclone-test-zuyudux4foqorok9hatizap4'", Local "Local file system at /tmp/rclone2821158979", Modify Window "1s" 2022/04/20 06:42:59 DEBUG : dst/file1: Starting multipart upload 2022/04/20 06:42:59 DEBUG : dst/file1: Uploading segment 0/18 size 18 2022/04/20 06:43:01 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zuyudux4foqorok9hatizap4/backup" 2022/04/20 06:43:03 DEBUG : dst/file1: Sizes differ (src 14 vs dst 18) 2022/04/20 06:43:05 INFO : dst/file1: Moved (server-side) 2022/04/20 06:43:05 DEBUG : dst/file1: Starting multipart upload 2022/04/20 06:43:06 DEBUG : dst/file1: Uploading segment 0/14 size 14 2022/04/20 06:43:06 DEBUG : dst/file1: quickxor = 6648031bca1003108ce10d6eae4319dc40873900 OK 2022/04/20 06:43:06 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 (24.45s) === RUN TestCopyFileCopyDest run.go:181: Remote "One drive root 'rclone-test-zuyudux4foqorok9hatizap4'", Local "Local file system at /tmp/rclone2821158979", Modify Window "1s" 2022/04/20 06:43:23 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zuyudux4foqorok9hatizap4/dst" 2022/04/20 06:43:27 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zuyudux4foqorok9hatizap4/CopyDest" 2022/04/20 06:43:30 DEBUG : one: Need to transfer - File not found at Destination 2022/04/20 06:43:31 DEBUG : one: Starting multipart upload 2022/04/20 06:43:33 DEBUG : one: Uploading segment 0/3 size 3 2022/04/20 06:43:33 DEBUG : one: quickxor = 6f70431900000000000000000300000000000000 OK 2022/04/20 06:43:33 INFO : one: Copied (new) 2022/04/20 06:43:38 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/04/20 06:43:38 DEBUG : one: Starting multipart upload 2022/04/20 06:43:38 DEBUG : one: Uploading segment 0/5 size 5 2022/04/20 06:43:39 DEBUG : one: quickxor = 6f704319e8200300000000000500000000000000 OK 2022/04/20 06:43:39 INFO : one: Copied (replaced existing) 2022/04/20 06:43:40 DEBUG : dst/one: Starting multipart upload 2022/04/20 06:43:40 DEBUG : dst/one: Uploading segment 0/3 size 3 2022/04/20 06:43:42 DEBUG : CopyDest/one: Starting multipart upload 2022/04/20 06:43:43 DEBUG : CopyDest/one: Uploading segment 0/5 size 5 2022/04/20 06:43:46 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zuyudux4foqorok9hatizap4/BackupDir" 2022/04/20 06:43:50 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 06:43:50 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/04/20 06:43:52 INFO : one: Moved (server-side) 2022/04/20 06:43:52 ERROR : one: Failed to copy: nameAlreadyExists: The specified item name already exists. 2022/04/20 06:43:52 ERROR : one: Destination found in --copy-dest, error copying 2022/04/20 06:43:52 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/04/20 06:43:53 INFO : one: Moved (server-side) 2022/04/20 06:43:53 DEBUG : one: Starting multipart upload 2022/04/20 06:43:54 DEBUG : one: Uploading segment 0/5 size 5 2022/04/20 06:43:55 DEBUG : one: quickxor = 6f704319e8200300000000000500000000000000 OK 2022/04/20 06:43:55 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:44:06 DEBUG : CopyDest/two: Starting multipart upload 2022/04/20 06:44:07 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:44:20 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 06:44:21 ERROR : two: Failed to copy: nameAlreadyExists: The specified item name already exists. 2022/04/20 06:44:21 ERROR : two: Destination found in --copy-dest, error copying 2022/04/20 06:44:21 DEBUG : two: Need to transfer - File not found at Destination 2022/04/20 06:44:21 DEBUG : two: Starting multipart upload 2022/04/20 06:44:22 DEBUG : two: Uploading segment 0/3 size 3 2022/04/20 06:44:22 DEBUG : two: quickxor = 74b8c31b00000000000000000300000000000000 OK 2022/04/20 06:44:22 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:44:34 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 06:44:34 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/04/20 06:44:34 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:44:45 DEBUG : CopyDest/three: Starting multipart upload 2022/04/20 06:44:46 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:44:58 DEBUG : three: Sizes differ (src 7 vs dst 5) 2022/04/20 06:44:58 DEBUG : three: Destination not found in --copy-dest 2022/04/20 06:44:58 DEBUG : three: Need to transfer - File not found at Destination 2022/04/20 06:44:58 DEBUG : three: Starting multipart upload 2022/04/20 06:44:59 DEBUG : three: Uploading segment 0/7 size 7 2022/04/20 06:44:59 DEBUG : three: quickxor = 7440831cca50063acc0000000700000000000000 OK 2022/04/20 06:44:59 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 (111.62s) === RUN TestDirMove run.go:181: Remote "One drive root 'rclone-test-zuyudux4foqorok9hatizap4'", Local "Local file system at /tmp/rclone2821158979", Modify Window "1s" 2022/04/20 06:45:15 DEBUG : A1/one: Starting multipart upload 2022/04/20 06:45:16 DEBUG : A1/one: Uploading segment 0/3 size 3 2022/04/20 06:45:16 DEBUG : A1/two: Starting multipart upload 2022/04/20 06:45:17 DEBUG : A1/two: Uploading segment 0/3 size 3 2022/04/20 06:45:18 DEBUG : A1/B1/three: Starting multipart upload 2022/04/20 06:45:19 DEBUG : A1/B1/three: Uploading segment 0/5 size 5 2022/04/20 06:45:20 DEBUG : A1/B1/C1/four: Starting multipart upload 2022/04/20 06:45:21 DEBUG : A1/B1/C1/four: Uploading segment 0/4 size 4 2022/04/20 06:45:22 DEBUG : A1/B1/C2/five: Starting multipart upload 2022/04/20 06:45:22 DEBUG : A1/B1/C2/five: Uploading segment 0/4 size 4 2022/04/20 06:45:23 DEBUG : A1/B2: Making directory 2022/04/20 06:45:24 DEBUG : A1/B1/C3: Making directory 2022/04/20 06:45:35 INFO : A2/one: Moved (server-side) to: A3/one 2022/04/20 06:45:35 INFO : A2/B1/three: Moved (server-side) to: A3/B1/three 2022/04/20 06:45:35 INFO : A2/two: Moved (server-side) to: A3/two 2022/04/20 06:45:36 INFO : A2/B1/C1/four: Moved (server-side) to: A3/B1/C1/four 2022/04/20 06:45:36 INFO : A2/B1/C2/five: Moved (server-side) to: A3/B1/C2/five operations_test.go:1431: Error Trace: operations_test.go:1431 Error: Received unexpected error: RenameDir rmdir: directory not empty Test: TestDirMove --- FAIL: TestDirMove (30.65s) FAIL 2022/04/20 06:45:45 DEBUG : One drive root 'rclone-test-zuyudux4foqorok9hatizap4': Purge remote "./operations.test -test.v -test.timeout 1h0m0s -remote TestOneDriveBusiness: -verbose -test.run '^(TestCopyFileBackupDir|TestCopyFileCopyDest|TestDirMove|TestMoveFileBackupDir)$'" - Finished ERROR in 3m10.37329338s (try 3/5): exit status 1: Failed [TestMoveFileBackupDir TestCopyFileBackupDir TestCopyFileCopyDest TestDirMove]