"./sync.test -test.v -test.timeout 1h0m0s -remote TestLinkbox: -verbose -test.run '^(TestMoveWithIgnoreExisting|TestServerSideMoveDeleteEmptySourceDirs|TestSyncCompareDest)$'" - Starting (try 3/5)
2026/08/17 05:33:50 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-reqopum0yuyo"
2026/08/17 05:33:50 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/08/17 05:33:50 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo': Using cached web token
2026/08/17 05:33:51 DEBUG : Creating backend with remote "/tmp/rclone1469782952"
=== RUN   TestMoveWithIgnoreExisting
    run.go:198: Remote "Linkbox root 'rclone-test-reqopum0yuyo'", Local "Local file system at /tmp/rclone1469782952", Modify Window "876000h0m0s"
2026/08/17 05:33:51 DEBUG : existing-b: Need to transfer - File not found at Destination
2026/08/17 05:33:51 DEBUG : existing: Need to transfer - File not found at Destination
2026/08/17 05:33:51 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo': Waiting for checks to finish
2026/08/17 05:33:51 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo': Waiting for transfers to finish
2026/08/17 05:33:55 DEBUG : existing-b: size = 6 OK
2026/08/17 05:33:55 INFO  : existing-b: Copied (new)
2026/08/17 05:33:55 INFO  : existing-b: Deleted
2026/08/17 05:33:56 DEBUG : existing: size = 6 OK
2026/08/17 05:33:56 INFO  : existing: Copied (new)
2026/08/17 05:33:56 INFO  : existing: Deleted
2026/08/17 05:33:56 DEBUG : existing: Destination exists, skipping
2026/08/17 05:33:56 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2026/08/17 05:33:56 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo': Waiting for checks to finish
2026/08/17 05:33:56 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo': Waiting for transfers to finish
2026/08/17 05:33:56 INFO  : There was nothing to transfer
--- PASS: TestMoveWithIgnoreExisting (8.32s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:198: Remote "Linkbox root 'rclone-test-reqopum0yuyo'", Local "Local file system at /tmp/rclone1469782952", Modify Window "876000h0m0s"
2026/08/17 05:33:59 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-fetayec9xoho"
2026/08/17 05:33:59 DEBUG : Linkbox root 'rclone-test-fetayec9xoho': Using cached web token
2026/08/17 05:34:06 INFO  : tomatoDir: Making directory
2026/08/17 05:34:07 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/08/17 05:34:07 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/08/17 05:34:07 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/08/17 05:34:07 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/08/17 05:34:09 DEBUG : pacer: Reducing sleep to 600ms
2026/08/17 05:34:09 DEBUG : pacer: Reducing sleep to 450ms
2026/08/17 05:34:09 DEBUG : pacer: Reducing sleep to 337.5ms
    sync_test.go:1736: Server side move (if possible) Linkbox root 'rclone-test-reqopum0yuyo' -> Linkbox root 'rclone-test-fetayec9xoho'
2026/08/17 05:34:15 DEBUG : pacer: Reducing sleep to 253.125ms
2026/08/17 05:34:16 DEBUG : potato2: Need to transfer - File not found at Destination
2026/08/17 05:34:16 DEBUG : empty space: size = 1 OK
2026/08/17 05:34:16 DEBUG : empty space: Sizes identical
2026/08/17 05:34:16 DEBUG : empty space: Unchanged skipping
2026/08/17 05:34:16 DEBUG : potato3: size = 68 (Linkbox root 'rclone-test-reqopum0yuyo')
2026/08/17 05:34:16 DEBUG : potato3: size = 60 (Linkbox root 'rclone-test-fetayec9xoho')
2026/08/17 05:34:16 DEBUG : potato3: Sizes differ
2026/08/17 05:34:16 DEBUG : pacer: Reducing sleep to 200ms
2026/08/17 05:34:16 DEBUG : Linkbox root 'rclone-test-fetayec9xoho': Waiting for checks to finish
2026/08/17 05:34:16 NOTICE: Time may be set wrong - time from "aht.nuplink3.net" is 1586h24m39.711015626s different from this computer
2026/08/17 05:34:16 DEBUG : potato3: Update: removing old file
2026/08/17 05:34:17 INFO  : empty space: Deleted
2026/08/17 05:34:17 DEBUG : Linkbox root 'rclone-test-fetayec9xoho': Waiting for transfers to finish
2026/08/17 05:34:18 DEBUG : potato2: size = 60 OK
2026/08/17 05:34:18 INFO  : potato2: Copied (new)
2026/08/17 05:34:20 DEBUG : potato3: size = 68 OK
2026/08/17 05:34:20 INFO  : potato3: Copied (replaced existing)
2026/08/17 05:34:20 INFO  : potato2: Deleted
2026/08/17 05:34:21 INFO  : potato3: Deleted
2026/08/17 05:34:21 INFO  : tomatoDir: Removing directory
2026/08/17 05:34:22 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo': deleted 1 directories
2026/08/17 05:34:23 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-ludijas4benu"
2026/08/17 05:34:23 DEBUG : Linkbox root 'rclone-test-ludijas4benu': Using cached web token
2026/08/17 05:34:24 INFO  : tomatoDir: Making directory
2026/08/17 05:34:26 DEBUG : empty space: Need to transfer - File not found at Destination
2026/08/17 05:34:26 DEBUG : potato2: Need to transfer - File not found at Destination
2026/08/17 05:34:26 DEBUG : potato3: Need to transfer - File not found at Destination
2026/08/17 05:34:26 DEBUG : Linkbox root 'rclone-test-ludijas4benu': Waiting for checks to finish
2026/08/17 05:34:26 DEBUG : Linkbox root 'rclone-test-ludijas4benu': Waiting for transfers to finish
2026/08/17 05:34:31 DEBUG : empty space: size = 1 OK
2026/08/17 05:34:31 INFO  : empty space: Copied (new)
2026/08/17 05:34:31 DEBUG : potato2: size = 60 OK
2026/08/17 05:34:31 INFO  : potato2: Copied (new)
2026/08/17 05:34:31 DEBUG : potato3: size = 68 OK
2026/08/17 05:34:31 INFO  : potato3: Copied (new)
2026/08/17 05:34:32 INFO  : empty space: Deleted
2026/08/17 05:34:32 INFO  : potato2: Deleted
2026/08/17 05:34:32 INFO  : potato3: Deleted
2026/08/17 05:34:32 INFO  : tomatoDir: Removing directory
2026/08/17 05:34:34 DEBUG : Linkbox root 'rclone-test-fetayec9xoho': deleted 1 directories
2026/08/17 05:34:35 DEBUG : Linkbox root 'rclone-test-ludijas4benu': Purge remote
2026/08/17 05:34:36 DEBUG : Linkbox root 'rclone-test-fetayec9xoho': Purge remote
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (38.53s)
=== RUN   TestSyncCompareDest
    run.go:198: Remote "Linkbox root 'rclone-test-reqopum0yuyo'", Local "Local file system at /tmp/rclone1469782952", Modify Window "876000h0m0s"
2026/08/17 05:34:38 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-reqopum0yuyo/dst"
2026/08/17 05:34:38 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo/dst': Using cached web token
2026/08/17 05:34:39 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-reqopum0yuyo/CompareDest"
2026/08/17 05:34:39 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo/CompareDest': Using cached web token
2026/08/17 05:34:41 DEBUG : one: Need to transfer - File not found at Destination
2026/08/17 05:34:41 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo/dst': Waiting for checks to finish
2026/08/17 05:34:41 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo/dst': Waiting for transfers to finish
2026/08/17 05:34:44 DEBUG : one: size = 3 OK
2026/08/17 05:34:44 INFO  : one: Copied (new)
2026/08/17 05:34:44 DEBUG : Waiting for deletions to finish
2026/08/17 05:34:45 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo/dst': Waiting for checks to finish
2026/08/17 05:34:45 DEBUG : one: size = 5 (Local file system at /tmp/rclone1469782952)
2026/08/17 05:34:45 DEBUG : one: size = 3 (Linkbox root 'rclone-test-reqopum0yuyo/dst')
2026/08/17 05:34:45 DEBUG : one: Sizes differ
2026/08/17 05:34:46 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo/dst': Waiting for transfers to finish
2026/08/17 05:34:46 DEBUG : one: Update: removing old file
2026/08/17 05:34:49 DEBUG : one: size = 5 OK
2026/08/17 05:34:49 INFO  : one: Copied (replaced existing)
2026/08/17 05:34:49 DEBUG : Waiting for deletions to finish
2026/08/17 05:34:49 DEBUG : dst/one: Update: removing old file
2026/08/17 05:34:57 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo/dst': Waiting for checks to finish
2026/08/17 05:34:57 DEBUG : one: size = 5 (Local file system at /tmp/rclone1469782952)
2026/08/17 05:34:57 DEBUG : one: size = 3 (Linkbox root 'rclone-test-reqopum0yuyo/dst')
2026/08/17 05:34:57 DEBUG : one: Sizes differ
2026/08/17 05:34:57 DEBUG : one: size = 5 OK
2026/08/17 05:34:57 DEBUG : one: Sizes identical
2026/08/17 05:34:57 DEBUG : one: Destination found in --compare-dest, skipping
2026/08/17 05:34:57 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo/dst': Waiting for transfers to finish
2026/08/17 05:34:57 DEBUG : Waiting for deletions to finish
2026/08/17 05:34:57 INFO  : There was nothing to transfer
2026/08/17 05:35:01 DEBUG : one: size = 5 (Local file system at /tmp/rclone1469782952)
2026/08/17 05:35:01 DEBUG : one: size = 3 (Linkbox root 'rclone-test-reqopum0yuyo/dst')
2026/08/17 05:35:01 DEBUG : one: Sizes differ
2026/08/17 05:35:01 DEBUG : two: size = 3 OK
2026/08/17 05:35:01 DEBUG : two: Sizes identical
2026/08/17 05:35:01 DEBUG : two: Destination found in --compare-dest, skipping
2026/08/17 05:35:01 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo/dst': Waiting for checks to finish
2026/08/17 05:35:02 DEBUG : one: size = 5 OK
2026/08/17 05:35:02 DEBUG : one: Sizes identical
2026/08/17 05:35:02 DEBUG : one: Destination found in --compare-dest, skipping
2026/08/17 05:35:02 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo/dst': Waiting for transfers to finish
2026/08/17 05:35:02 DEBUG : Waiting for deletions to finish
2026/08/17 05:35:02 INFO  : There was nothing to transfer
2026/08/17 05:35:02 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/08/17 05:35:02 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/08/17 05:35:02 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/08/17 05:35:02 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/08/17 05:35:02 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/08/17 05:35:02 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/08/17 05:35:03 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/08/17 05:35:03 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/08/17 05:35:05 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/08/17 05:35:07 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/08/17 05:35:09 DEBUG : pacer: Reducing sleep to 1.5s
2026/08/17 05:35:11 DEBUG : pacer: Reducing sleep to 1.125s
2026/08/17 05:35:12 DEBUG : pacer: Reducing sleep to 843.75ms
2026/08/17 05:35:13 DEBUG : one: size = 5 (Local file system at /tmp/rclone1469782952)
2026/08/17 05:35:13 DEBUG : one: size = 3 (Linkbox root 'rclone-test-reqopum0yuyo/dst')
2026/08/17 05:35:13 DEBUG : one: Sizes differ
2026/08/17 05:35:13 DEBUG : two: size = 3 OK
2026/08/17 05:35:13 DEBUG : two: Sizes identical
2026/08/17 05:35:13 DEBUG : two: Destination found in --compare-dest, skipping
2026/08/17 05:35:13 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo/dst': Waiting for checks to finish
2026/08/17 05:35:13 DEBUG : one: size = 5 OK
2026/08/17 05:35:13 DEBUG : one: Sizes identical
2026/08/17 05:35:13 DEBUG : one: Destination found in --compare-dest, skipping
2026/08/17 05:35:13 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo/dst': Waiting for transfers to finish
2026/08/17 05:35:13 DEBUG : Waiting for deletions to finish
2026/08/17 05:35:13 INFO  : There was nothing to transfer
2026/08/17 05:35:13 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/08/17 05:35:14 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/08/17 05:35:15 DEBUG : pacer: Reducing sleep to 355.957031ms
    sync_test.go:2206: No hash on uploaded file so skipping compare timestamp test
2026/08/17 05:35:15 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/08/17 05:35:16 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/08/17 05:35:16 DEBUG : pacer: Reducing sleep to 200ms
2026/08/17 05:35:16 DEBUG : one: size = 5 (Local file system at /tmp/rclone1469782952)
2026/08/17 05:35:16 DEBUG : one: size = 3 (Linkbox root 'rclone-test-reqopum0yuyo/dst')
2026/08/17 05:35:16 DEBUG : one: Sizes differ
2026/08/17 05:35:16 DEBUG : two: size = 5 (Local file system at /tmp/rclone1469782952)
2026/08/17 05:35:16 DEBUG : two: size = 3 (Linkbox root 'rclone-test-reqopum0yuyo/CompareDest')
2026/08/17 05:35:16 DEBUG : two: Sizes differ
2026/08/17 05:35:16 DEBUG : two: Need to transfer - File not found at Destination
2026/08/17 05:35:16 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo/dst': Waiting for checks to finish
2026/08/17 05:35:17 DEBUG : one: size = 5 OK
2026/08/17 05:35:17 DEBUG : one: Sizes identical
2026/08/17 05:35:17 DEBUG : one: Destination found in --compare-dest, skipping
2026/08/17 05:35:17 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo/dst': Waiting for transfers to finish
2026/08/17 05:35:19 DEBUG : two: size = 5 OK
2026/08/17 05:35:19 INFO  : two: Copied (new)
2026/08/17 05:35:19 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncCompareDest (50.60s)
PASS
2026/08/17 05:35:28 DEBUG : Linkbox root 'rclone-test-reqopum0yuyo': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestLinkbox: -verbose -test.run '^(TestMoveWithIgnoreExisting|TestServerSideMoveDeleteEmptySourceDirs|TestSyncCompareDest)$'" - Finished OK in 1m39.755580065s (try 3/5)