"./operations.test -test.v -test.timeout 1h0m0s -remote TestLinkbox: -verbose -test.run '^(TestCopyFileCompareDest|TestDirMove)$|^TestRcat$/^withChecksum=false,ignoreChecksum=true$'" - Starting (try 2/5)
2026/09/24 04:25:56 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-laperag9lufe"
2026/09/24 04:25:56 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/09/24 04:25:56 DEBUG : Linkbox root 'rclone-test-laperag9lufe': Using cached web token
2026/09/24 04:25:57 DEBUG : Creating backend with remote "/tmp/rclone638023690"
=== RUN   TestCopyFileCompareDest
    run.go:198: Remote "Linkbox root 'rclone-test-laperag9lufe'", Local "Local file system at /tmp/rclone638023690", Modify Window "876000h0m0s"
2026/09/24 04:25:57 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-laperag9lufe/dst"
2026/09/24 04:25:57 DEBUG : Linkbox root 'rclone-test-laperag9lufe/dst': Using cached web token
2026/09/24 04:25:59 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-laperag9lufe/CompareDest"
2026/09/24 04:25:59 DEBUG : Linkbox root 'rclone-test-laperag9lufe/CompareDest': Using cached web token
2026/09/24 04:26:00 DEBUG : one: Need to transfer - File not found at Destination
2026/09/24 04:26:05 DEBUG : one: size = 3 OK
2026/09/24 04:26:05 INFO  : one: Copied (new)
2026/09/24 04:26:07 DEBUG : one: size = 5 (Local file system at /tmp/rclone638023690)
2026/09/24 04:26:07 DEBUG : one: size = 3 (Linkbox root 'rclone-test-laperag9lufe/dst')
2026/09/24 04:26:07 DEBUG : one: Sizes differ
2026/09/24 04:26:07 DEBUG : one: Update: removing old file
2026/09/24 04:26:11 DEBUG : one: size = 5 OK
2026/09/24 04:26:11 INFO  : one: Copied (replaced existing)
2026/09/24 04:26:11 DEBUG : dst/one: Update: removing old file
2026/09/24 04:26:15 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:26:15 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/09/24 04:26:15 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:26:15 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/09/24 04:26:16 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:26:16 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/09/24 04:26:16 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:26:16 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/09/24 04:26:18 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:26:20 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:26:22 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:26:24 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:26:26 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:26:28 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
    run.go:299: Retry Put of "dst/one" to Linkbox root 'rclone-test-laperag9lufe': 1/10 (Update failed to read object: getting files failed: invalid character '<' looking for beginning of value)
2026/09/24 04:26:30 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:26:32 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:26:34 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:26:36 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:26:38 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:26:40 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:26:42 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:26:44 DEBUG : pacer: Reducing sleep to 1.5s
2026/09/24 04:26:44 DEBUG : dst/one: Update: removing old file
2026/09/24 04:26:47 DEBUG : pacer: Reducing sleep to 1.125s
2026/09/24 04:26:48 DEBUG : pacer: Reducing sleep to 843.75ms
2026/09/24 04:26:50 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/09/24 04:26:50 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/09/24 04:26:51 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/09/24 04:26:52 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/09/24 04:26:53 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/09/24 04:26:53 DEBUG : pacer: Reducing sleep to 200ms
2026/09/24 04:26:56 DEBUG : one: size = 5 (Local file system at /tmp/rclone638023690)
2026/09/24 04:26:56 DEBUG : one: size = 3 (Linkbox root 'rclone-test-laperag9lufe/dst')
2026/09/24 04:26:56 DEBUG : one: Sizes differ
2026/09/24 04:26:56 DEBUG : one: size = 5 OK
2026/09/24 04:26:56 DEBUG : one: Sizes identical
2026/09/24 04:26:56 DEBUG : one: Destination found in --compare-dest, skipping
2026/09/24 04:27:00 DEBUG : two: Need to transfer - File not found at Destination
2026/09/24 04:27:00 DEBUG : two: size = 3 OK
2026/09/24 04:27:00 DEBUG : two: Sizes identical
2026/09/24 04:27:00 DEBUG : two: Destination found in --compare-dest, skipping
2026/09/24 04:27:01 DEBUG : two: Need to transfer - File not found at Destination
2026/09/24 04:27:01 DEBUG : two: size = 3 OK
2026/09/24 04:27:01 DEBUG : two: Sizes identical
2026/09/24 04:27:01 DEBUG : two: Destination found in --compare-dest, skipping
2026/09/24 04:27:03 DEBUG : two: Need to transfer - File not found at Destination
2026/09/24 04:27:03 DEBUG : two: size = 5 (Local file system at /tmp/rclone638023690)
2026/09/24 04:27:03 DEBUG : two: size = 3 (Linkbox root 'rclone-test-laperag9lufe/CompareDest')
2026/09/24 04:27:03 DEBUG : two: Sizes differ
2026/09/24 04:27:05 DEBUG : two: Trying to read object after upload: try again in 100ms (1/10)
2026/09/24 04:27:05 DEBUG : two: size = 5 OK
2026/09/24 04:27:05 INFO  : two: Copied (new)
--- PASS: TestCopyFileCompareDest (77.56s)
=== RUN   TestDirMove
    run.go:198: Remote "Linkbox root 'rclone-test-laperag9lufe'", Local "Local file system at /tmp/rclone638023690", Modify Window "876000h0m0s"
2026/09/24 04:27:16 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:27:16 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/09/24 04:27:17 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:27:17 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/09/24 04:27:17 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:27:17 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/09/24 04:27:18 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:27:18 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/09/24 04:27:19 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:27:21 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:27:23 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:27:26 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:27:27 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:27:29 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:27:32 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:27:34 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:27:36 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:27:38 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:27:40 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:27:42 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:27:44 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:27:46 DEBUG : pacer: Reducing sleep to 1.5s
2026/09/24 04:27:49 DEBUG : pacer: Reducing sleep to 1.125s
2026/09/24 04:27:49 DEBUG : pacer: Reducing sleep to 843.75ms
2026/09/24 04:27:50 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/09/24 04:27:51 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/09/24 04:27:53 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/09/24 04:27:53 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/09/24 04:27:54 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/09/24 04:27:55 DEBUG : pacer: Reducing sleep to 200ms
2026/09/24 04:27:57 DEBUG : A1/B1/three: Trying to read object after upload: try again in 100ms (1/10)
2026/09/24 04:27:57 DEBUG : A1/B1/three: Trying to read object after upload: try again in 200ms (2/10)
2026/09/24 04:28:01 DEBUG : A1/B1/C1/four: Trying to read object after upload: try again in 100ms (1/10)
2026/09/24 04:28:02 DEBUG : A1/B1/C1/four: Trying to read object after upload: try again in 200ms (2/10)
2026/09/24 04:28:02 DEBUG : A1/B1/C1/four: Trying to read object after upload: try again in 400ms (3/10)
2026/09/24 04:28:06 DEBUG : A1/B1/C2/five: Trying to read object after upload: try again in 100ms (1/10)
2026/09/24 04:28:07 INFO  : A1/B2: Making directory
2026/09/24 04:28:08 INFO  : A1/B1/C3: Making directory
2026/09/24 04:28:23 NOTICE: Time may be set wrong - time from "aht.nuplink3.net" is 362h15m23.299634162s different from this computer
2026/09/24 04:28:25 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:28:25 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/09/24 04:28:25 DEBUG : pacer: Reducing sleep to 300ms
2026/09/24 04:28:26 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:28:26 DEBUG : pacer: Rate limited, increasing sleep to 600ms
2026/09/24 04:28:26 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:28:26 DEBUG : pacer: Rate limited, increasing sleep to 1.2s
2026/09/24 04:28:26 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:28:26 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/09/24 04:28:28 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:28:30 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:28:32 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:28:34 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:28:36 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:28:38 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:28:40 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:28:42 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:28:44 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:28:47 DEBUG : pacer: Reducing sleep to 1.5s
2026/09/24 04:28:48 DEBUG : pacer: Reducing sleep to 1.125s
2026/09/24 04:28:51 DEBUG : pacer: Reducing sleep to 843.75ms
2026/09/24 04:28:52 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/09/24 04:28:52 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/09/24 04:28:52 DEBUG : A2/one: size = 3 OK
2026/09/24 04:28:52 INFO  : A1/one: Copied (new) to: A2/one
2026/09/24 04:28:53 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/09/24 04:28:53 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/09/24 04:28:53 DEBUG : A2/B1/three: size = 5 OK
2026/09/24 04:28:53 INFO  : A1/B1/three: Copied (new) to: A2/B1/three
2026/09/24 04:28:54 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/09/24 04:28:54 DEBUG : A2/B1/C2/five: size = 4 OK
2026/09/24 04:28:54 INFO  : A1/B1/C2/five: Copied (new) to: A2/B1/C2/five
2026/09/24 04:28:54 DEBUG : pacer: Reducing sleep to 200ms
2026/09/24 04:28:54 DEBUG : A2/B1/C1/four: size = 4 OK
2026/09/24 04:28:54 INFO  : A1/B1/C1/four: Copied (new) to: A2/B1/C1/four
2026/09/24 04:28:55 DEBUG : A2/two: size = 3 OK
2026/09/24 04:28:55 INFO  : A1/two: Copied (new) to: A2/two
2026/09/24 04:28:55 INFO  : A1/one: Deleted
2026/09/24 04:28:56 INFO  : A1/B1/three: Deleted
2026/09/24 04:28:56 INFO  : A1/B1/C2/five: Deleted
2026/09/24 04:28:56 INFO  : A1/B1/C1/four: Deleted
2026/09/24 04:28:56 INFO  : A1/two: Deleted
2026/09/24 04:29:23 DEBUG : A3/one: size = 3 OK
2026/09/24 04:29:23 INFO  : A2/one: Copied (new) to: A3/one
2026/09/24 04:29:23 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:29:23 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/09/24 04:29:23 DEBUG : pacer: Reducing sleep to 300ms
2026/09/24 04:29:24 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:29:24 DEBUG : pacer: Rate limited, increasing sleep to 600ms
2026/09/24 04:29:24 DEBUG : pacer: Reducing sleep to 450ms
2026/09/24 04:29:24 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:29:24 DEBUG : pacer: Rate limited, increasing sleep to 900ms
2026/09/24 04:29:24 DEBUG : pacer: Reducing sleep to 675ms
2026/09/24 04:29:24 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:29:24 DEBUG : pacer: Rate limited, increasing sleep to 1.35s
2026/09/24 04:29:25 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:29:25 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/09/24 04:29:26 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:29:28 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:29:30 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:29:32 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:29:34 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:29:36 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:29:38 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:29:40 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:29:42 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:29:44 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/09/24 04:29:47 DEBUG : pacer: Reducing sleep to 1.5s
2026/09/24 04:29:47 DEBUG : A3/B1/three: size = 5 OK
2026/09/24 04:29:47 INFO  : A2/B1/three: Copied (new) to: A3/B1/three
2026/09/24 04:29:49 DEBUG : pacer: Reducing sleep to 1.125s
2026/09/24 04:29:49 DEBUG : A3/two: size = 3 OK
2026/09/24 04:29:49 INFO  : A2/two: Copied (new) to: A3/two
2026/09/24 04:29:50 DEBUG : pacer: Reducing sleep to 843.75ms
2026/09/24 04:29:50 DEBUG : A3/B1/C2/five: size = 4 OK
2026/09/24 04:29:50 INFO  : A2/B1/C2/five: Copied (new) to: A3/B1/C2/five
2026/09/24 04:29:51 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/09/24 04:29:51 DEBUG : A3/B1/C1/four: size = 4 OK
2026/09/24 04:29:51 INFO  : A2/B1/C1/four: Copied (new) to: A3/B1/C1/four
2026/09/24 04:29:53 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/09/24 04:29:53 INFO  : A2/one: Deleted
2026/09/24 04:29:54 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/09/24 04:29:54 INFO  : A2/B1/three: Deleted
2026/09/24 04:29:55 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/09/24 04:29:55 INFO  : A2/two: Deleted
2026/09/24 04:29:55 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/09/24 04:29:55 INFO  : A2/B1/C2/five: Deleted
2026/09/24 04:29:55 DEBUG : pacer: Reducing sleep to 200ms
2026/09/24 04:29:55 INFO  : A2/B1/C1/four: Deleted
    operations_test.go:1618: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations_test.go:1618
        	Error:      	Received unexpected error:
        	            	RenameDir rmdir: directory not empty
        	Test:       	TestDirMove
--- FAIL: TestDirMove (187.74s)
=== RUN   TestRcat
=== RUN   TestRcat/withChecksum=false,ignoreChecksum=true
    run.go:198: Remote "Linkbox root 'rclone-test-laperag9lufe'", Local "Local file system at /tmp/rclone638023690", Modify Window "876000h0m0s"
2026/09/24 04:30:23 DEBUG : Linkbox root 'rclone-test-laperag9lufe': File to upload is small (34 bytes), uploading instead of streaming
2026/09/24 04:30:25 DEBUG : ignore_checksum_small_file_from_pipe: Trying to read object after upload: try again in 100ms (1/10)
2026/09/24 04:30:25 DEBUG : ignore_checksum_small_file_from_pipe: size = 34 OK
2026/09/24 04:30:25 DEBUG : ignore_checksum_small_file_from_pipe: Sizes identical
2026/09/24 04:30:25 DEBUG : Linkbox root 'rclone-test-laperag9lufe': Target remote doesn't support streaming uploads, creating temporary local FS to spool file
2026/09/24 04:30:27 DEBUG : ignore_checksum_big_file_from_pipe: size = 102401 OK
2026/09/24 04:30:27 DEBUG : ignore_checksum_big_file_from_pipe: Sizes identical
--- PASS: TestRcat (7.90s)
    --- PASS: TestRcat/withChecksum=false,ignoreChecksum=true (7.90s)
FAIL
2026/09/24 04:30:31 DEBUG : Linkbox root 'rclone-test-laperag9lufe': Purge remote
"./operations.test -test.v -test.timeout 1h0m0s -remote TestLinkbox: -verbose -test.run '^(TestCopyFileCompareDest|TestDirMove)$|^TestRcat$/^withChecksum=false,ignoreChecksum=true$'" - Finished ERROR in 4m35.559266799s (try 2/5): exit status 1: Failed [TestDirMove]