"./sync.test -test.v -test.timeout 1h0m0s -remote TestLinkbox: -verbose -test.run '^(TestMoveOverSelf|TestServerSideMoveOverSelf|TestServerSideMoveWithFilter|TestSyncCompareDest)$'" - Starting (try 4/5)
2026/07/24 04:22:03 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-lucatas7duke"
2026/07/24 04:22:03 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/07/24 04:22:03 DEBUG : Linkbox root 'rclone-test-lucatas7duke': Using cached web token
2026/07/24 04:22:04 DEBUG : Creating backend with remote "/tmp/rclone856713790"
=== RUN   TestMoveOverSelf
    run.go:198: Remote "Linkbox root 'rclone-test-lucatas7duke'", Local "Local file system at /tmp/rclone856713790", Modify Window "876000h0m0s"
2026/07/24 04:22:10 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/24 04:22:10 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 200ms (2/10)
2026/07/24 04:22:10 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 400ms (3/10)
2026/07/24 04:22:12 DEBUG : sub dir/hello world: size = 17 (Local file system at /tmp/rclone856713790)
2026/07/24 04:22:12 DEBUG : sub dir/hello world: size = 11 (Linkbox root 'rclone-test-lucatas7duke')
2026/07/24 04:22:12 DEBUG : sub dir/hello world: Sizes differ
2026/07/24 04:22:12 DEBUG : sub dir/hello world: Update: removing old file
2026/07/24 04:22:12 DEBUG : Linkbox root 'rclone-test-lucatas7duke': Waiting for checks to finish
2026/07/24 04:22:12 DEBUG : Linkbox root 'rclone-test-lucatas7duke': Waiting for transfers to finish
2026/07/24 04:22:15 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/24 04:22:15 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 200ms (2/10)
2026/07/24 04:22:16 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 400ms (3/10)
2026/07/24 04:22:16 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 800ms (4/10)
2026/07/24 04:22:17 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 1.6s (5/10)
2026/07/24 04:22:19 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 3.2s (6/10)
2026/07/24 04:22:22 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 6.4s (7/10)
2026/07/24 04:22:29 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 12.8s (8/10)
2026/07/24 04:22:42 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 25.6s (9/10)
2026/07/24 04:23:08 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 51.2s (10/10)
2026/07/24 04:23:59 ERROR : sub dir/hello world: Failed to copy: object not found
2026/07/24 04:23:59 ERROR : sub dir/hello world: Not deleting source as copy failed: object not found
    sync_test.go:685: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:685
        	Error:      	Received unexpected error:
        	            	object not found
        	Test:       	TestMoveOverSelf
--- FAIL: TestMoveOverSelf (118.56s)
=== RUN   TestServerSideMoveOverSelf
    run.go:198: Remote "Linkbox root 'rclone-test-lucatas7duke'", Local "Local file system at /tmp/rclone856713790", Modify Window "876000h0m0s"
2026/07/24 04:24:07 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-womafon0mona"
2026/07/24 04:24:07 DEBUG : Linkbox root 'rclone-test-womafon0mona': Using cached web token
    sync_test.go:701: Server side copy (if possible) Linkbox root 'rclone-test-lucatas7duke' -> Linkbox root 'rclone-test-womafon0mona'
2026/07/24 04:24:08 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/07/24 04:24:08 DEBUG : Linkbox root 'rclone-test-womafon0mona': Waiting for checks to finish
2026/07/24 04:24:08 DEBUG : Linkbox root 'rclone-test-womafon0mona': Waiting for transfers to finish
2026/07/24 04:24:09 NOTICE: Time may be set wrong - time from "aht.nuplink3.net" is 1009h21m32.03817951s different from this computer
2026/07/24 04:24:14 DEBUG : sub dir/hello world: size = 11 OK
2026/07/24 04:24:14 INFO  : sub dir/hello world: Copied (new)
2026/07/24 04:24:14 DEBUG : sub dir/hello world: Update: removing old file
2026/07/24 04:24:18 DEBUG : Linkbox root 'rclone-test-womafon0mona': Waiting for checks to finish
2026/07/24 04:24:18 DEBUG : sub dir/hello world: size = 17 (Linkbox root 'rclone-test-lucatas7duke')
2026/07/24 04:24:18 DEBUG : sub dir/hello world: size = 11 (Linkbox root 'rclone-test-womafon0mona')
2026/07/24 04:24:18 DEBUG : sub dir/hello world: Sizes differ
2026/07/24 04:24:18 DEBUG : Linkbox root 'rclone-test-womafon0mona': Waiting for transfers to finish
2026/07/24 04:24:18 DEBUG : sub dir/hello world: Update: removing old file
2026/07/24 04:24:22 DEBUG : sub dir/hello world: size = 17 OK
2026/07/24 04:24:22 INFO  : sub dir/hello world: Copied (replaced existing)
2026/07/24 04:24:23 INFO  : sub dir/hello world: Deleted
2026/07/24 04:24:26 DEBUG : testing file moves
2026/07/24 04:24:27 DEBUG : sub dir/hello world: size = 24 (Linkbox root 'rclone-test-lucatas7duke')
2026/07/24 04:24:27 DEBUG : sub dir/hello world: size = 17 (Linkbox root 'rclone-test-womafon0mona')
2026/07/24 04:24:27 DEBUG : sub dir/hello world: Sizes differ
2026/07/24 04:24:27 DEBUG : Linkbox root 'rclone-test-womafon0mona': Waiting for checks to finish
2026/07/24 04:24:27 DEBUG : Linkbox root 'rclone-test-womafon0mona': Waiting for transfers to finish
2026/07/24 04:24:27 DEBUG : sub dir/hello world: Update: removing old file
2026/07/24 04:24:30 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/24 04:24:30 DEBUG : sub dir/hello world: size = 24 OK
2026/07/24 04:24:30 INFO  : sub dir/hello world: Copied (replaced existing)
2026/07/24 04:24:32 INFO  : sub dir/hello world: Deleted
2026/07/24 04:24:32 DEBUG : Linkbox root 'rclone-test-womafon0mona': Purge remote
--- PASS: TestServerSideMoveOverSelf (33.54s)
=== RUN   TestServerSideMoveWithFilter
    run.go:198: Remote "Linkbox root 'rclone-test-lucatas7duke'", Local "Local file system at /tmp/rclone856713790", Modify Window "876000h0m0s"
2026/07/24 04:24:36 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-natuzuk5mibo"
2026/07/24 04:24:36 DEBUG : Linkbox root 'rclone-test-natuzuk5mibo': Using cached web token
2026/07/24 04:24:39 DEBUG : potato2: Trying to read object after upload: try again in 100ms (1/10)
2026/07/24 04:24:39 DEBUG : potato2: Trying to read object after upload: try again in 200ms (2/10)
2026/07/24 04:24:39 DEBUG : potato2: Trying to read object after upload: try again in 400ms (3/10)
2026/07/24 04:24:44 DEBUG : potato3: Trying to read object after upload: try again in 100ms (1/10)
    sync_test.go:1736: Server side move (if possible) Linkbox root 'rclone-test-lucatas7duke' -> Linkbox root 'rclone-test-natuzuk5mibo'
2026/07/24 04:24:48 DEBUG : empty space: Trying to read object after upload: try again in 100ms (1/10)
2026/07/24 04:24:49 DEBUG : empty space: Trying to read object after upload: try again in 200ms (2/10)
2026/07/24 04:24:51 DEBUG : potato3: Trying to read object after upload: try again in 100ms (1/10)
2026/07/24 04:24:52 DEBUG : empty space: Excluded (Size Filter)
2026/07/24 04:24:52 DEBUG : empty space: Excluded
2026/07/24 04:24:52 DEBUG : empty space: Excluded (Size Filter)
2026/07/24 04:24:52 DEBUG : empty space: Excluded
2026/07/24 04:24:52 DEBUG : potato2: Need to transfer - File not found at Destination
2026/07/24 04:24:52 DEBUG : potato3: size = 68 (Linkbox root 'rclone-test-lucatas7duke')
2026/07/24 04:24:52 DEBUG : potato3: size = 60 (Linkbox root 'rclone-test-natuzuk5mibo')
2026/07/24 04:24:52 DEBUG : potato3: Sizes differ
2026/07/24 04:24:52 DEBUG : Linkbox root 'rclone-test-natuzuk5mibo': Waiting for checks to finish
2026/07/24 04:24:52 DEBUG : Linkbox root 'rclone-test-natuzuk5mibo': Waiting for transfers to finish
2026/07/24 04:24:52 DEBUG : potato3: Update: removing old file
2026/07/24 04:24:54 DEBUG : potato2: Trying to read object after upload: try again in 100ms (1/10)
2026/07/24 04:24:55 DEBUG : potato2: Trying to read object after upload: try again in 200ms (2/10)
2026/07/24 04:24:55 DEBUG : potato2: Trying to read object after upload: try again in 400ms (3/10)
2026/07/24 04:24:55 DEBUG : potato3: size = 68 OK
2026/07/24 04:24:55 INFO  : potato3: Copied (replaced existing)
2026/07/24 04:24:55 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/24 04:24:55 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/24 04:24:56 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/24 04:24:56 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/24 04:24:56 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/24 04:24:56 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/24 04:24:56 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/24 04:24:56 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/24 04:24:56 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/24 04:24:56 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/24 04:24:56 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/24 04:24:56 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/24 04:24:57 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/24 04:24:57 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/24 04:24:57 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/24 04:24:57 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/24 04:24:58 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/24 04:24:59 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/24 04:25:01 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/24 04:25:01 DEBUG : potato2: size = 60 OK
2026/07/24 04:25:01 INFO  : potato2: Copied (new)
2026/07/24 04:25:02 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/24 04:25:02 INFO  : potato3: Deleted
2026/07/24 04:25:04 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/24 04:25:04 INFO  : potato2: Deleted
2026/07/24 04:25:04 DEBUG : pacer: Reducing sleep to 843.75ms
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
2026/07/24 04:25:06 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/24 04:25:06 DEBUG : pacer: Reducing sleep to 474.609375ms
    fstest.go:292: Sleeping for 6s just to make sure
2026/07/24 04:25:12 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/24 04:25:12 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-yozulud2zoyi"
2026/07/24 04:25:12 DEBUG : Linkbox root 'rclone-test-yozulud2zoyi': Using cached web token
2026/07/24 04:25:14 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/24 04:25:14 DEBUG : empty space: Excluded (Size Filter)
2026/07/24 04:25:14 DEBUG : empty space: Excluded
2026/07/24 04:25:14 DEBUG : potato2: Need to transfer - File not found at Destination
2026/07/24 04:25:14 DEBUG : potato3: Need to transfer - File not found at Destination
2026/07/24 04:25:14 DEBUG : Linkbox root 'rclone-test-yozulud2zoyi': Waiting for checks to finish
2026/07/24 04:25:14 DEBUG : Linkbox root 'rclone-test-yozulud2zoyi': Waiting for transfers to finish
2026/07/24 04:25:15 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/24 04:25:16 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/24 04:25:19 DEBUG : potato2: Trying to read object after upload: try again in 100ms (1/10)
2026/07/24 04:25:19 DEBUG : potato3: size = 68 OK
2026/07/24 04:25:19 INFO  : potato3: Copied (new)
2026/07/24 04:25:19 DEBUG : potato2: size = 60 OK
2026/07/24 04:25:19 INFO  : potato2: Copied (new)
2026/07/24 04:25:20 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/24 04:25:20 INFO  : potato3: Deleted
2026/07/24 04:25:21 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/24 04:25:21 INFO  : potato2: Deleted
2026/07/24 04:25:21 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/24 04:25:21 DEBUG : Linkbox root 'rclone-test-yozulud2zoyi': Purge remote
2026/07/24 04:25:23 DEBUG : Linkbox root 'rclone-test-natuzuk5mibo': Purge remote
2026/07/24 04:25:24 DEBUG : pacer: Reducing sleep to 200ms
2026/07/24 04:25:24 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/24 04:25:26 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/24 04:25:26 DEBUG : pacer: Reducing sleep to 200.225829ms
--- PASS: TestServerSideMoveWithFilter (49.81s)
=== RUN   TestSyncCompareDest
    run.go:198: Remote "Linkbox root 'rclone-test-lucatas7duke'", Local "Local file system at /tmp/rclone856713790", Modify Window "876000h0m0s"
2026/07/24 04:25:26 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-lucatas7duke/dst"
2026/07/24 04:25:26 DEBUG : Linkbox root 'rclone-test-lucatas7duke/dst': Using cached web token
2026/07/24 04:25:27 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-lucatas7duke/CompareDest"
2026/07/24 04:25:27 DEBUG : Linkbox root 'rclone-test-lucatas7duke/CompareDest': Using cached web token
2026/07/24 04:25:29 DEBUG : one: Need to transfer - File not found at Destination
2026/07/24 04:25:29 DEBUG : Linkbox root 'rclone-test-lucatas7duke/dst': Waiting for checks to finish
2026/07/24 04:25:29 DEBUG : Linkbox root 'rclone-test-lucatas7duke/dst': Waiting for transfers to finish
2026/07/24 04:25:32 DEBUG : one: Trying to read object after upload: try again in 100ms (1/10)
2026/07/24 04:25:32 DEBUG : one: size = 3 OK
2026/07/24 04:25:32 INFO  : one: Copied (new)
2026/07/24 04:25:32 DEBUG : Waiting for deletions to finish
2026/07/24 04:25:33 DEBUG : pacer: Reducing sleep to 200ms
2026/07/24 04:25:33 DEBUG : one: size = 5 (Local file system at /tmp/rclone856713790)
2026/07/24 04:25:33 DEBUG : one: size = 3 (Linkbox root 'rclone-test-lucatas7duke/dst')
2026/07/24 04:25:33 DEBUG : one: Sizes differ
2026/07/24 04:25:33 DEBUG : Linkbox root 'rclone-test-lucatas7duke/dst': Waiting for checks to finish
2026/07/24 04:25:34 DEBUG : Linkbox root 'rclone-test-lucatas7duke/dst': Waiting for transfers to finish
2026/07/24 04:25:34 DEBUG : one: Update: removing old file
2026/07/24 04:25:37 DEBUG : one: Trying to read object after upload: try again in 100ms (1/10)
2026/07/24 04:25:37 DEBUG : one: Trying to read object after upload: try again in 200ms (2/10)
2026/07/24 04:25:38 DEBUG : one: Trying to read object after upload: try again in 400ms (3/10)
2026/07/24 04:25:38 DEBUG : one: Trying to read object after upload: try again in 800ms (4/10)
2026/07/24 04:25:39 DEBUG : one: Trying to read object after upload: try again in 1.6s (5/10)
2026/07/24 04:25:41 DEBUG : one: Trying to read object after upload: try again in 3.2s (6/10)
2026/07/24 04:25:44 DEBUG : one: Trying to read object after upload: try again in 6.4s (7/10)
2026/07/24 04:25:51 DEBUG : one: Trying to read object after upload: try again in 12.8s (8/10)
2026/07/24 04:26:04 DEBUG : one: Trying to read object after upload: try again in 25.6s (9/10)
2026/07/24 04:26:30 DEBUG : one: Trying to read object after upload: try again in 51.2s (10/10)
2026/07/24 04:27:21 ERROR : one: Failed to copy: object not found
2026/07/24 04:27:21 ERROR : Linkbox root 'rclone-test-lucatas7duke/dst': not deleting files as there were IO errors
2026/07/24 04:27:21 ERROR : Linkbox root 'rclone-test-lucatas7duke/dst': not deleting directories as there were IO errors
    sync_test.go:2132: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2132
        	Error:      	Received unexpected error:
        	            	object not found
        	Test:       	TestSyncCompareDest
    run.go:186: removing dir "dst" failed - try 1/3: sleeping 1s: directory not empty
--- FAIL: TestSyncCompareDest (119.85s)
FAIL
2026/07/24 04:27:26 DEBUG : Linkbox root 'rclone-test-lucatas7duke': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestLinkbox: -verbose -test.run '^(TestMoveOverSelf|TestServerSideMoveOverSelf|TestServerSideMoveWithFilter|TestSyncCompareDest)$'" - Finished ERROR in 5m23.954155653s (try 4/5): exit status 1: Failed [TestMoveOverSelf TestSyncCompareDest]