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