"./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|TestSyncOverlapWithFilter|TestSyncWithTrackRenames|TestSyncWithTrackRenamesStrategyLeaf|TestSyncWithTrackRenamesStrategyModtime)$'" - Starting (try 2/5) 2025/11/03 03:45:45 DEBUG : Creating backend with remote "TestB2:rclone-test-zakufow4reru" 2025/11/03 03:45:45 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/11/03 03:45:46 DEBUG : Creating backend with remote "/tmp/rclone1253114081" === RUN TestServerSideCopy run.go:185: Remote "B2 bucket rclone-test-zakufow4reru", Local "Local file system at /tmp/rclone1253114081", Modify Window "1ms" 2025/11/03 03:45:48 DEBUG : Creating backend with remote "TestB2:rclone-test-ciqidep8qoxo" sync_test.go:620: Server side copy (if possible) B2 bucket rclone-test-zakufow4reru -> B2 bucket rclone-test-ciqidep8qoxo 2025/11/03 03:45:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/11/03 03:45:49 DEBUG : B2 bucket rclone-test-ciqidep8qoxo: Waiting for checks to finish 2025/11/03 03:45:49 DEBUG : B2 bucket rclone-test-ciqidep8qoxo: Waiting for transfers to finish 2025/11/03 03:45:50 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/03 03:45:50 DEBUG : B2 bucket rclone-test-ciqidep8qoxo: Purge remote 2025/11/03 03:45:50 INFO : B2 bucket rclone-test-ciqidep8qoxo: cleaning bucket "rclone-test-ciqidep8qoxo" of all files --- FAIL: TestServerSideCopy (5.01s) === RUN TestServerSideCopyOverSelf run.go:185: Remote "B2 bucket rclone-test-zakufow4reru", Local "Local file system at /tmp/rclone1253114081", Modify Window "1ms" 2025/11/03 03:45:51 DEBUG : Creating backend with remote "TestB2:rclone-test-fizaliq6vubo" sync_test.go:656: Server side copy (if possible) B2 bucket rclone-test-zakufow4reru -> B2 bucket rclone-test-fizaliq6vubo 2025/11/03 03:45:52 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/11/03 03:45:52 DEBUG : B2 bucket rclone-test-fizaliq6vubo: Waiting for checks to finish 2025/11/03 03:45:52 DEBUG : B2 bucket rclone-test-fizaliq6vubo: Waiting for transfers to finish 2025/11/03 03:45:53 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/03 03:45:53 DEBUG : B2 bucket rclone-test-fizaliq6vubo: Purge remote 2025/11/03 03:45:53 INFO : B2 bucket rclone-test-fizaliq6vubo: cleaning bucket "rclone-test-fizaliq6vubo" of all files --- FAIL: TestServerSideCopyOverSelf (3.42s) === RUN TestServerSideMoveOverSelf run.go:185: Remote "B2 bucket rclone-test-zakufow4reru", Local "Local file system at /tmp/rclone1253114081", Modify Window "1ms" 2025/11/03 03:45:55 DEBUG : Creating backend with remote "TestB2:rclone-test-dexuken8naba" 2025/11/03 03:45:55 DEBUG : pacer: low level retry 1/10 (error incident id 3894aee67876-07a7ec876d9ce42a (500 internal_error)) 2025/11/03 03:45:55 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/11/03 03:45:56 DEBUG : pacer: low level retry 2/10 (error incident id 3894aee67876-56c081acbaeda73d (500 internal_error)) 2025/11/03 03:45:56 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2025/11/03 03:45:56 DEBUG : pacer: low level retry 3/10 (error incident id 3894aee67876-79fc661fcd59e50e (500 internal_error)) 2025/11/03 03:45:56 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2025/11/03 03:45:57 DEBUG : pacer: low level retry 4/10 (error incident id 3894aee67876-ac233c78ad8dbe03 (500 internal_error)) 2025/11/03 03:45:57 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2025/11/03 03:45:57 DEBUG : pacer: low level retry 5/10 (error incident id 3894aee67876-3a383688edb0f022 (500 internal_error)) 2025/11/03 03:45:57 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2025/11/03 03:45:57 DEBUG : pacer: low level retry 6/10 (error incident id 3894aee67876-d766eed7c967ee0f (500 internal_error)) 2025/11/03 03:45:57 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2025/11/03 03:45:57 DEBUG : pacer: low level retry 7/10 (error incident id 3894aee67876-9a4f6073eb1063b5 (500 internal_error)) 2025/11/03 03:45:57 DEBUG : pacer: Rate limited, increasing sleep to 1.28s 2025/11/03 03:45:58 DEBUG : pacer: low level retry 8/10 (error incident id 3894aee67876-3f9aec7fdb02284e (500 internal_error)) 2025/11/03 03:45:58 DEBUG : pacer: Rate limited, increasing sleep to 2.56s 2025/11/03 03:45:59 DEBUG : pacer: low level retry 9/10 (error incident id 3894aee67876-4eb57a344dbc3432 (500 internal_error)) 2025/11/03 03:45:59 DEBUG : pacer: Rate limited, increasing sleep to 5.12s 2025/11/03 03:46:02 DEBUG : pacer: low level retry 10/10 (error incident id 3894aee67876-3c93c80b5998457f (500 internal_error)) 2025/11/03 03:46:02 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-3c93c80b5998457f (500 internal_error) Test: TestServerSideMoveOverSelf --- FAIL: TestServerSideMoveOverSelf (8.52s) === RUN TestSyncAfterChangingModtimeOnly run.go:185: Remote "B2 bucket rclone-test-zakufow4reru", Local "Local file system at /tmp/rclone1253114081", Modify Window "1ms" 2025/11/03 03:46:04 DEBUG : empty space: size = 1 OK 2025/11/03 03:46:04 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/03 03:46:04 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for checks to finish 2025/11/03 03:46:04 DEBUG : empty space: sha1 = 3bc15c8aae3e4124dd409035f32ea2fd6835efc9 OK 2025/11/03 03:46:04 NOTICE: empty space: Skipped update modification time as --dry-run is set (size 1) 2025/11/03 03:46:04 DEBUG : empty space: Unchanged skipping 2025/11/03 03:46:04 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for transfers to finish 2025/11/03 03:46:04 DEBUG : Waiting for deletions to finish 2025/11/03 03:46:04 INFO : There was nothing to transfer 2025/11/03 03:46:04 DEBUG : empty space: size = 1 OK 2025/11/03 03:46:04 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/03 03:46:04 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for checks to finish 2025/11/03 03:46:04 DEBUG : empty space: sha1 = 3bc15c8aae3e4124dd409035f32ea2fd6835efc9 OK 2025/11/03 03:46:05 ERROR : empty space: Failed to set modification time: expected a FileSseMode but found: '' (400 bad_request) 2025/11/03 03:46:05 DEBUG : empty space: Unchanged skipping 2025/11/03 03:46:05 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for transfers to finish 2025/11/03 03:46:05 ERROR : B2 bucket rclone-test-zakufow4reru: not deleting files as there were IO errors 2025/11/03 03:46:05 ERROR : B2 bucket rclone-test-zakufow4reru: 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.56s) === RUN TestSyncWithTrackRenames run.go:185: Remote "B2 bucket rclone-test-zakufow4reru", Local "Local file system at /tmp/rclone1253114081", Modify Window "1ms" sync_test.go:1568: Can track renames: true 2025/11/03 03:46:06 INFO : B2 bucket rclone-test-zakufow4reru: Making map for --track-renames 2025/11/03 03:46:06 INFO : B2 bucket rclone-test-zakufow4reru: Finished making map for --track-renames 2025/11/03 03:46:06 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for checks to finish 2025/11/03 03:46:06 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/11/03 03:46:06 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/11/03 03:46:06 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for renames to finish 2025/11/03 03:46:06 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for transfers to finish 2025/11/03 03:46:06 DEBUG : yam: size = 11 OK 2025/11/03 03:46:06 DEBUG : yam: sha1 = ad84b2fb6729688a5ee3225164a6d4d58465b33e OK 2025/11/03 03:46:06 INFO : yam: Copied (new) 2025/11/03 03:46:07 DEBUG : potato: size = 14 OK 2025/11/03 03:46:07 DEBUG : potato: sha1 = 1d1ac61cfffcfdd0a15cc9ae575fb06ca8c11fb5 OK 2025/11/03 03:46:07 INFO : potato: Copied (new) 2025/11/03 03:46:07 DEBUG : Waiting for deletions to finish 2025/11/03 03:46:08 DEBUG : potato: size = 14 OK 2025/11/03 03:46:08 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/11/03 03:46:08 INFO : B2 bucket rclone-test-zakufow4reru: Making map for --track-renames 2025/11/03 03:46:08 INFO : B2 bucket rclone-test-zakufow4reru: Finished making map for --track-renames 2025/11/03 03:46:08 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for checks to finish 2025/11/03 03:46:08 DEBUG : potato: Unchanged skipping 2025/11/03 03:46:08 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for renames to finish 2025/11/03 03:46:08 ERROR : yam: Failed to copy: expected a FileSseMode but found: '' (400 bad_request) 2025/11/03 03:46:08 ERROR : yam: Not deleting source as copy failed: expected a FileSseMode but found: '' (400 bad_request) 2025/11/03 03:46:08 DEBUG : yaml: Failed to rename to "yam": expected a FileSseMode but found: '' (400 bad_request) 2025/11/03 03:46:08 DEBUG : yaml: Need to transfer - No matching file found at Destination 2025/11/03 03:46:08 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for transfers to finish 2025/11/03 03:46:08 DEBUG : yaml: size = 11 OK 2025/11/03 03:46:08 DEBUG : yaml: sha1 = ad84b2fb6729688a5ee3225164a6d4d58465b33e OK 2025/11/03 03:46:08 INFO : yaml: Copied (new) 2025/11/03 03:46:08 ERROR : B2 bucket rclone-test-zakufow4reru: not deleting files as there were IO errors 2025/11/03 03:46:08 ERROR : B2 bucket rclone-test-zakufow4reru: 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.66s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:185: Remote "B2 bucket rclone-test-zakufow4reru", Local "Local file system at /tmp/rclone1253114081", Modify Window "1ms" sync_test.go:1640: Can track renames: true 2025/11/03 03:46:09 INFO : B2 bucket rclone-test-zakufow4reru: Making map for --track-renames 2025/11/03 03:46:09 INFO : B2 bucket rclone-test-zakufow4reru: Finished making map for --track-renames 2025/11/03 03:46:09 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for checks to finish 2025/11/03 03:46:09 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/11/03 03:46:09 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/11/03 03:46:09 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for renames to finish 2025/11/03 03:46:09 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for transfers to finish 2025/11/03 03:46:09 DEBUG : yam: size = 11 OK 2025/11/03 03:46:09 DEBUG : yam: sha1 = ad84b2fb6729688a5ee3225164a6d4d58465b33e OK 2025/11/03 03:46:09 INFO : yam: Copied (new) 2025/11/03 03:46:10 DEBUG : potato: size = 14 OK 2025/11/03 03:46:10 DEBUG : potato: sha1 = 1d1ac61cfffcfdd0a15cc9ae575fb06ca8c11fb5 OK 2025/11/03 03:46:10 INFO : potato: Copied (new) 2025/11/03 03:46:10 DEBUG : Waiting for deletions to finish 2025/11/03 03:46:10 DEBUG : potato: size = 14 OK 2025/11/03 03:46:10 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/11/03 03:46:10 INFO : B2 bucket rclone-test-zakufow4reru: Making map for --track-renames 2025/11/03 03:46:10 INFO : B2 bucket rclone-test-zakufow4reru: Finished making map for --track-renames 2025/11/03 03:46:10 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for checks to finish 2025/11/03 03:46:10 DEBUG : potato: Unchanged skipping 2025/11/03 03:46:10 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for renames to finish 2025/11/03 03:46:10 ERROR : yam: Failed to copy: expected a FileSseMode but found: '' (400 bad_request) 2025/11/03 03:46:10 ERROR : yam: Not deleting source as copy failed: expected a FileSseMode but found: '' (400 bad_request) 2025/11/03 03:46:10 DEBUG : yaml: Failed to rename to "yam": expected a FileSseMode but found: '' (400 bad_request) 2025/11/03 03:46:10 DEBUG : yaml: Need to transfer - No matching file found at Destination 2025/11/03 03:46:10 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for transfers to finish 2025/11/03 03:46:11 DEBUG : yaml: size = 11 OK 2025/11/03 03:46:11 DEBUG : yaml: sha1 = ad84b2fb6729688a5ee3225164a6d4d58465b33e OK 2025/11/03 03:46:11 INFO : yaml: Copied (new) 2025/11/03 03:46:11 ERROR : B2 bucket rclone-test-zakufow4reru: not deleting files as there were IO errors 2025/11/03 03:46:11 ERROR : B2 bucket rclone-test-zakufow4reru: 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.44s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:185: Remote "B2 bucket rclone-test-zakufow4reru", Local "Local file system at /tmp/rclone1253114081", Modify Window "1ms" sync_test.go:1679: Can track renames: true 2025/11/03 03:46:12 INFO : B2 bucket rclone-test-zakufow4reru: Making map for --track-renames 2025/11/03 03:46:12 INFO : B2 bucket rclone-test-zakufow4reru: Finished making map for --track-renames 2025/11/03 03:46:12 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for checks to finish 2025/11/03 03:46:12 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/11/03 03:46:12 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for renames to finish 2025/11/03 03:46:12 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/11/03 03:46:12 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for transfers to finish 2025/11/03 03:46:12 DEBUG : potato: size = 14 OK 2025/11/03 03:46:12 DEBUG : potato: sha1 = 1d1ac61cfffcfdd0a15cc9ae575fb06ca8c11fb5 OK 2025/11/03 03:46:12 INFO : potato: Copied (new) 2025/11/03 03:46:13 DEBUG : sub/yam: size = 11 OK 2025/11/03 03:46:13 DEBUG : sub/yam: sha1 = ad84b2fb6729688a5ee3225164a6d4d58465b33e OK 2025/11/03 03:46:13 INFO : sub/yam: Copied (new) 2025/11/03 03:46:13 DEBUG : Waiting for deletions to finish 2025/11/03 03:46:13 DEBUG : potato: size = 14 OK 2025/11/03 03:46:13 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/11/03 03:46:13 INFO : B2 bucket rclone-test-zakufow4reru: Making map for --track-renames 2025/11/03 03:46:13 DEBUG : potato: Unchanged skipping 2025/11/03 03:46:13 INFO : B2 bucket rclone-test-zakufow4reru: Finished making map for --track-renames 2025/11/03 03:46:13 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for checks to finish 2025/11/03 03:46:13 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for renames to finish 2025/11/03 03:46:13 ERROR : sub/yam: Failed to copy: expected a FileSseMode but found: '' (400 bad_request) 2025/11/03 03:46:13 ERROR : sub/yam: Not deleting source as copy failed: expected a FileSseMode but found: '' (400 bad_request) 2025/11/03 03:46:13 DEBUG : yam: Failed to rename to "sub/yam": expected a FileSseMode but found: '' (400 bad_request) 2025/11/03 03:46:13 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/11/03 03:46:13 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for transfers to finish 2025/11/03 03:46:14 DEBUG : yam: size = 11 OK 2025/11/03 03:46:14 DEBUG : yam: sha1 = ad84b2fb6729688a5ee3225164a6d4d58465b33e OK 2025/11/03 03:46:14 INFO : yam: Copied (new) 2025/11/03 03:46:14 ERROR : B2 bucket rclone-test-zakufow4reru: not deleting files as there were IO errors 2025/11/03 03:46:14 ERROR : B2 bucket rclone-test-zakufow4reru: 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 (3.10s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:185: Remote "B2 bucket rclone-test-zakufow4reru", Local "Local file system at /tmp/rclone1253114081", Modify Window "1ms" 2025/11/03 03:46:15 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/11/03 03:46:15 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/11/03 03:46:15 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for checks to finish 2025/11/03 03:46:15 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for transfers to finish 2025/11/03 03:46:15 DEBUG : nested/sub dir/file: size = 6 OK 2025/11/03 03:46:15 DEBUG : nested/sub dir/file: sha1 = b4b3e0a278988bc15f2913af3f4153ccef74e465 OK 2025/11/03 03:46:15 INFO : nested/sub dir/file: Copied (new) 2025/11/03 03:46:15 INFO : nested/sub dir/file: Deleted 2025/11/03 03:46:15 DEBUG : sub dir/hello world: size = 11 OK 2025/11/03 03:46:15 DEBUG : sub dir/hello world: sha1 = 2aae6c35c94fcfb415dbe95f408b9ce91ee846ed OK 2025/11/03 03:46:15 INFO : sub dir/hello world: Copied (new) 2025/11/03 03:46:15 INFO : sub dir/hello world: Deleted 2025/11/03 03:46:15 ERROR : Local file system at /tmp/rclone1253114081: 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.38s) === RUN TestServerSideMove run.go:185: Remote "B2 bucket rclone-test-zakufow4reru", Local "Local file system at /tmp/rclone1253114081", Modify Window "1ms" 2025/11/03 03:46:16 DEBUG : Creating backend with remote "TestB2:rclone-test-havitin1bofu" 2025/11/03 03:46:17 DEBUG : pacer: low level retry 1/10 (error incident id 3894aee67876-33e0ffcfd518fb06 (500 internal_error)) 2025/11/03 03:46:17 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/11/03 03:46:17 DEBUG : pacer: low level retry 2/10 (error incident id 3894aee67876-55558f4b49b3f411 (500 internal_error)) 2025/11/03 03:46:17 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2025/11/03 03:46:17 DEBUG : pacer: low level retry 3/10 (error incident id 3894aee67876-a791c7eb1b04d573 (500 internal_error)) 2025/11/03 03:46:17 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2025/11/03 03:46:17 DEBUG : pacer: low level retry 4/10 (error incident id 3894aee67876-d970cfe5a958dcb9 (500 internal_error)) 2025/11/03 03:46:17 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2025/11/03 03:46:17 DEBUG : pacer: low level retry 5/10 (error incident id 3894aee67876-0e7610455febe08e (500 internal_error)) 2025/11/03 03:46:17 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2025/11/03 03:46:18 DEBUG : pacer: low level retry 6/10 (error incident id 3894aee67876-99902fbfed0c0fc9 (500 internal_error)) 2025/11/03 03:46:18 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2025/11/03 03:46:18 DEBUG : pacer: low level retry 7/10 (error incident id 3894aee67876-0dfbe314df2c6ced (500 internal_error)) 2025/11/03 03:46:18 DEBUG : pacer: Rate limited, increasing sleep to 1.28s 2025/11/03 03:46:19 DEBUG : pacer: low level retry 8/10 (error incident id 3894aee67876-956c991e7b2a6382 (500 internal_error)) 2025/11/03 03:46:19 DEBUG : pacer: Rate limited, increasing sleep to 2.56s 2025/11/03 03:46:20 DEBUG : pacer: low level retry 9/10 (error incident id 3894aee67876-fed5cfdcd2c005c3 (500 internal_error)) 2025/11/03 03:46:20 DEBUG : pacer: Rate limited, increasing sleep to 5.12s 2025/11/03 03:46:22 DEBUG : pacer: low level retry 10/10 (error incident id 3894aee67876-73c766f7b376e5c7 (500 internal_error)) 2025/11/03 03:46:22 DEBUG : pacer: Rate limited, increasing sleep to 10.24s sync_test.go:1721: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1721 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1911 Error: Received unexpected error: failed to authorize account: failed to authenticate: incident id 3894aee67876-73c766f7b376e5c7 (500 internal_error) Test: TestServerSideMove --- FAIL: TestServerSideMove (7.18s) === RUN TestServerSideMoveWithFilter run.go:185: Remote "B2 bucket rclone-test-zakufow4reru", Local "Local file system at /tmp/rclone1253114081", Modify Window "1ms" 2025/11/03 03:46:23 DEBUG : Creating backend with remote "TestB2:rclone-test-beluxab9vuqo" sync_test.go:1735: Server side move (if possible) B2 bucket rclone-test-zakufow4reru -> B2 bucket rclone-test-beluxab9vuqo 2025/11/03 03:46:28 DEBUG : empty space: Excluded (Size Filter) 2025/11/03 03:46:28 DEBUG : empty space: Excluded (Size Filter) 2025/11/03 03:46:28 DEBUG : potato2: Need to transfer - File not found at Destination 2025/11/03 03:46:28 DEBUG : potato3: size = 68 (B2 bucket rclone-test-zakufow4reru) 2025/11/03 03:46:28 DEBUG : potato3: size = 60 (B2 bucket rclone-test-beluxab9vuqo) 2025/11/03 03:46:28 DEBUG : potato3: Sizes differ 2025/11/03 03:46:28 DEBUG : B2 bucket rclone-test-beluxab9vuqo: Waiting for checks to finish 2025/11/03 03:46:28 DEBUG : B2 bucket rclone-test-beluxab9vuqo: Waiting for transfers to finish 2025/11/03 03:46:28 ERROR : potato2: Failed to copy: expected a FileSseMode but found: '' (400 bad_request) 2025/11/03 03:46:28 ERROR : potato2: Not deleting source as copy failed: expected a FileSseMode but found: '' (400 bad_request) 2025/11/03 03:46:29 ERROR : potato3: Failed to copy: expected a FileSseMode but found: '' (400 bad_request) 2025/11/03 03:46:29 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/03 03:46:29 DEBUG : B2 bucket rclone-test-beluxab9vuqo: Purge remote 2025/11/03 03:46:29 INFO : B2 bucket rclone-test-beluxab9vuqo: cleaning bucket "rclone-test-beluxab9vuqo" of all files 2025/11/03 03:46:29 DEBUG : empty space: Deleting (id "4_z0ff2cd63d02d4b7b9fa80e1b_f1165fe5434dbf981_d20251103_m034628_c001_v0001183_t0053_u01762141588024") 2025/11/03 03:46:29 DEBUG : potato3: Deleting (id "4_z0ff2cd63d02d4b7b9fa80e1b_f1165fe5434dbf983_d20251103_m034628_c001_v0001183_t0054_u01762141588237") --- FAIL: TestServerSideMoveWithFilter (7.18s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:185: Remote "B2 bucket rclone-test-zakufow4reru", Local "Local file system at /tmp/rclone1253114081", Modify Window "1ms" 2025/11/03 03:46:30 DEBUG : Creating backend with remote "TestB2:rclone-test-kozasec3gole" 2025/11/03 03:46:31 DEBUG : pacer: low level retry 1/10 (error incident id 3894aee67876-036522c3b128052f (500 internal_error)) 2025/11/03 03:46:31 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/11/03 03:46:31 DEBUG : pacer: low level retry 2/10 (error incident id 3894aee67876-08f102ca069ed1b2 (500 internal_error)) 2025/11/03 03:46:31 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2025/11/03 03:46:31 DEBUG : pacer: low level retry 3/10 (error incident id 3894aee67876-653d16232b588d1e (500 internal_error)) 2025/11/03 03:46:31 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2025/11/03 03:46:31 DEBUG : pacer: low level retry 4/10 (error incident id 3894aee67876-7ca679f6b65073e4 (500 internal_error)) 2025/11/03 03:46:31 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2025/11/03 03:46:32 DEBUG : pacer: low level retry 5/10 (error incident id 3894aee67876-70e8ca5ffdbe2445 (500 internal_error)) 2025/11/03 03:46:32 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2025/11/03 03:46:32 DEBUG : pacer: low level retry 6/10 (error incident id 3894aee67876-9809805e2753efef (500 internal_error)) 2025/11/03 03:46:32 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2025/11/03 03:46:32 DEBUG : pacer: low level retry 7/10 (error incident id 3894aee67876-574ad3122a56e54d (500 internal_error)) 2025/11/03 03:46:32 DEBUG : pacer: Rate limited, increasing sleep to 1.28s 2025/11/03 03:46:33 DEBUG : pacer: low level retry 8/10 (error incident id 3894aee67876-d174e436669479ee (500 internal_error)) 2025/11/03 03:46:33 DEBUG : pacer: Rate limited, increasing sleep to 2.56s 2025/11/03 03:46:34 DEBUG : pacer: low level retry 9/10 (error incident id 3894aee67876-0c22f1e1b9f9f243 (500 internal_error)) 2025/11/03 03:46:34 DEBUG : pacer: Rate limited, increasing sleep to 5.12s 2025/11/03 03:46:37 DEBUG : pacer: low level retry 10/10 (error incident id 3894aee67876-fe6287caad3ae313 (500 internal_error)) 2025/11/03 03:46:37 DEBUG : pacer: Rate limited, increasing sleep to 10.24s sync_test.go:1721: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1721 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1931 Error: Received unexpected error: failed to authorize account: failed to authenticate: incident id 3894aee67876-fe6287caad3ae313 (500 internal_error) Test: TestServerSideMoveDeleteEmptySourceDirs --- FAIL: TestServerSideMoveDeleteEmptySourceDirs (7.10s) === RUN TestSyncOverlapWithFilter run.go:185: Remote "B2 bucket rclone-test-zakufow4reru", Local "Local file system at /tmp/rclone1253114081", Modify Window "1ms" 2025/11/03 03:46:37 DEBUG : Creating backend with remote "TestB2:rclone-test-zakufow4reru/rclone-sync-test" 2025/11/03 03:46:37 DEBUG : Config file has changed externally - reloading 2025/11/03 03:46:39 DEBUG : Creating backend with remote "TestB2:rclone-test-zakufow4reru/rclone-sync-test-include/layer2" 2025/11/03 03:46:41 DEBUG : Creating backend with remote "TestB2:rclone-test-zakufow4reru/rclone-sync-test-ignore-file" 2025/11/03 03:46:45 DEBUG : B2 bucket rclone-test-zakufow4reru path rclone-sync-test: Waiting for checks to finish 2025/11/03 03:46:45 DEBUG : B2 bucket rclone-test-zakufow4reru path rclone-sync-test: Waiting for transfers to finish 2025/11/03 03:46:45 DEBUG : Waiting for deletions to finish 2025/11/03 03:46:45 INFO : There was nothing to transfer 2025/11/03 03:46:45 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for checks to finish 2025/11/03 03:46:45 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for transfers to finish 2025/11/03 03:46:45 DEBUG : Waiting for deletions to finish 2025/11/03 03:46:45 INFO : There was nothing to transfer 2025/11/03 03:46:46 DEBUG : B2 bucket rclone-test-zakufow4reru path rclone-sync-test-include/layer2: Waiting for checks to finish 2025/11/03 03:46:46 DEBUG : B2 bucket rclone-test-zakufow4reru path rclone-sync-test-include/layer2: Waiting for transfers to finish 2025/11/03 03:46:46 DEBUG : Waiting for deletions to finish 2025/11/03 03:46:46 INFO : There was nothing to transfer 2025/11/03 03:46:46 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for checks to finish 2025/11/03 03:46:46 DEBUG : B2 bucket rclone-test-zakufow4reru: Waiting for transfers to finish 2025/11/03 03:46:46 DEBUG : Waiting for deletions to finish 2025/11/03 03:46:46 INFO : There was nothing to transfer 2025/11/03 03:46:47 DEBUG : B2 bucket rclone-test-zakufow4reru path rclone-sync-test-ignore-file: Waiting for checks to finish 2025/11/03 03:46:47 DEBUG : B2 bucket rclone-test-zakufow4reru path rclone-sync-test-ignore-file: Waiting for transfers to finish 2025/11/03 03:46:47 DEBUG : Waiting for deletions to finish 2025/11/03 03:46:47 INFO : There was nothing to transfer --- PASS: TestSyncOverlapWithFilter (9.69s) FAIL 2025/11/03 03:46:47 DEBUG : B2 bucket rclone-test-zakufow4reru: Purge remote 2025/11/03 03:46:47 INFO : B2 bucket rclone-test-zakufow4reru: cleaning bucket "rclone-test-zakufow4reru" of all files 2025/11/03 03:46:47 DEBUG : empty space: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f420343d706863c8e_d20251103_m034630_c001_v7007000_t0000_u01762141590193") 2025/11/03 03:46:47 DEBUG : empty space: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f105ea26879d5e55b_d20251103_m034625_c001_v0001117_t0006_u01762141585246") 2025/11/03 03:46:47 DEBUG : empty space: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f400b1d5622efbb03_d20251103_m034605_c001_v7007000_t0000_u01762141565620") 2025/11/03 03:46:47 DEBUG : empty space: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f1006c18380cc85dc_d20251103_m034603_c001_v0001181_t0028_u01762141563788") 2025/11/03 03:46:47 DEBUG : nested/sub dir/file: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f400b1d5622efbb22_d20251103_m034616_c001_v7007000_t0000_u01762141576015") 2025/11/03 03:46:47 DEBUG : nested/sub dir/file: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f1006c18380cc8617_d20251103_m034615_c001_v0001181_t0043_u01762141575374") 2025/11/03 03:46:47 DEBUG : potato: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f400b1d5622efbb17_d20251103_m034614_c001_v7007000_t0000_u01762141574455") 2025/11/03 03:46:47 DEBUG : potato: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f1006c18380cc860b_d20251103_m034612_c001_v0001181_t0010_u01762141572272") 2025/11/03 03:46:47 DEBUG : potato: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f400b1d5622efbb0b_d20251103_m034611_c001_v7007000_t0000_u01762141571358") 2025/11/03 03:46:48 DEBUG : potato: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f105ea26879d5e524_d20251103_m034609_c001_v0001117_t0044_u01762141569829") 2025/11/03 03:46:48 DEBUG : potato: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f400b1d5622efbb08_d20251103_m034608_c001_v7007000_t0000_u01762141568920") 2025/11/03 03:46:48 DEBUG : potato: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f105ea26879d5e51c_d20251103_m034606_c001_v0001117_t0005_u01762141566733") 2025/11/03 03:46:48 DEBUG : potato2: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f420343d706863c91_d20251103_m034630_c001_v7007000_t0000_u01762141590374") 2025/11/03 03:46:48 DEBUG : potato2: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f1006c18380cc863e_d20251103_m034624_c001_v0001181_t0025_u01762141584675") 2025/11/03 03:46:48 DEBUG : potato3: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f420343d706863c92_d20251103_m034630_c001_v7007000_t0000_u01762141590555") 2025/11/03 03:46:48 DEBUG : potato3: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f1006c18380cc8642_d20251103_m034626_c001_v0001181_t0008_u01762141586158") 2025/11/03 03:46:48 DEBUG : rclone-sync-test-ignore-file/.ignore: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f405701c3684b5030_d20251103_m034647_c001_v7007000_t0000_u01762141607347") 2025/11/03 03:46:48 DEBUG : rclone-sync-test-ignore-file/.ignore: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f105ea26879d5e588_d20251103_m034644_c001_v0001117_t0056_u01762141604023") 2025/11/03 03:46:48 DEBUG : sub dir/hello world: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f400b1d5622efbb24_d20251103_m034616_c001_v7007000_t0000_u01762141576197") 2025/11/03 03:46:48 DEBUG : sub dir/hello world: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f105ea26879d5e532_d20251103_m034615_c001_v0001117_t0038_u01762141575364") 2025/11/03 03:46:48 DEBUG : sub dir/hello world: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f400b1d5622efbb02_d20251103_m034603_c001_v7007000_t0000_u01762141563059") 2025/11/03 03:46:48 DEBUG : sub dir/hello world: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f1006c18380cc85b9_d20251103_m034554_c001_v0001181_t0012_u01762141554904") 2025/11/03 03:46:48 DEBUG : sub dir/hello world: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f41673bf139c3c02c_d20251103_m034554_c001_v7007000_t0000_u01762141554539") 2025/11/03 03:46:48 DEBUG : sub dir/hello world: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f1006c18380cc85ae_d20251103_m034551_c001_v0001181_t0012_u01762141551484") 2025/11/03 03:46:49 DEBUG : sub dir/hello world: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f41673bf139c3c020_d20251103_m034551_c001_v7007000_t0000_u01762141551119") 2025/11/03 03:46:49 DEBUG : sub dir/hello world: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f1006c18380cc859a_d20251103_m034547_c001_v0001181_t0027_u01762141547964") 2025/11/03 03:46:49 DEBUG : sub/yam: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f400b1d5622efbb19_d20251103_m034614_c001_v7007000_t0000_u01762141574637") 2025/11/03 03:46:49 DEBUG : sub/yam: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f105ea26879d5e52e_d20251103_m034612_c001_v0001117_t0036_u01762141572263") 2025/11/03 03:46:49 DEBUG : yam: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f400b1d5622efbb1a_d20251103_m034614_c001_v7007000_t0000_u01762141574821") 2025/11/03 03:46:49 DEBUG : yam: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f1006c18380cc8611_d20251103_m034614_c001_v0001181_t0053_u01762141574067") 2025/11/03 03:46:49 DEBUG : yam: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f400b1d5622efbb0c_d20251103_m034611_c001_v7007000_t0000_u01762141571539") 2025/11/03 03:46:49 DEBUG : yam: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f1006c18380cc85fb_d20251103_m034609_c001_v0001181_t0038_u01762141569839") 2025/11/03 03:46:49 DEBUG : yam: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f400b1d5622efbb09_d20251103_m034609_c001_v7007000_t0000_u01762141569102") 2025/11/03 03:46:49 DEBUG : yam: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f1006c18380cc85e7_d20251103_m034606_c001_v0001181_t0004_u01762141566163") 2025/11/03 03:46:49 DEBUG : yaml: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f400b1d5622efbb0d_d20251103_m034611_c001_v7007000_t0000_u01762141571720") 2025/11/03 03:46:49 DEBUG : yaml: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f1006c18380cc85ff_d20251103_m034610_c001_v0001181_t0031_u01762141570976") 2025/11/03 03:46:49 DEBUG : yaml: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f400b1d5622efbb0a_d20251103_m034609_c001_v7007000_t0000_u01762141569284") 2025/11/03 03:46:49 DEBUG : yaml: Deleting (id "4_z6f522d93d02d4b7b9fa80e1b_f1006c18380cc85f3_d20251103_m034608_c001_v0001181_t0037_u01762141568529") "./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|TestSyncOverlapWithFilter|TestSyncWithTrackRenames|TestSyncWithTrackRenamesStrategyLeaf|TestSyncWithTrackRenamesStrategyModtime)$'" - Finished ERROR in 1m4.852896256s (try 2/5): exit status 1: Failed [TestServerSideCopy TestServerSideCopyOverSelf TestServerSideMoveOverSelf TestSyncAfterChangingModtimeOnly TestSyncWithTrackRenames TestSyncWithTrackRenamesStrategyModtime TestSyncWithTrackRenamesStrategyLeaf TestMoveWithDeleteEmptySrcDirs TestServerSideMove TestServerSideMoveWithFilter TestServerSideMoveDeleteEmptySourceDirs]