"./sync.test -test.v -test.timeout 1h0m0s -remote TestLinkbox: -verbose -test.run '^(TestNothingToTransferWithEmptyDirs|TestNothingToTransferWithoutEmptyDirs|TestServerSideMoveWithFilter|TestSyncSuffix)$'" - Starting (try 2/5)
2026/09/26 04:47:27 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-gezarec1bivi"
2026/09/26 04:47:27 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/09/26 04:47:27 DEBUG : Linkbox root 'rclone-test-gezarec1bivi': Using cached web token
2026/09/26 04:47:28 DEBUG : Creating backend with remote "/tmp/rclone3865551857"
=== RUN   TestServerSideMoveWithFilter
    run.go:198: Remote "Linkbox root 'rclone-test-gezarec1bivi'", Local "Local file system at /tmp/rclone3865551857", Modify Window "876000h0m0s"
2026/09/26 04:47:28 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-fipowun0bede"
2026/09/26 04:47:28 DEBUG : Linkbox root 'rclone-test-fipowun0bede': Using cached web token
2026/09/26 04:47:36 DEBUG : empty space: Trying to read object after upload: try again in 100ms (1/10)
2026/09/26 04:47:37 DEBUG : empty space: Trying to read object after upload: try again in 200ms (2/10)
    sync_test.go:1736: Server side move (if possible) Linkbox root 'rclone-test-gezarec1bivi' -> Linkbox root 'rclone-test-fipowun0bede'
2026/09/26 04:47:46 DEBUG : empty space: Excluded (Size Filter)
2026/09/26 04:47:46 DEBUG : empty space: Excluded
2026/09/26 04:47:46 DEBUG : empty space: Excluded (Size Filter)
2026/09/26 04:47:46 DEBUG : empty space: Excluded
2026/09/26 04:47:46 DEBUG : potato2: Need to transfer - File not found at Destination
2026/09/26 04:47:46 DEBUG : Linkbox root 'rclone-test-fipowun0bede': Waiting for checks to finish
2026/09/26 04:47:46 DEBUG : potato3: size = 68 (Linkbox root 'rclone-test-gezarec1bivi')
2026/09/26 04:47:46 DEBUG : potato3: size = 60 (Linkbox root 'rclone-test-fipowun0bede')
2026/09/26 04:47:46 DEBUG : potato3: Sizes differ
2026/09/26 04:47:46 DEBUG : Linkbox root 'rclone-test-fipowun0bede': Waiting for transfers to finish
2026/09/26 04:47:46 NOTICE: Time may be set wrong - time from "aht.nuplink3.net" is 48h13m46.395181617s different from this computer
2026/09/26 04:47:46 DEBUG : potato3: Update: removing old file
2026/09/26 04:47:48 DEBUG : potato2: Trying to read object after upload: try again in 100ms (1/10)
2026/09/26 04:47:48 DEBUG : potato2: size = 60 OK
2026/09/26 04:47:48 INFO  : potato2: Copied (new)
2026/09/26 04:47:49 DEBUG : potato3: size = 68 OK
2026/09/26 04:47:49 INFO  : potato3: Copied (replaced existing)
2026/09/26 04:47:50 INFO  : potato2: Deleted
2026/09/26 04:47:51 INFO  : potato3: Deleted
    fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:302: Flushing the directory cache
    fstest.go:293: Sleeping for 6s just to make sure
2026/09/26 04:47:59 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-yawawos6poka"
2026/09/26 04:47:59 DEBUG : Linkbox root 'rclone-test-yawawos6poka': Using cached web token
2026/09/26 04:48:00 DEBUG : empty space: Excluded (Size Filter)
2026/09/26 04:48:00 DEBUG : empty space: Excluded
2026/09/26 04:48:00 DEBUG : potato2: Need to transfer - File not found at Destination
2026/09/26 04:48:00 DEBUG : potato3: Need to transfer - File not found at Destination
2026/09/26 04:48:00 DEBUG : Linkbox root 'rclone-test-yawawos6poka': Waiting for checks to finish
2026/09/26 04:48:00 DEBUG : Linkbox root 'rclone-test-yawawos6poka': Waiting for transfers to finish
2026/09/26 04:48:04 DEBUG : potato2: size = 60 OK
2026/09/26 04:48:04 INFO  : potato2: Copied (new)
2026/09/26 04:48:05 DEBUG : potato3: size = 68 OK
2026/09/26 04:48:05 INFO  : potato3: Copied (new)
2026/09/26 04:48:06 INFO  : potato2: Deleted
2026/09/26 04:48:06 INFO  : potato3: Deleted
2026/09/26 04:48:06 DEBUG : Linkbox root 'rclone-test-yawawos6poka': Purge remote
2026/09/26 04:48:08 DEBUG : Linkbox root 'rclone-test-fipowun0bede': Purge remote
--- PASS: TestServerSideMoveWithFilter (42.62s)
=== RUN   TestSyncSuffix
    run.go:198: Remote "Linkbox root 'rclone-test-gezarec1bivi'", Local "Local file system at /tmp/rclone3865551857", Modify Window "876000h0m0s"
    sync_test.go:2510: Skipping test as remote does not support server-side move
--- SKIP: TestSyncSuffix (0.43s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:198: Remote "Linkbox root 'rclone-test-gezarec1bivi'", Local "Local file system at /tmp/rclone3865551857", Modify Window "876000h0m0s"
2026/09/26 04:48:11 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2026/09/26 04:48:11 INFO  : sub dir: Making directory
2026/09/26 04:48:37 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/26 04:48:37 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/09/26 04:48:38 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/09/26 04:48:38 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/09/26 04:48:38 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/09/26 04:48:38 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/09/26 04:48:39 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/09/26 04:48:39 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/09/26 04:48:40 DEBUG : pacer: Reducing sleep to 1.5s
2026/09/26 04:48:42 DEBUG : pacer: Reducing sleep to 1.125s
2026/09/26 04:48:44 DEBUG : pacer: Reducing sleep to 843.75ms
2026/09/26 04:48:45 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/09/26 04:48:47 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/09/26 04:48:47 DEBUG : pacer: Reducing sleep to 355.957031ms
    run.go:186: removing dir "sub dir2/very/very/very/very/very/nested/subdir" failed - try 1/3: sleeping 1s: directory not empty
2026/09/26 04:48:49 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/09/26 04:48:50 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/09/26 04:48:50 DEBUG : pacer: Reducing sleep to 200ms
--- PASS: TestNothingToTransferWithEmptyDirs (51.24s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:198: Remote "Linkbox root 'rclone-test-gezarec1bivi'", Local "Local file system at /tmp/rclone3865551857", Modify Window "876000h0m0s"
2026/09/26 04:49:03 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2026/09/26 04:49:03 INFO  : sub dir: Making directory
--- PASS: TestNothingToTransferWithoutEmptyDirs (42.38s)
PASS
2026/09/26 04:49:45 DEBUG : Linkbox root 'rclone-test-gezarec1bivi': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestLinkbox: -verbose -test.run '^(TestNothingToTransferWithEmptyDirs|TestNothingToTransferWithoutEmptyDirs|TestServerSideMoveWithFilter|TestSyncSuffix)$'" - Finished OK in 2m19.116116135s (try 2/5)