"./operations.test -test.v -test.timeout 1h0m0s -remote TestLinkbox: -verbose -test.run '^(TestCat|TestCheckSumDownload|TestCopyFile|TestCopyFileImmutable|TestCopyLongFileNameCollision|TestDirMove|TestMoveFile|TestRmdirsLeaveRoot)$|^TestCheckSizeOnly$/^3$'" - Starting (try 2/5)
2026/09/26 02:05:57 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-sutesef4xayu"
2026/09/26 02:05:57 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/09/26 02:05:57 DEBUG : Linkbox root 'rclone-test-sutesef4xayu': Using cached web token
2026/09/26 02:05:57 DEBUG : Creating backend with remote "/tmp/rclone914755733"
=== RUN   TestCheckSizeOnly
    run.go:198: Remote "Linkbox root 'rclone-test-sutesef4xayu'", Local "Local file system at /tmp/rclone914755733", Modify Window "876000h0m0s"
2026/09/26 02:06:03 DEBUG : empty space: Trying to read object after upload: try again in 100ms (1/10)
2026/09/26 02:06:04 DEBUG : empty space: Trying to read object after upload: try again in 200ms (2/10)
2026/09/26 02:06:04 DEBUG : empty space: Trying to read object after upload: try again in 400ms (3/10)
2026/09/26 02:06:05 DEBUG : empty space: Trying to read object after upload: try again in 800ms (4/10)
=== RUN   TestCheckSizeOnly/3
--- PASS: TestCheckSizeOnly (18.91s)
    --- PASS: TestCheckSizeOnly/3 (0.20s)
=== RUN   TestCheckSumDownload
    run.go:198: Remote "Linkbox root 'rclone-test-sutesef4xayu'", Local "Local file system at /tmp/rclone914755733", Modify Window "876000h0m0s"
2026/09/26 02:06:16 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-sutesef4xayu/data"
2026/09/26 02:06:16 DEBUG : Linkbox root 'rclone-test-sutesef4xayu/data': Using cached web token
2026/09/26 02:06:21 DEBUG : data/banana: Trying to read object after upload: try again in 100ms (1/10)
=== RUN   TestCheckSumDownload/subtest1
2026/09/26 02:06:27 DEBUG : test.sum: Update: removing old file
=== RUN   TestCheckSumDownload/subtest2
2026/09/26 02:06:31 DEBUG : test.sum: Update: removing old file
=== RUN   TestCheckSumDownload/subtest3
2026/09/26 02:06:36 DEBUG : test.sum: Update: removing old file
=== RUN   TestCheckSumDownload/subtest4
2026/09/26 02:06:40 DEBUG : test.sum: Update: removing old file
=== RUN   TestCheckSumDownload/subtest5
2026/09/26 02:06:45 DEBUG : test.sum: Update: removing old file
=== RUN   TestCheckSumDownload/subtest6
2026/09/26 02:06:50 DEBUG : data/banana: Update: removing old file
2026/09/26 02:06:53 DEBUG : data/potato: Update: removing old file
2026/09/26 02:06:56 DEBUG : test.sum: Update: removing old file
=== RUN   TestCheckSumDownload/subtest7
--- PASS: TestCheckSumDownload (50.35s)
    --- PASS: TestCheckSumDownload/subtest1 (0.87s)
    --- PASS: TestCheckSumDownload/subtest2 (0.47s)
    --- PASS: TestCheckSumDownload/subtest3 (0.70s)
    --- PASS: TestCheckSumDownload/subtest4 (0.69s)
    --- PASS: TestCheckSumDownload/subtest5 (0.69s)
    --- PASS: TestCheckSumDownload/subtest6 (1.25s)
    --- PASS: TestCheckSumDownload/subtest7 (0.67s)
=== RUN   TestCopyFile
    run.go:198: Remote "Linkbox root 'rclone-test-sutesef4xayu'", Local "Local file system at /tmp/rclone914755733", Modify Window "876000h0m0s"
2026/09/26 02:07:07 DEBUG : file1: Need to transfer - File not found at Destination
2026/09/26 02:07:10 DEBUG : sub/file2: size = 14 OK
2026/09/26 02:07:10 INFO  : file1: Copied (new) to: sub/file2
2026/09/26 02:07:11 DEBUG : sub/file2: size = 14 OK
2026/09/26 02:07:11 DEBUG : file1: Sizes identical
2026/09/26 02:07:11 DEBUG : file1: Unchanged skipping
2026/09/26 02:07:11 DEBUG : Linkbox root 'rclone-test-sutesef4xayu': don't need to copy/move sub/file2, it is already at target location
--- PASS: TestCopyFile (8.52s)
=== RUN   TestCopyFileImmutable
    run.go:198: Remote "Linkbox root 'rclone-test-sutesef4xayu'", Local "Local file system at /tmp/rclone914755733", Modify Window "876000h0m0s"
2026/09/26 02:07:15 DEBUG : existing: Need to transfer - File not found at Destination
2026/09/26 02:07:17 DEBUG : existing: size = 6 OK
2026/09/26 02:07:17 INFO  : existing: Copied (new)
2026/09/26 02:07:18 DEBUG : existing: size = 6 OK
2026/09/26 02:07:18 DEBUG : existing: Sizes identical
2026/09/26 02:07:18 DEBUG : existing: Unchanged skipping
2026/09/26 02:07:18 DEBUG : existing: size = 8 (Local file system at /tmp/rclone914755733)
2026/09/26 02:07:18 DEBUG : existing: size = 6 (Linkbox root 'rclone-test-sutesef4xayu')
2026/09/26 02:07:18 DEBUG : existing: Sizes differ
2026/09/26 02:07:18 ERROR : existing: Source and destination exist but do not match: immutable file modified
--- PASS: TestCopyFileImmutable (5.21s)
=== RUN   TestCopyLongFileNameCollision
    run.go:198: Remote "Linkbox root 'rclone-test-sutesef4xayu'", Local "Local file system at /tmp/rclone914755733", Modify Window "876000h0m0s"
    copy_test.go:500: Partial uploads not supported
--- SKIP: TestCopyLongFileNameCollision (0.40s)
=== RUN   TestCat
    run.go:198: Remote "Linkbox root 'rclone-test-sutesef4xayu'", Local "Local file system at /tmp/rclone914755733", Modify Window "876000h0m0s"
2026/09/26 02:07:25 DEBUG : file2: Trying to read object after upload: try again in 100ms (1/10)
--- PASS: TestCat (10.58s)
=== RUN   TestRmdirsLeaveRoot
    run.go:198: Remote "Linkbox root 'rclone-test-sutesef4xayu'", Local "Local file system at /tmp/rclone914755733", Modify Window "876000h0m0s"
2026/09/26 02:07:31 INFO  : A1: Making directory
2026/09/26 02:07:33 INFO  : A1/B1: Making directory
2026/09/26 02:07:34 INFO  : A1/B1/C1: Making directory
2026/09/26 02:07:37 DEBUG : removing 1 level 3 directories
2026/09/26 02:07:37 INFO  : A1/B1/C1: Removing directory
2026/09/26 02:07:39 DEBUG : removing 1 level 2 directories
2026/09/26 02:07:39 INFO  : A1/B1: Removing directory
--- PASS: TestRmdirsLeaveRoot (11.54s)
=== RUN   TestMoveFile
    run.go:198: Remote "Linkbox root 'rclone-test-sutesef4xayu'", Local "Local file system at /tmp/rclone914755733", Modify Window "876000h0m0s"
2026/09/26 02:07:43 DEBUG : file1: Need to transfer - File not found at Destination
2026/09/26 02:07:47 DEBUG : sub/file2: size = 14 OK
2026/09/26 02:07:47 INFO  : file1: Copied (new) to: sub/file2
2026/09/26 02:07:47 INFO  : file1: Deleted
2026/09/26 02:07:47 DEBUG : sub/file2: size = 14 OK
2026/09/26 02:07:47 DEBUG : file1: Sizes identical
2026/09/26 02:07:47 DEBUG : file1: Unchanged skipping
2026/09/26 02:07:47 INFO  : file1: Deleted
2026/09/26 02:07:48 DEBUG : Linkbox root 'rclone-test-sutesef4xayu': don't need to copy/move sub/file2, it is already at target location
--- PASS: TestMoveFile (8.64s)
=== RUN   TestDirMove
    run.go:198: Remote "Linkbox root 'rclone-test-sutesef4xayu'", Local "Local file system at /tmp/rclone914755733", Modify Window "876000h0m0s"
2026/09/26 02:08:01 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/26 02:08:01 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/09/26 02:08:01 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/09/26 02:08:01 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/09/26 02:08:01 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/09/26 02:08:01 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/09/26 02:08:02 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/09/26 02:08:02 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/09/26 02:08:04 DEBUG : pacer: Reducing sleep to 1.5s
2026/09/26 02:08:06 DEBUG : pacer: Reducing sleep to 1.125s
2026/09/26 02:08:08 DEBUG : pacer: Reducing sleep to 843.75ms
2026/09/26 02:08:09 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/09/26 02:08:10 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/09/26 02:08:11 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/09/26 02:08:12 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/09/26 02:08:12 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/09/26 02:08:13 DEBUG : pacer: Reducing sleep to 200ms
2026/09/26 02:08:15 INFO  : A1/B2: Making directory
2026/09/26 02:08:17 INFO  : A1/B1/C3: Making directory
2026/09/26 02:08:36 DEBUG : A2/one: size = 3 OK
2026/09/26 02:08:36 INFO  : A1/one: Copied (new) to: A2/one
2026/09/26 02:08:36 DEBUG : A2/B1/C2/five: size = 4 OK
2026/09/26 02:08:36 INFO  : A1/B1/C2/five: Copied (new) to: A2/B1/C2/five
2026/09/26 02:08:36 DEBUG : A2/two: size = 3 OK
2026/09/26 02:08:36 INFO  : A1/two: Copied (new) to: A2/two
2026/09/26 02:08:37 DEBUG : A2/B1/three: size = 5 OK
2026/09/26 02:08:37 INFO  : A1/B1/three: Copied (new) to: A2/B1/three
2026/09/26 02:08:37 DEBUG : A2/B1/C1/four: size = 4 OK
2026/09/26 02:08:37 INFO  : A1/B1/C1/four: Copied (new) to: A2/B1/C1/four
2026/09/26 02:08:37 INFO  : A1/one: Deleted
2026/09/26 02:08:38 INFO  : A1/B1/C2/five: Deleted
2026/09/26 02:08:38 INFO  : A1/two: Deleted
2026/09/26 02:08:38 INFO  : A1/B1/three: Deleted
2026/09/26 02:08:39 INFO  : A1/B1/C1/four: Deleted
2026/09/26 02:09:03 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/26 02:09:03 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/09/26 02:09:03 DEBUG : pacer: Reducing sleep to 300ms
2026/09/26 02:09:03 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/26 02:09:03 DEBUG : pacer: Rate limited, increasing sleep to 600ms
2026/09/26 02:09:03 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/26 02:09:03 DEBUG : pacer: Rate limited, increasing sleep to 1.2s
2026/09/26 02:09:04 DEBUG : pacer: Reducing sleep to 900ms
2026/09/26 02:09:06 DEBUG : pacer: Reducing sleep to 675ms
2026/09/26 02:09:07 DEBUG : pacer: Reducing sleep to 506.25ms
2026/09/26 02:09:07 DEBUG : pacer: Reducing sleep to 379.6875ms
2026/09/26 02:09:08 DEBUG : pacer: Reducing sleep to 284.765625ms
2026/09/26 02:09:09 DEBUG : pacer: Reducing sleep to 213.574218ms
2026/09/26 02:09:09 DEBUG : A3/one: size = 3 OK
2026/09/26 02:09:09 INFO  : A2/one: Copied (new) to: A3/one
2026/09/26 02:09:09 DEBUG : pacer: Reducing sleep to 200ms
2026/09/26 02:09:10 DEBUG : A3/B1/C1/four: size = 4 OK
2026/09/26 02:09:10 INFO  : A2/B1/C1/four: Copied (new) to: A3/B1/C1/four
2026/09/26 02:09:10 DEBUG : A3/two: size = 3 OK
2026/09/26 02:09:10 INFO  : A2/two: Copied (new) to: A3/two
2026/09/26 02:09:10 DEBUG : A3/B1/three: size = 5 OK
2026/09/26 02:09:10 INFO  : A2/B1/three: Copied (new) to: A3/B1/three
2026/09/26 02:09:11 INFO  : A2/one: Deleted
2026/09/26 02:09:11 DEBUG : A3/B1/C2/five: size = 4 OK
2026/09/26 02:09:11 INFO  : A2/B1/C2/five: Copied (new) to: A3/B1/C2/five
2026/09/26 02:09:11 INFO  : A2/B1/C1/four: Deleted
2026/09/26 02:09:12 INFO  : A2/two: Deleted
2026/09/26 02:09:12 INFO  : A2/B1/three: Deleted
2026/09/26 02:09:12 INFO  : A2/B1/C2/five: Deleted
2026/09/26 02:09:23 INFO  : Linkbox root 'rclone-test-sutesef4xayu': Can't DirMove - falling back to file moves: can't move directory - incompatible remotes
2026/09/26 02:09:39 DEBUG : A4/B1/C2/five: size = 4 OK
2026/09/26 02:09:39 INFO  : A3/B1/C2/five: Copied (new) to: A4/B1/C2/five
2026/09/26 02:09:39 DEBUG : A4/one: size = 3 OK
2026/09/26 02:09:39 INFO  : A3/one: Copied (new) to: A4/one
2026/09/26 02:09:39 DEBUG : A4/two: size = 3 OK
2026/09/26 02:09:39 INFO  : A3/two: Copied (new) to: A4/two
2026/09/26 02:09:40 DEBUG : A4/B1/C1/four: size = 4 OK
2026/09/26 02:09:40 INFO  : A3/B1/C1/four: Copied (new) to: A4/B1/C1/four
2026/09/26 02:09:40 DEBUG : A4/B1/three: size = 5 OK
2026/09/26 02:09:40 INFO  : A3/B1/three: Copied (new) to: A4/B1/three
2026/09/26 02:09:40 INFO  : A3/B1/C2/five: Deleted
2026/09/26 02:09:40 INFO  : A3/one: Deleted
2026/09/26 02:09:41 INFO  : A3/two: Deleted
2026/09/26 02:09:41 INFO  : A3/B1/C1/four: Deleted
2026/09/26 02:09:42 INFO  : A3/B1/three: Deleted
2026/09/26 02:10:03 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/26 02:10:03 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/09/26 02:10:03 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/09/26 02:10:03 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/09/26 02:10:03 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/09/26 02:10:03 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/09/26 02:10:04 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/09/26 02:10:04 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/09/26 02:10:07 DEBUG : pacer: Reducing sleep to 1.5s
2026/09/26 02:10:08 DEBUG : pacer: Reducing sleep to 1.125s
2026/09/26 02:10:10 DEBUG : pacer: Reducing sleep to 843.75ms
2026/09/26 02:10:11 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/09/26 02:10:13 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/09/26 02:10:13 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/09/26 02:10:14 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/09/26 02:10:15 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/09/26 02:10:16 DEBUG : pacer: Reducing sleep to 200ms
--- PASS: TestDirMove (144.47s)
PASS
2026/09/26 02:10:16 DEBUG : Linkbox root 'rclone-test-sutesef4xayu': Purge remote
"./operations.test -test.v -test.timeout 1h0m0s -remote TestLinkbox: -verbose -test.run '^(TestCat|TestCheckSumDownload|TestCopyFile|TestCopyFileImmutable|TestCopyLongFileNameCollision|TestDirMove|TestMoveFile|TestRmdirsLeaveRoot)$|^TestCheckSizeOnly$/^3$'" - Finished OK in 4m20.925954453s (try 2/5)