"./sync.test -test.v -test.timeout 1h0m0s -remote TestB2: -list-retries 5 -verbose -fast-list -test.run '^(TestMoveWithDeleteEmptySrcDirs|TestServerSideCopy|TestServerSideCopyOverSelf|TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs|TestServerSideMoveOverSelf|TestServerSideMoveWithFilter|TestSyncAfterChangingModtimeOnly|TestSyncWithTrackRenames|TestSyncWithTrackRenamesStrategyLeaf|TestSyncWithTrackRenamesStrategyModtime)$'" - Starting (try 4/5) 2025/11/02 02:42:23 DEBUG : Creating backend with remote "TestB2:rclone-test-ridukep0sece" 2025/11/02 02:42:23 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/11/02 02:42:24 DEBUG : Creating backend with remote "/tmp/rclone720132006" === RUN TestServerSideCopy run.go:185: Remote "B2 bucket rclone-test-ridukep0sece", Local "Local file system at /tmp/rclone720132006", Modify Window "1ms" 2025/11/02 02:42:26 DEBUG : Creating backend with remote "TestB2:rclone-test-gowatar5wela" sync_test.go:620: Server side copy (if possible) B2 bucket rclone-test-ridukep0sece -> B2 bucket rclone-test-gowatar5wela 2025/11/02 02:42:27 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/11/02 02:42:27 DEBUG : B2 bucket rclone-test-gowatar5wela: Waiting for checks to finish 2025/11/02 02:42:27 DEBUG : B2 bucket rclone-test-gowatar5wela: Waiting for transfers to finish 2025/11/02 02:42:28 ERROR : sub dir/hello world: Failed to copy: expected a FileSseMode but found: '' (400 bad_request) sync_test.go:624: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:624 Error: Received unexpected error: expected a FileSseMode but found: '' (400 bad_request) Test: TestServerSideCopy 2025/11/02 02:42:28 DEBUG : B2 bucket rclone-test-gowatar5wela: Purge remote 2025/11/02 02:42:28 INFO : B2 bucket rclone-test-gowatar5wela: cleaning bucket "rclone-test-gowatar5wela" of all files --- FAIL: TestServerSideCopy (4.66s) === RUN TestServerSideCopyOverSelf run.go:185: Remote "B2 bucket rclone-test-ridukep0sece", Local "Local file system at /tmp/rclone720132006", Modify Window "1ms" 2025/11/02 02:42:29 DEBUG : Creating backend with remote "TestB2:rclone-test-vitevow5nogi" sync_test.go:656: Server side copy (if possible) B2 bucket rclone-test-ridukep0sece -> B2 bucket rclone-test-vitevow5nogi 2025/11/02 02:42:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/11/02 02:42:31 DEBUG : B2 bucket rclone-test-vitevow5nogi: Waiting for checks to finish 2025/11/02 02:42:31 DEBUG : B2 bucket rclone-test-vitevow5nogi: Waiting for transfers to finish 2025/11/02 02:42:31 ERROR : sub dir/hello world: Failed to copy: expected a FileSseMode but found: '' (400 bad_request) sync_test.go:660: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:660 Error: Received unexpected error: expected a FileSseMode but found: '' (400 bad_request) Test: TestServerSideCopyOverSelf 2025/11/02 02:42:31 DEBUG : B2 bucket rclone-test-vitevow5nogi: Purge remote 2025/11/02 02:42:31 INFO : B2 bucket rclone-test-vitevow5nogi: cleaning bucket "rclone-test-vitevow5nogi" of all files --- FAIL: TestServerSideCopyOverSelf (3.46s) === RUN TestServerSideMoveOverSelf run.go:185: Remote "B2 bucket rclone-test-ridukep0sece", Local "Local file system at /tmp/rclone720132006", Modify Window "1ms" 2025/11/02 02:42:33 DEBUG : Creating backend with remote "TestB2:rclone-test-ceyatav7mamo" 2025/11/02 02:42:33 DEBUG : pacer: low level retry 1/10 (error incident id 3894aee67876-56fa0c5739aed104 (500 internal_error)) 2025/11/02 02:42:33 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/11/02 02:42:34 DEBUG : pacer: low level retry 2/10 (error incident id 3894aee67876-88d4a93d2e9bf100 (500 internal_error)) 2025/11/02 02:42:34 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2025/11/02 02:42:34 DEBUG : pacer: low level retry 3/10 (error incident id 3894aee67876-8eeb4c08c7d68b02 (500 internal_error)) 2025/11/02 02:42:34 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2025/11/02 02:42:34 DEBUG : pacer: low level retry 4/10 (error incident id 3894aee67876-38b39fc0bc604a9a (500 internal_error)) 2025/11/02 02:42:34 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2025/11/02 02:42:34 DEBUG : pacer: low level retry 5/10 (error incident id 3894aee67876-5c057b366c9e2fd9 (500 internal_error)) 2025/11/02 02:42:34 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2025/11/02 02:42:35 DEBUG : pacer: low level retry 6/10 (error incident id 3894aee67876-3d6785e0de83f108 (500 internal_error)) 2025/11/02 02:42:35 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2025/11/02 02:42:35 DEBUG : pacer: low level retry 7/10 (error incident id 3894aee67876-7b43ce017f91c3c5 (500 internal_error)) 2025/11/02 02:42:35 DEBUG : pacer: Rate limited, increasing sleep to 1.28s 2025/11/02 02:42:36 DEBUG : pacer: low level retry 8/10 (error incident id 3894aee67876-abae51c9b453f16e (500 internal_error)) 2025/11/02 02:42:36 DEBUG : pacer: Rate limited, increasing sleep to 2.56s 2025/11/02 02:42:37 DEBUG : pacer: low level retry 9/10 (error incident id 3894aee67876-2709266c7126be65 (500 internal_error)) 2025/11/02 02:42:37 DEBUG : pacer: Rate limited, increasing sleep to 5.12s 2025/11/02 02:42:39 DEBUG : pacer: low level retry 10/10 (error incident id 3894aee67876-edadf8be6b98b73f (500 internal_error)) 2025/11/02 02:42:39 DEBUG : pacer: Rate limited, increasing sleep to 10.24s sync_test.go:699: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:699 Error: Received unexpected error: failed to authorize account: failed to authenticate: incident id 3894aee67876-edadf8be6b98b73f (500 internal_error) Test: TestServerSideMoveOverSelf --- FAIL: TestServerSideMoveOverSelf (8.03s) === RUN TestSyncAfterChangingModtimeOnly run.go:185: Remote "B2 bucket rclone-test-ridukep0sece", Local "Local file system at /tmp/rclone720132006", Modify Window "1ms" 2025/11/02 02:42:41 DEBUG : empty space: size = 1 OK 2025/11/02 02:42:41 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/11/02 02:42:41 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for checks to finish 2025/11/02 02:42:41 DEBUG : empty space: sha1 = 3bc15c8aae3e4124dd409035f32ea2fd6835efc9 OK 2025/11/02 02:42:41 NOTICE: empty space: Skipped update modification time as --dry-run is set (size 1) 2025/11/02 02:42:41 DEBUG : empty space: Unchanged skipping 2025/11/02 02:42:41 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for transfers to finish 2025/11/02 02:42:41 DEBUG : Waiting for deletions to finish 2025/11/02 02:42:41 INFO : There was nothing to transfer 2025/11/02 02:42:42 DEBUG : empty space: size = 1 OK 2025/11/02 02:42:42 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for checks to finish 2025/11/02 02:42:42 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/11/02 02:42:42 DEBUG : empty space: sha1 = 3bc15c8aae3e4124dd409035f32ea2fd6835efc9 OK 2025/11/02 02:42:42 ERROR : empty space: Failed to set modification time: expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:42:42 DEBUG : empty space: Unchanged skipping 2025/11/02 02:42:42 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for transfers to finish 2025/11/02 02:42:42 ERROR : B2 bucket rclone-test-ridukep0sece: not deleting files as there were IO errors 2025/11/02 02:42:42 ERROR : B2 bucket rclone-test-ridukep0sece: not deleting directories as there were IO errors sync_test.go:1033: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1033 Error: Received unexpected error: not deleting files as there were IO errors Test: TestSyncAfterChangingModtimeOnly --- FAIL: TestSyncAfterChangingModtimeOnly (2.80s) === RUN TestSyncWithTrackRenames run.go:185: Remote "B2 bucket rclone-test-ridukep0sece", Local "Local file system at /tmp/rclone720132006", Modify Window "1ms" sync_test.go:1568: Can track renames: true 2025/11/02 02:42:43 INFO : B2 bucket rclone-test-ridukep0sece: Making map for --track-renames 2025/11/02 02:42:43 INFO : B2 bucket rclone-test-ridukep0sece: Finished making map for --track-renames 2025/11/02 02:42:43 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for checks to finish 2025/11/02 02:42:43 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/11/02 02:42:43 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/11/02 02:42:43 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for renames to finish 2025/11/02 02:42:43 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for transfers to finish 2025/11/02 02:42:44 DEBUG : potato: size = 14 OK 2025/11/02 02:42:44 DEBUG : potato: sha1 = 1d1ac61cfffcfdd0a15cc9ae575fb06ca8c11fb5 OK 2025/11/02 02:42:44 INFO : potato: Copied (new) 2025/11/02 02:42:44 DEBUG : yam: size = 11 OK 2025/11/02 02:42:44 DEBUG : yam: sha1 = ad84b2fb6729688a5ee3225164a6d4d58465b33e OK 2025/11/02 02:42:44 INFO : yam: Copied (new) 2025/11/02 02:42:44 DEBUG : Waiting for deletions to finish 2025/11/02 02:42:44 DEBUG : potato: size = 14 OK 2025/11/02 02:42:44 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/11/02 02:42:44 INFO : B2 bucket rclone-test-ridukep0sece: Making map for --track-renames 2025/11/02 02:42:44 INFO : B2 bucket rclone-test-ridukep0sece: Finished making map for --track-renames 2025/11/02 02:42:44 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for checks to finish 2025/11/02 02:42:44 DEBUG : potato: Unchanged skipping 2025/11/02 02:42:44 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for renames to finish 2025/11/02 02:42:45 ERROR : yam: Failed to copy: expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:42:45 ERROR : yam: Not deleting source as copy failed: expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:42:45 DEBUG : yaml: Failed to rename to "yam": expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:42:45 DEBUG : yaml: Need to transfer - No matching file found at Destination 2025/11/02 02:42:45 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for transfers to finish 2025/11/02 02:42:46 DEBUG : yaml: size = 11 OK 2025/11/02 02:42:46 DEBUG : yaml: sha1 = ad84b2fb6729688a5ee3225164a6d4d58465b33e OK 2025/11/02 02:42:46 INFO : yaml: Copied (new) 2025/11/02 02:42:46 ERROR : B2 bucket rclone-test-ridukep0sece: not deleting files as there were IO errors 2025/11/02 02:42:46 ERROR : B2 bucket rclone-test-ridukep0sece: not deleting directories as there were IO errors sync_test.go:1586: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1586 Error: Received unexpected error: not deleting files as there were IO errors Test: TestSyncWithTrackRenames --- FAIL: TestSyncWithTrackRenames (3.53s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:185: Remote "B2 bucket rclone-test-ridukep0sece", Local "Local file system at /tmp/rclone720132006", Modify Window "1ms" sync_test.go:1640: Can track renames: true 2025/11/02 02:42:47 INFO : B2 bucket rclone-test-ridukep0sece: Making map for --track-renames 2025/11/02 02:42:47 INFO : B2 bucket rclone-test-ridukep0sece: Finished making map for --track-renames 2025/11/02 02:42:47 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for checks to finish 2025/11/02 02:42:47 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/11/02 02:42:47 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/11/02 02:42:47 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for renames to finish 2025/11/02 02:42:47 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for transfers to finish 2025/11/02 02:42:47 DEBUG : potato: size = 14 OK 2025/11/02 02:42:47 DEBUG : potato: sha1 = 1d1ac61cfffcfdd0a15cc9ae575fb06ca8c11fb5 OK 2025/11/02 02:42:47 INFO : potato: Copied (new) 2025/11/02 02:42:48 DEBUG : yam: size = 11 OK 2025/11/02 02:42:48 DEBUG : yam: sha1 = ad84b2fb6729688a5ee3225164a6d4d58465b33e OK 2025/11/02 02:42:48 INFO : yam: Copied (new) 2025/11/02 02:42:48 DEBUG : Waiting for deletions to finish 2025/11/02 02:42:48 DEBUG : potato: size = 14 OK 2025/11/02 02:42:48 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/11/02 02:42:48 INFO : B2 bucket rclone-test-ridukep0sece: Making map for --track-renames 2025/11/02 02:42:48 INFO : B2 bucket rclone-test-ridukep0sece: Finished making map for --track-renames 2025/11/02 02:42:48 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for checks to finish 2025/11/02 02:42:48 DEBUG : potato: Unchanged skipping 2025/11/02 02:42:48 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for renames to finish 2025/11/02 02:42:48 ERROR : yam: Failed to copy: expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:42:48 ERROR : yam: Not deleting source as copy failed: expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:42:48 DEBUG : yaml: Failed to rename to "yam": expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:42:48 DEBUG : yaml: Need to transfer - No matching file found at Destination 2025/11/02 02:42:48 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for transfers to finish 2025/11/02 02:42:49 DEBUG : yaml: size = 11 OK 2025/11/02 02:42:49 DEBUG : yaml: sha1 = ad84b2fb6729688a5ee3225164a6d4d58465b33e OK 2025/11/02 02:42:49 INFO : yaml: Copied (new) 2025/11/02 02:42:49 ERROR : B2 bucket rclone-test-ridukep0sece: not deleting files as there were IO errors 2025/11/02 02:42:49 ERROR : B2 bucket rclone-test-ridukep0sece: not deleting directories as there were IO errors sync_test.go:1658: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1658 Error: Received unexpected error: not deleting files as there were IO errors Test: TestSyncWithTrackRenamesStrategyModtime --- FAIL: TestSyncWithTrackRenamesStrategyModtime (2.89s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:185: Remote "B2 bucket rclone-test-ridukep0sece", Local "Local file system at /tmp/rclone720132006", Modify Window "1ms" sync_test.go:1679: Can track renames: true 2025/11/02 02:42:50 INFO : B2 bucket rclone-test-ridukep0sece: Making map for --track-renames 2025/11/02 02:42:50 INFO : B2 bucket rclone-test-ridukep0sece: Finished making map for --track-renames 2025/11/02 02:42:50 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for checks to finish 2025/11/02 02:42:50 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/11/02 02:42:50 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/11/02 02:42:50 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for renames to finish 2025/11/02 02:42:50 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for transfers to finish 2025/11/02 02:42:50 DEBUG : potato: size = 14 OK 2025/11/02 02:42:50 DEBUG : potato: sha1 = 1d1ac61cfffcfdd0a15cc9ae575fb06ca8c11fb5 OK 2025/11/02 02:42:50 INFO : potato: Copied (new) 2025/11/02 02:42:50 DEBUG : sub/yam: size = 11 OK 2025/11/02 02:42:50 DEBUG : sub/yam: sha1 = ad84b2fb6729688a5ee3225164a6d4d58465b33e OK 2025/11/02 02:42:50 INFO : sub/yam: Copied (new) 2025/11/02 02:42:50 DEBUG : Waiting for deletions to finish 2025/11/02 02:42:51 DEBUG : potato: size = 14 OK 2025/11/02 02:42:51 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/11/02 02:42:51 DEBUG : potato: Unchanged skipping 2025/11/02 02:42:51 INFO : B2 bucket rclone-test-ridukep0sece: Making map for --track-renames 2025/11/02 02:42:51 INFO : B2 bucket rclone-test-ridukep0sece: Finished making map for --track-renames 2025/11/02 02:42:51 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for checks to finish 2025/11/02 02:42:51 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for renames to finish 2025/11/02 02:42:51 ERROR : sub/yam: Failed to copy: expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:42:51 ERROR : sub/yam: Not deleting source as copy failed: expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:42:51 DEBUG : yam: Failed to rename to "sub/yam": expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:42:51 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/11/02 02:42:51 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for transfers to finish 2025/11/02 02:42:51 DEBUG : yam: size = 11 OK 2025/11/02 02:42:51 DEBUG : yam: sha1 = ad84b2fb6729688a5ee3225164a6d4d58465b33e OK 2025/11/02 02:42:51 INFO : yam: Copied (new) 2025/11/02 02:42:51 ERROR : B2 bucket rclone-test-ridukep0sece: not deleting files as there were IO errors 2025/11/02 02:42:51 ERROR : B2 bucket rclone-test-ridukep0sece: not deleting directories as there were IO errors sync_test.go:1697: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1697 Error: Received unexpected error: not deleting files as there were IO errors Test: TestSyncWithTrackRenamesStrategyLeaf --- FAIL: TestSyncWithTrackRenamesStrategyLeaf (2.66s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:185: Remote "B2 bucket rclone-test-ridukep0sece", Local "Local file system at /tmp/rclone720132006", Modify Window "1ms" 2025/11/02 02:42:52 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/11/02 02:42:52 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/11/02 02:42:52 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for checks to finish 2025/11/02 02:42:52 DEBUG : B2 bucket rclone-test-ridukep0sece: Waiting for transfers to finish 2025/11/02 02:42:53 DEBUG : nested/sub dir/file: size = 6 OK 2025/11/02 02:42:53 DEBUG : nested/sub dir/file: sha1 = b4b3e0a278988bc15f2913af3f4153ccef74e465 OK 2025/11/02 02:42:53 INFO : nested/sub dir/file: Copied (new) 2025/11/02 02:42:53 INFO : nested/sub dir/file: Deleted 2025/11/02 02:42:53 DEBUG : sub dir/hello world: size = 11 OK 2025/11/02 02:42:53 DEBUG : sub dir/hello world: sha1 = 2aae6c35c94fcfb415dbe95f408b9ce91ee846ed OK 2025/11/02 02:42:53 INFO : sub dir/hello world: Copied (new) 2025/11/02 02:42:53 INFO : sub dir/hello world: Deleted 2025/11/02 02:42:53 ERROR : Local file system at /tmp/rclone720132006: not deleting directories as there were IO errors sync_test.go:1818: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1818 Error: Received unexpected error: not deleting directories as there were IO errors Test: TestMoveWithDeleteEmptySrcDirs --- FAIL: TestMoveWithDeleteEmptySrcDirs (1.52s) === RUN TestServerSideMove run.go:185: Remote "B2 bucket rclone-test-ridukep0sece", Local "Local file system at /tmp/rclone720132006", Modify Window "1ms" 2025/11/02 02:42:54 DEBUG : Creating backend with remote "TestB2:rclone-test-carosam6nudu" sync_test.go:1735: Server side move (if possible) B2 bucket rclone-test-ridukep0sece -> B2 bucket rclone-test-carosam6nudu 2025/11/02 02:42:57 DEBUG : potato2: Need to transfer - File not found at Destination 2025/11/02 02:42:57 DEBUG : empty space: size = 1 OK 2025/11/02 02:42:57 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/11/02 02:42:57 DEBUG : empty space: Unchanged skipping 2025/11/02 02:42:57 DEBUG : potato3: size = 68 (B2 bucket rclone-test-ridukep0sece) 2025/11/02 02:42:57 DEBUG : potato3: size = 60 (B2 bucket rclone-test-carosam6nudu) 2025/11/02 02:42:57 DEBUG : potato3: Sizes differ 2025/11/02 02:42:57 DEBUG : B2 bucket rclone-test-carosam6nudu: Waiting for checks to finish 2025/11/02 02:42:58 ERROR : potato2: Failed to copy: expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:42:58 ERROR : potato2: Not deleting source as copy failed: expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:42:58 INFO : empty space: Deleted 2025/11/02 02:42:58 DEBUG : B2 bucket rclone-test-carosam6nudu: Waiting for transfers to finish 2025/11/02 02:42:58 ERROR : potato3: Failed to copy: expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:42:58 ERROR : potato3: Not deleting source as copy failed: expected a FileSseMode but found: '' (400 bad_request) sync_test.go:1746: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1746 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1911 Error: Received unexpected error: expected a FileSseMode but found: '' (400 bad_request) Test: TestServerSideMove 2025/11/02 02:42:58 DEBUG : B2 bucket rclone-test-carosam6nudu: Purge remote 2025/11/02 02:42:58 INFO : B2 bucket rclone-test-carosam6nudu: cleaning bucket "rclone-test-carosam6nudu" of all files 2025/11/02 02:42:58 DEBUG : empty space: Deleting (id "4_zaf324d43702d4b2b9fa80e1b_f10707eda6369ac4e_d20251102_m024257_c001_v0001182_t0052_u01762051377255") 2025/11/02 02:42:58 DEBUG : potato3: Deleting (id "4_zaf324d43702d4b2b9fa80e1b_f10707eda6369ac52_d20251102_m024257_c001_v0001182_t0045_u01762051377468") --- FAIL: TestServerSideMove (5.93s) === RUN TestServerSideMoveWithFilter run.go:185: Remote "B2 bucket rclone-test-ridukep0sece", Local "Local file system at /tmp/rclone720132006", Modify Window "1ms" 2025/11/02 02:43:00 DEBUG : Creating backend with remote "TestB2:rclone-test-rowaban1vuwu" sync_test.go:1735: Server side move (if possible) B2 bucket rclone-test-ridukep0sece -> B2 bucket rclone-test-rowaban1vuwu 2025/11/02 02:43:05 DEBUG : empty space: Excluded (Size Filter) 2025/11/02 02:43:05 DEBUG : empty space: Excluded (Size Filter) 2025/11/02 02:43:05 DEBUG : potato2: Need to transfer - File not found at Destination 2025/11/02 02:43:05 DEBUG : potato3: size = 68 (B2 bucket rclone-test-ridukep0sece) 2025/11/02 02:43:05 DEBUG : potato3: size = 60 (B2 bucket rclone-test-rowaban1vuwu) 2025/11/02 02:43:05 DEBUG : potato3: Sizes differ 2025/11/02 02:43:05 DEBUG : B2 bucket rclone-test-rowaban1vuwu: Waiting for checks to finish 2025/11/02 02:43:05 DEBUG : B2 bucket rclone-test-rowaban1vuwu: Waiting for transfers to finish 2025/11/02 02:43:05 ERROR : potato2: Failed to copy: expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:43:05 ERROR : potato2: Not deleting source as copy failed: expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:43:05 ERROR : potato3: Failed to copy: expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:43:05 ERROR : potato3: Not deleting source as copy failed: expected a FileSseMode but found: '' (400 bad_request) sync_test.go:1746: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1746 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1924 Error: Received unexpected error: expected a FileSseMode but found: '' (400 bad_request) Test: TestServerSideMoveWithFilter 2025/11/02 02:43:05 DEBUG : B2 bucket rclone-test-rowaban1vuwu: Purge remote 2025/11/02 02:43:05 INFO : B2 bucket rclone-test-rowaban1vuwu: cleaning bucket "rclone-test-rowaban1vuwu" of all files 2025/11/02 02:43:06 DEBUG : empty space: Deleting (id "4_z2f825df3702d4b2b9fa80e1b_f118f55f43e605c3c_d20251102_m024304_c001_v0001117_t0017_u01762051384040") 2025/11/02 02:43:06 DEBUG : potato3: Deleting (id "4_z2f825df3702d4b2b9fa80e1b_f118f55f43e605c40_d20251102_m024304_c001_v0001117_t0003_u01762051384611") --- FAIL: TestServerSideMoveWithFilter (7.76s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:185: Remote "B2 bucket rclone-test-ridukep0sece", Local "Local file system at /tmp/rclone720132006", Modify Window "1ms" 2025/11/02 02:43:07 DEBUG : Creating backend with remote "TestB2:rclone-test-dijorom1koru" 2025/11/02 02:43:09 INFO : tomatoDir: Making directory sync_test.go:1735: Server side move (if possible) B2 bucket rclone-test-ridukep0sece -> B2 bucket rclone-test-dijorom1koru 2025/11/02 02:43:13 DEBUG : potato2: Need to transfer - File not found at Destination 2025/11/02 02:43:13 DEBUG : empty space: size = 1 OK 2025/11/02 02:43:13 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/11/02 02:43:13 DEBUG : empty space: Unchanged skipping 2025/11/02 02:43:13 DEBUG : potato3: size = 68 (B2 bucket rclone-test-ridukep0sece) 2025/11/02 02:43:13 DEBUG : potato3: size = 60 (B2 bucket rclone-test-dijorom1koru) 2025/11/02 02:43:13 DEBUG : potato3: Sizes differ 2025/11/02 02:43:13 DEBUG : B2 bucket rclone-test-dijorom1koru: Waiting for checks to finish 2025/11/02 02:43:14 ERROR : potato2: Failed to copy: expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:43:14 ERROR : potato2: Not deleting source as copy failed: expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:43:14 INFO : empty space: Deleted 2025/11/02 02:43:14 DEBUG : B2 bucket rclone-test-dijorom1koru: Waiting for transfers to finish 2025/11/02 02:43:14 ERROR : potato3: Failed to copy: expected a FileSseMode but found: '' (400 bad_request) 2025/11/02 02:43:14 ERROR : potato3: Not deleting source as copy failed: expected a FileSseMode but found: '' (400 bad_request) sync_test.go:1746: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1746 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1931 Error: Received unexpected error: expected a FileSseMode but found: '' (400 bad_request) Test: TestServerSideMoveDeleteEmptySourceDirs 2025/11/02 02:43:14 DEBUG : B2 bucket rclone-test-dijorom1koru: Purge remote 2025/11/02 02:43:14 INFO : B2 bucket rclone-test-dijorom1koru: cleaning bucket "rclone-test-dijorom1koru" of all files 2025/11/02 02:43:14 DEBUG : empty space: Deleting (id "4_zbf328d03702d4b2b9fa80e1b_f1129681ccdc6cd99_d20251102_m024312_c001_v0001178_t0042_u01762051392622") 2025/11/02 02:43:14 DEBUG : potato3: Deleting (id "4_zbf328d03702d4b2b9fa80e1b_f1129681ccdc6cd9b_d20251102_m024312_c001_v0001178_t0052_u01762051392841") --- FAIL: TestServerSideMoveDeleteEmptySourceDirs (9.92s) FAIL 2025/11/02 02:43:17 DEBUG : B2 bucket rclone-test-ridukep0sece: Purge remote 2025/11/02 02:43:17 INFO : B2 bucket rclone-test-ridukep0sece: cleaning bucket "rclone-test-ridukep0sece" of all files 2025/11/02 02:43:18 DEBUG : empty space: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4d65_d20251102_m024314_c001_v7007000_t0000_u01762051394016") 2025/11/02 02:43:18 DEBUG : empty space: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f1189b6b6b42fa856_d20251102_m024309_c001_v0001134_t0030_u01762051389464") 2025/11/02 02:43:18 DEBUG : empty space: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4d17_d20251102_m024307_c001_v7007000_t0000_u01762051387167") 2025/11/02 02:43:18 DEBUG : empty space: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f106f2b0239a9ed71_d20251102_m024301_c001_v0001180_t0001_u01762051381851") 2025/11/02 02:43:18 DEBUG : empty space: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4c85_d20251102_m024258_c001_v7007000_t0000_u01762051378088") 2025/11/02 02:43:18 DEBUG : empty space: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f1189b6b6b42fa83c_d20251102_m024255_c001_v0001134_t0011_u01762051375060") 2025/11/02 02:43:18 DEBUG : empty space: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4c48_d20251102_m024243_c001_v7007000_t0000_u01762051363277") 2025/11/02 02:43:18 DEBUG : empty space: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f1189b6b6b42fa808_d20251102_m024241_c001_v0001134_t0056_u01762051361223") 2025/11/02 02:43:18 DEBUG : nested/sub dir/file: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4c71_d20251102_m024253_c001_v7007000_t0000_u01762051373701") 2025/11/02 02:43:19 DEBUG : nested/sub dir/file: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f106f2b0239a9ed1c_d20251102_m024252_c001_v0001180_t0034_u01762051372933") 2025/11/02 02:43:19 DEBUG : potato: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4c6c_d20251102_m024251_c001_v7007000_t0000_u01762051371986") 2025/11/02 02:43:19 DEBUG : potato: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f106f2b0239a9ed06_d20251102_m024250_c001_v0001180_t0012_u01762051370284") 2025/11/02 02:43:19 DEBUG : potato: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4c53_d20251102_m024249_c001_v7007000_t0000_u01762051369318") 2025/11/02 02:43:19 DEBUG : potato: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f106f2b0239a9ecea_d20251102_m024247_c001_v0001180_t0033_u01762051367382") 2025/11/02 02:43:19 DEBUG : potato: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4c4a_d20251102_m024246_c001_v7007000_t0000_u01762051366428") 2025/11/02 02:43:19 DEBUG : potato: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f1189b6b6b42fa810_d20251102_m024243_c001_v0001134_t0033_u01762051363848") 2025/11/02 02:43:19 DEBUG : potato2: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4d66_d20251102_m024316_c001_v7007000_t0000_u01762051396438") 2025/11/02 02:43:19 DEBUG : potato2: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f106f2b0239a9eda3_d20251102_m024308_c001_v0001180_t0005_u01762051388880") 2025/11/02 02:43:19 DEBUG : potato2: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4d1b_d20251102_m024307_c001_v7007000_t0000_u01762051387358") 2025/11/02 02:43:19 DEBUG : potato2: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f1189b6b6b42fa848_d20251102_m024301_c001_v0001134_t0045_u01762051381152") 2025/11/02 02:43:19 DEBUG : potato2: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4c94_d20251102_m024259_c001_v7007000_t0000_u01762051379614") 2025/11/02 02:43:19 DEBUG : potato2: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f106f2b0239a9ed2f_d20251102_m024254_c001_v0001180_t0014_u01762051374825") 2025/11/02 02:43:20 DEBUG : potato3: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4d67_d20251102_m024316_c001_v7007000_t0000_u01762051396631") 2025/11/02 02:43:20 DEBUG : potato3: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f106f2b0239a9edae_d20251102_m024309_c001_v0001180_t0008_u01762051389813") 2025/11/02 02:43:20 DEBUG : potato3: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4d20_d20251102_m024307_c001_v7007000_t0000_u01762051387557") 2025/11/02 02:43:20 DEBUG : potato3: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f1189b6b6b42fa84a_d20251102_m024302_c001_v0001134_t0045_u01762051382154") 2025/11/02 02:43:20 DEBUG : potato3: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4c95_d20251102_m024259_c001_v7007000_t0000_u01762051379805") 2025/11/02 02:43:20 DEBUG : potato3: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f106f2b0239a9ed35_d20251102_m024255_c001_v0001180_t0048_u01762051375446") 2025/11/02 02:43:20 DEBUG : sub dir/hello world: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4c72_d20251102_m024253_c001_v7007000_t0000_u01762051373887") 2025/11/02 02:43:20 DEBUG : sub dir/hello world: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f1189b6b6b42fa830_d20251102_m024252_c001_v0001134_t0035_u01762051372923") 2025/11/02 02:43:20 DEBUG : sub dir/hello world: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4c42_d20251102_m024240_c001_v7007000_t0000_u01762051360495") 2025/11/02 02:43:20 DEBUG : sub dir/hello world: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f1189b6b6b42fa7f9_d20251102_m024232_c001_v0001134_t0011_u01762051352823") 2025/11/02 02:43:20 DEBUG : sub dir/hello world: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f419682f804161d82_d20251102_m024232_c001_v7007000_t0000_u01762051352463") 2025/11/02 02:43:20 DEBUG : sub dir/hello world: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f1189b6b6b42fa7f4_d20251102_m024229_c001_v0001134_t0004_u01762051349366") 2025/11/02 02:43:20 DEBUG : sub dir/hello world: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f419682f804161d43_d20251102_m024229_c001_v7007000_t0000_u01762051349005") 2025/11/02 02:43:21 DEBUG : sub dir/hello world: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f1189b6b6b42fa7f0_d20251102_m024226_c001_v0001134_t0057_u01762051346003") 2025/11/02 02:43:21 DEBUG : sub/yam: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4c6f_d20251102_m024252_c001_v7007000_t0000_u01762051372178") 2025/11/02 02:43:21 DEBUG : sub/yam: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f1189b6b6b42fa826_d20251102_m024250_c001_v0001134_t0003_u01762051370274") 2025/11/02 02:43:21 DEBUG : yam: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4c70_d20251102_m024252_c001_v7007000_t0000_u01762051372368") 2025/11/02 02:43:21 DEBUG : yam: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f106f2b0239a9ed10_d20251102_m024251_c001_v0001180_t0042_u01762051371583") 2025/11/02 02:43:21 DEBUG : yam: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4c54_d20251102_m024249_c001_v7007000_t0000_u01762051369508") 2025/11/02 02:43:21 DEBUG : yam: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f1189b6b6b42fa81e_d20251102_m024247_c001_v0001134_t0050_u01762051367393") 2025/11/02 02:43:21 DEBUG : yam: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4c4c_d20251102_m024246_c001_v7007000_t0000_u01762051366618") 2025/11/02 02:43:21 DEBUG : yam: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f106f2b0239a9ecd4_d20251102_m024244_c001_v0001180_t0021_u01762051364434") 2025/11/02 02:43:22 DEBUG : yaml: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4c55_d20251102_m024249_c001_v7007000_t0000_u01762051369700") 2025/11/02 02:43:22 DEBUG : yaml: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f106f2b0239a9ecfa_d20251102_m024248_c001_v0001180_t0056_u01762051368915") 2025/11/02 02:43:22 DEBUG : yaml: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f413849d483de4c4e_d20251102_m024246_c001_v7007000_t0000_u01762051366810") 2025/11/02 02:43:22 DEBUG : yaml: Deleting (id "4_zcfe2cda3701d4b2b9fa80e1b_f1189b6b6b42fa818_d20251102_m024245_c001_v0001134_t0053_u01762051365469") "./sync.test -test.v -test.timeout 1h0m0s -remote TestB2: -list-retries 5 -verbose -fast-list -test.run '^(TestMoveWithDeleteEmptySrcDirs|TestServerSideCopy|TestServerSideCopyOverSelf|TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs|TestServerSideMoveOverSelf|TestServerSideMoveWithFilter|TestSyncAfterChangingModtimeOnly|TestSyncWithTrackRenames|TestSyncWithTrackRenamesStrategyLeaf|TestSyncWithTrackRenamesStrategyModtime)$'" - Finished ERROR in 1m0.014785931s (try 4/5): exit status 1: Failed [TestServerSideCopy TestServerSideCopyOverSelf TestServerSideMoveOverSelf TestSyncAfterChangingModtimeOnly TestSyncWithTrackRenames TestSyncWithTrackRenamesStrategyModtime TestSyncWithTrackRenamesStrategyLeaf TestMoveWithDeleteEmptySrcDirs TestServerSideMove TestServerSideMoveWithFilter TestServerSideMoveDeleteEmptySourceDirs]