"./operations.test -test.v -test.timeout 1h0m0s -remote TestB2: -list-retries 5 -verbose -fast-list -test.run '^(TestCopyFileBackupDir|TestCopyFileCopyDest|TestDirMove|TestMoveFileBackupDir|TestMultithreadCopy|TestMultithreadCopyAbort|TestTouchDir)$'" - Starting (try 3/5)
2025/11/02 04:31:50 DEBUG : Creating backend with remote "TestB2:rclone-test-wobosoz6dufo"
2025/11/02 04:31:50 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/11/02 04:31:50 DEBUG : Creating backend with remote "/tmp/rclone1204639492"
=== RUN   TestMultithreadCopy
    run.go:185: Remote "B2 bucket rclone-test-wobosoz6dufo", Local "Local file system at /tmp/rclone1204639492", Modify Window "1ms"
    multithread_test.go:137: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/multithread_test.go:137
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/operations/multithread_test.go:148
        	Error:      	Received unexpected error:
        	            	expected a FileSseMode but found: '' (400 bad_request)
        	Test:       	TestMultithreadCopy
--- FAIL: TestMultithreadCopy (1.38s)
=== RUN   TestMultithreadCopyAbort
    run.go:185: Remote "B2 bucket rclone-test-wobosoz6dufo", Local "Local file system at /tmp/rclone1204639492", Modify Window "1ms"
    multithread_test.go:137: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/multithread_test.go:137
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/operations/multithread_test.go:293
        	Error:      	Received unexpected error:
        	            	expected a FileSseMode but found: '' (400 bad_request)
        	Test:       	TestMultithreadCopyAbort
--- FAIL: TestMultithreadCopyAbort (0.53s)
=== RUN   TestCopyFileBackupDir
    run.go:185: Remote "B2 bucket rclone-test-wobosoz6dufo", Local "Local file system at /tmp/rclone1204639492", Modify Window "1ms"
2025/11/02 04:31:54 DEBUG : Creating backend with remote "TestB2:rclone-test-wobosoz6dufo/backup"
2025/11/02 04:31:55 DEBUG : dst/file1: size = 14 (Local file system at /tmp/rclone1204639492)
2025/11/02 04:31:55 DEBUG : dst/file1: size = 18 (B2 bucket rclone-test-wobosoz6dufo)
2025/11/02 04:31:55 DEBUG : dst/file1: Sizes differ
2025/11/02 04:31:56 ERROR : dst/file1: Failed to copy: expected a FileSseMode but found: '' (400 bad_request)
2025/11/02 04:31:56 ERROR : dst/file1: Not deleting source as copy failed: expected a FileSseMode but found: '' (400 bad_request)
    copy_test.go:186: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy_test.go:186
        	Error:      	Received unexpected error:
        	            	moving to --backup-dir failed: expected a FileSseMode but found: '' (400 bad_request)
        	Test:       	TestCopyFileBackupDir
--- FAIL: TestCopyFileBackupDir (4.60s)
=== RUN   TestCopyFileCopyDest
    run.go:185: Remote "B2 bucket rclone-test-wobosoz6dufo", Local "Local file system at /tmp/rclone1204639492", Modify Window "1ms"
2025/11/02 04:31:57 DEBUG : Creating backend with remote "TestB2:rclone-test-wobosoz6dufo/dst"
2025/11/02 04:31:58 DEBUG : Creating backend with remote "TestB2:rclone-test-wobosoz6dufo/CopyDest"
2025/11/02 04:31:59 DEBUG : one: Need to transfer - File not found at Destination
2025/11/02 04:32:02 DEBUG : one: size = 3 OK
2025/11/02 04:32:02 DEBUG : one: sha1 = fe05bcdcdc4928012781a5f1a2a77cbb5398e106 OK
2025/11/02 04:32:02 INFO  : one: Copied (new)
2025/11/02 04:32:03 DEBUG : one: size = 5 (Local file system at /tmp/rclone1204639492)
2025/11/02 04:32:03 DEBUG : one: size = 3 (B2 bucket rclone-test-wobosoz6dufo path dst)
2025/11/02 04:32:03 DEBUG : one: Sizes differ
2025/11/02 04:32:04 DEBUG : one: size = 5 OK
2025/11/02 04:32:04 DEBUG : one: sha1 = 7f376fd65843a1267de8f986d40e164e5a321c13 OK
2025/11/02 04:32:04 INFO  : one: Copied (replaced existing)
2025/11/02 04:32:06 DEBUG : Creating backend with remote "TestB2:rclone-test-wobosoz6dufo/BackupDir"
2025/11/02 04:32:07 DEBUG : one: size = 5 (Local file system at /tmp/rclone1204639492)
2025/11/02 04:32:07 DEBUG : one: size = 3 (B2 bucket rclone-test-wobosoz6dufo path dst)
2025/11/02 04:32:07 DEBUG : one: Sizes differ
2025/11/02 04:32:07 DEBUG : one: size = 5 OK
2025/11/02 04:32:07 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/11/02 04:32:07 DEBUG : one: size = 5 (Local file system at /tmp/rclone1204639492)
2025/11/02 04:32:07 DEBUG : one: size = 3 (B2 bucket rclone-test-wobosoz6dufo path dst)
2025/11/02 04:32:07 DEBUG : one: Sizes differ
2025/11/02 04:32:08 ERROR : one: Failed to copy: expected a FileSseMode but found: '' (400 bad_request)
2025/11/02 04:32:08 ERROR : one: Not deleting source as copy failed: expected a FileSseMode but found: '' (400 bad_request)
    copy_test.go:321: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy_test.go:321
        	Error:      	Received unexpected error:
        	            	moving to --backup-dir failed: expected a FileSseMode but found: '' (400 bad_request)
        	Test:       	TestCopyFileCopyDest
--- FAIL: TestCopyFileCopyDest (11.94s)
=== RUN   TestMoveFileBackupDir
    run.go:185: Remote "B2 bucket rclone-test-wobosoz6dufo", Local "Local file system at /tmp/rclone1204639492", Modify Window "1ms"
2025/11/02 04:32:10 DEBUG : Creating backend with remote "TestB2:rclone-test-wobosoz6dufo/backup"
2025/11/02 04:32:11 DEBUG : pacer: low level retry 1/10 (error incident id 3894aee67876-46fb89958b15ccf3 (500 internal_error))
2025/11/02 04:32:11 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/11/02 04:32:11 DEBUG : pacer: low level retry 2/10 (error incident id 3894aee67876-ff7097a5df4804f1 (500 internal_error))
2025/11/02 04:32:11 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/11/02 04:32:11 DEBUG : pacer: low level retry 3/10 (error incident id 3894aee67876-64efa49143f6d96b (500 internal_error))
2025/11/02 04:32:11 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2025/11/02 04:32:11 DEBUG : pacer: low level retry 4/10 (error incident id 3894aee67876-ac3166cd61de44f9 (500 internal_error))
2025/11/02 04:32:11 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2025/11/02 04:32:11 DEBUG : pacer: low level retry 5/10 (error incident id 3894aee67876-fea27b33592fe0c6 (500 internal_error))
2025/11/02 04:32:11 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2025/11/02 04:32:12 DEBUG : pacer: low level retry 6/10 (error incident id 3894aee67876-b87a92be31bc60a2 (500 internal_error))
2025/11/02 04:32:12 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2025/11/02 04:32:12 DEBUG : pacer: low level retry 7/10 (error incident id 3894aee67876-c30b7ffb4f31c2ad (500 internal_error))
2025/11/02 04:32:12 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2025/11/02 04:32:12 DEBUG : pacer: low level retry 8/10 (error incident id 3894aee67876-fbb32ae4cb908669 (500 internal_error))
2025/11/02 04:32:12 DEBUG : pacer: Rate limited, increasing sleep to 2.56s
2025/11/02 04:32:14 DEBUG : pacer: low level retry 9/10 (error incident id 3894aee67876-855e2647d81b78c4 (500 internal_error))
2025/11/02 04:32:14 DEBUG : pacer: Rate limited, increasing sleep to 5.12s
2025/11/02 04:32:16 DEBUG : pacer: low level retry 10/10 (error incident id 3894aee67876-4d41e3f0e50531e8 (500 internal_error))
2025/11/02 04:32:16 DEBUG : pacer: Rate limited, increasing sleep to 10.24s
    operations_test.go:1052: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:1052
        	Error:      	Received unexpected error:
        	            	creating Fs for --backup-dir failed: failed to make fs for --backup-dir "TestB2:rclone-test-wobosoz6dufo/backup": failed to authorize account: failed to authenticate: incident id 3894aee67876-4d41e3f0e50531e8 (500 internal_error)
        	Test:       	TestMoveFileBackupDir
--- FAIL: TestMoveFileBackupDir (8.56s)
=== RUN   TestDirMove
    run.go:185: Remote "B2 bucket rclone-test-wobosoz6dufo", Local "Local file system at /tmp/rclone1204639492", Modify Window "1ms"
2025/11/02 04:32:20 INFO  : A1/B2: Making directory
2025/11/02 04:32:20 INFO  : A1/B1/C3: Making directory
    fstest.go:250: Filtering empty directory "A1/B2"
    fstest.go:250: Filtering empty directory "A1/B1/C3"
2025/11/02 04:32:21 ERROR : A1/one: Failed to copy: expected a FileSseMode but found: '' (400 bad_request)
2025/11/02 04:32:21 ERROR : A1/one: Not deleting source as copy failed: expected a FileSseMode but found: '' (400 bad_request)
2025/11/02 04:32:21 ERROR : A1/B1/C2/five: Failed to copy: Post "https://api001.backblazeb2.com/b2api/v1/b2_copy_file": expected a FileSseMode but found: '' (400 bad_request)
2025/11/02 04:32:21 ERROR : A1/B1/C2/five: Not deleting source as copy failed: Post "https://api001.backblazeb2.com/b2api/v1/b2_copy_file": expected a FileSseMode but found: '' (400 bad_request)
2025/11/02 04:32:21 ERROR : A1/two: Failed to copy: Post "https://api001.backblazeb2.com/b2api/v1/b2_copy_file": expected a FileSseMode but found: '' (400 bad_request)
2025/11/02 04:32:21 ERROR : A1/two: Not deleting source as copy failed: Post "https://api001.backblazeb2.com/b2api/v1/b2_copy_file": expected a FileSseMode but found: '' (400 bad_request)
2025/11/02 04:32:21 ERROR : A1/B1/three: Failed to copy: Post "https://api001.backblazeb2.com/b2api/v1/b2_copy_file": expected a FileSseMode but found: '' (400 bad_request)
2025/11/02 04:32:21 ERROR : A1/B1/C1/four: Failed to copy: Post "https://api001.backblazeb2.com/b2api/v1/b2_copy_file": expected a FileSseMode but found: '' (400 bad_request)
2025/11/02 04:32:21 ERROR : A1/B1/three: Not deleting source as copy failed: Post "https://api001.backblazeb2.com/b2api/v1/b2_copy_file": expected a FileSseMode but found: '' (400 bad_request)
2025/11/02 04:32:21 ERROR : A1/B1/C1/four: Not deleting source as copy failed: Post "https://api001.backblazeb2.com/b2api/v1/b2_copy_file": expected a FileSseMode but found: '' (400 bad_request)
    operations_test.go:1388: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:1388
        	Error:      	Received unexpected error:
        	            	RenameDir renames: expected a FileSseMode but found: '' (400 bad_request)
        	Test:       	TestDirMove
--- FAIL: TestDirMove (4.92s)
=== RUN   TestTouchDir
    run.go:185: Remote "B2 bucket rclone-test-wobosoz6dufo", Local "Local file system at /tmp/rclone1204639492", Modify Window "1ms"
2025/11/02 04:32:24 DEBUG : B2 bucket rclone-test-wobosoz6dufo: Touching "sub dir/potato3"
2025/11/02 04:32:24 DEBUG : B2 bucket rclone-test-wobosoz6dufo: Touching "empty space"
2025/11/02 04:32:24 DEBUG : B2 bucket rclone-test-wobosoz6dufo: Touching "potato2"
2025/11/02 04:32:24 ERROR : sub dir/potato3: failed to touch: expected a FileSseMode but found: '' (400 bad_request)
2025/11/02 04:32:24 ERROR : empty space: failed to touch: expected a FileSseMode but found: '' (400 bad_request)
2025/11/02 04:32:24 ERROR : potato2: failed to touch: expected a FileSseMode but found: '' (400 bad_request)
    operations_test.go:1687: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:1687
        	Error:      	Should be true
        	Test:       	TestTouchDir
--- FAIL: TestTouchDir (3.06s)
FAIL
2025/11/02 04:32:25 DEBUG : B2 bucket rclone-test-wobosoz6dufo: Purge remote
2025/11/02 04:32:25 INFO  : B2 bucket rclone-test-wobosoz6dufo: cleaning bucket "rclone-test-wobosoz6dufo" of all files
2025/11/02 04:32:25 DEBUG : A1/B1/C1/four: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f4064ce6046d9814f_d20251102_m043221_c001_v7007000_t0000_u01762057941629")
2025/11/02 04:32:25 DEBUG : A1/B1/C1/four: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f1128da0032580c60_d20251102_m043219_c001_v0001101_t0036_u01762057939426")
2025/11/02 04:32:25 DEBUG : A1/B1/C2/five: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f4064ce6046d98150_d20251102_m043221_c001_v7007000_t0000_u01762057941813")
2025/11/02 04:32:25 DEBUG : A1/B1/C2/five: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f1128da0032580c64_d20251102_m043219_c001_v0001101_t0040_u01762057939734")
2025/11/02 04:32:25 DEBUG : A1/B1/three: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f4064ce6046d98152_d20251102_m043222_c001_v7007000_t0000_u01762057942003")
2025/11/02 04:32:25 DEBUG : A1/B1/three: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f1128da0032580c5c_d20251102_m043218_c001_v0001101_t0010_u01762057938906")
2025/11/02 04:32:25 DEBUG : A1/one: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f4064ce6046d98153_d20251102_m043222_c001_v7007000_t0000_u01762057942190")
2025/11/02 04:32:25 DEBUG : A1/one: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f1128da0032580c54_d20251102_m043218_c001_v0001101_t0046_u01762057938188")
2025/11/02 04:32:25 DEBUG : A1/two: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f4064ce6046d98155_d20251102_m043222_c001_v7007000_t0000_u01762057942374")
2025/11/02 04:32:26 DEBUG : A1/two: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f1128da0032580c58_d20251102_m043218_c001_v0001101_t0058_u01762057938550")
2025/11/02 04:32:26 DEBUG : CopyDest/one: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f405b1c37b594641e_d20251102_m043208_c001_v7007000_t0000_u01762057928717")
2025/11/02 04:32:26 DEBUG : CopyDest/one: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f1128da0032580c26_d20251102_m043205_c001_v0001101_t0058_u01762057925356")
2025/11/02 04:32:26 DEBUG : dst/file1: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f419682f804170a5a_d20251102_m043217_c001_v7007000_t0000_u01762057937451")
2025/11/02 04:32:26 DEBUG : dst/file1: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f1128da0032580c40_d20251102_m043209_c001_v0001101_t0050_u01762057929277")
2025/11/02 04:32:26 DEBUG : dst/file1: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f41400e9a7e258df8_d20251102_m043156_c001_v7007000_t0000_u01762057916959")
2025/11/02 04:32:26 DEBUG : dst/file1: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f1128da0032580bfc_d20251102_m043153_c001_v0001101_t0021_u01762057913279")
2025/11/02 04:32:26 DEBUG : dst/one: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f405b1c37b594641f_d20251102_m043208_c001_v7007000_t0000_u01762057928900")
2025/11/02 04:32:26 DEBUG : dst/one: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f1128da0032580c22_d20251102_m043204_c001_v0001101_t0004_u01762057924842")
2025/11/02 04:32:26 DEBUG : dst/one: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f10932ba8dc929968_d20251102_m043203_c001_v0001144_t0015_u01762057923666")
2025/11/02 04:32:26 DEBUG : dst/one: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f10932ba8dc929962_d20251102_m043201_c001_v0001144_t0022_u01762057921264")
2025/11/02 04:32:26 DEBUG : empty space: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f419682f804170a64_d20251102_m043225_c001_v7007000_t0000_u01762057945054")
2025/11/02 04:32:26 DEBUG : empty space: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f1128da0032580c6a_d20251102_m043223_c001_v0001101_t0052_u01762057943380")
2025/11/02 04:32:26 DEBUG : potato2: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f419682f804170a65_d20251102_m043225_c001_v7007000_t0000_u01762057945240")
2025/11/02 04:32:26 DEBUG : potato2: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f1128da0032580c68_d20251102_m043222_c001_v0001101_t0032_u01762057942741")
2025/11/02 04:32:26 DEBUG : sub dir/potato3: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f419682f804170a66_d20251102_m043225_c001_v7007000_t0000_u01762057945426")
2025/11/02 04:32:26 DEBUG : sub dir/potato3: Deleting (id "4_z8ff2fdb3d05d4b2b9fa80e1b_f1128da0032580c6c_d20251102_m043223_c001_v0001101_t0043_u01762057943716")
"./operations.test -test.v -test.timeout 1h0m0s -remote TestB2: -list-retries 5 -verbose -fast-list -test.run '^(TestCopyFileBackupDir|TestCopyFileCopyDest|TestDirMove|TestMoveFileBackupDir|TestMultithreadCopy|TestMultithreadCopyAbort|TestTouchDir)$'" - Finished ERROR in 37.758703549s (try 3/5): exit status 1: Failed [TestMultithreadCopy TestMultithreadCopyAbort TestCopyFileBackupDir TestCopyFileCopyDest TestMoveFileBackupDir TestDirMove TestTouchDir]