"./operations.test -test.v -test.timeout 1h0m0s -remote TestLinkbox: -verbose -test.run '^TestIndexChanged$'" - Starting (try 2/5)
2026/09/30 06:17:19 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-yivowev0gece"
2026/09/30 06:17:19 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/09/30 06:17:19 DEBUG : Linkbox root 'rclone-test-yivowev0gece': Using cached web token
2026/09/30 06:17:20 DEBUG : Creating backend with remote "/tmp/rclone3732468062"
=== RUN   TestIndexChanged
    run.go:198: Remote "Linkbox root 'rclone-test-yivowev0gece'", Local "Local file system at /tmp/rclone3732468062", Modify Window "876000h0m0s"
2026/09/30 06:17:35 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/30 06:17:35 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/09/30 06:17:36 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/30 06:17:36 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/09/30 06:17:36 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/30 06:17:36 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/09/30 06:17:37 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/09/30 06:17:37 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/09/30 06:17:39 DEBUG : pacer: Reducing sleep to 1.5s
2026/09/30 06:17:41 DEBUG : pacer: Reducing sleep to 1.125s
2026/09/30 06:17:42 DEBUG : pacer: Reducing sleep to 843.75ms
2026/09/30 06:17:43 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/09/30 06:17:45 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/09/30 06:17:46 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/09/30 06:17:46 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/09/30 06:17:46 DEBUG : index.html: size = 12393 OK
2026/09/30 06:17:46 INFO  : index.html: Copied (new)
2026/09/30 06:17:46 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/09/30 06:17:47 DEBUG : pacer: Reducing sleep to 200ms
2026/09/30 06:17:47 DEBUG : sub/index.html: size = 12302 OK
2026/09/30 06:17:47 INFO  : sub/index.html: Copied (new)
2026/09/30 06:17:47 DEBUG : other/index.html: size = 12056 OK
2026/09/30 06:17:47 INFO  : other/index.html: Copied (new)
2026/09/30 06:17:47 DEBUG : sub/deep/index.html: size = 12085 OK
2026/09/30 06:17:47 INFO  : sub/deep/index.html: Copied (new)
2026/09/30 06:17:51 INFO  : Linkbox root 'rclone-test-yivowev0gece': Partial index: listing 3 directories and walking 0 changed directories
2026/09/30 06:17:52 DEBUG : sub/deep/index.html: Update: removing old file
2026/09/30 06:17:52 NOTICE: Time may be set wrong - time from "aht.nuplink3.net" is 20m52.59228177s different from this computer
2026/09/30 06:17:52 DEBUG : index.html: Unchanged skipping
2026/09/30 06:17:52 DEBUG : sub/index.html: Unchanged skipping
2026/09/30 06:17:55 DEBUG : sub/deep/index.html: size = 12342 OK
2026/09/30 06:17:55 INFO  : sub/deep/index.html: Copied (replaced existing)
2026/09/30 06:18:00 INFO  : Linkbox root 'rclone-test-yivowev0gece': Partial index: listing 3 directories and walking 0 changed directories
2026/09/30 06:18:00 DEBUG : sub/index.html: Update: removing old file
2026/09/30 06:18:00 DEBUG : index.html: Unchanged skipping
2026/09/30 06:18:03 DEBUG : sub/new/index.html: size = 12083 OK
2026/09/30 06:18:03 INFO  : sub/new/index.html: Copied (new)
2026/09/30 06:18:04 DEBUG : sub/index.html: size = 12548 OK
2026/09/30 06:18:04 INFO  : sub/index.html: Copied (replaced existing)
2026/09/30 06:18:07 INFO  : Linkbox root 'rclone-test-yivowev0gece': Partial index: listing 1 directories and walking 1 changed directories
2026/09/30 06:18:07 DEBUG : other/index.html: Update: removing old file
2026/09/30 06:18:07 DEBUG : index.html: Unchanged skipping
2026/09/30 06:18:10 DEBUG : other/index.html: size = 12591 OK
2026/09/30 06:18:10 INFO  : other/index.html: Copied (replaced existing)
2026/09/30 06:18:13 INFO  : Linkbox root 'rclone-test-yivowev0gece': Partial index: listing 1 directories and walking 0 changed directories
2026/09/30 06:18:13 DEBUG : other/index.html: Update: removing old file
2026/09/30 06:18:13 DEBUG : index.html: Unchanged skipping
2026/09/30 06:18:16 DEBUG : other/index.html: size = 12859 OK
2026/09/30 06:18:16 INFO  : other/index.html: Copied (replaced existing)
2026/09/30 06:18:19 INFO  : Linkbox root 'rclone-test-yivowev0gece': Nothing changed so nothing to index
2026/09/30 06:18:19 INFO  : Linkbox root 'rclone-test-yivowev0gece': Root changed so doing a full index
2026/09/30 06:18:20 DEBUG : sub/index.html: Update: removing old file
2026/09/30 06:18:20 DEBUG : index.html: Unchanged skipping
2026/09/30 06:18:21 DEBUG : sub/deep/index.html: Unchanged skipping
2026/09/30 06:18:21 DEBUG : sub/new/index.html: Unchanged skipping
2026/09/30 06:18:21 DEBUG : other/index.html: Unchanged skipping
2026/09/30 06:18:24 DEBUG : sub/index.html: size = 12805 OK
2026/09/30 06:18:24 INFO  : sub/index.html: Copied (replaced existing)
2026/09/30 06:18:26 INFO  : Linkbox root 'rclone-test-yivowev0gece': Partial index would list 2 directories, more than 1, so doing a full index
2026/09/30 06:18:28 DEBUG : sub/index.html: Update: removing old file
2026/09/30 06:18:28 DEBUG : index.html: Unchanged skipping
2026/09/30 06:18:28 DEBUG : sub/deep/index.html: Unchanged skipping
2026/09/30 06:18:28 DEBUG : sub/new/index.html: Unchanged skipping
2026/09/30 06:18:28 DEBUG : other/index.html: Unchanged skipping
2026/09/30 06:18:31 DEBUG : sub/index.html: size = 13061 OK
2026/09/30 06:18:31 INFO  : sub/index.html: Copied (replaced existing)
2026/09/30 06:18:34 INFO  : Linkbox root 'rclone-test-yivowev0gece': Partial index: listing 1 directories and walking 1 changed directories
2026/09/30 06:18:34 DEBUG : sub/deep/index.html: Update: removing old file
2026/09/30 06:18:35 DEBUG : index.html: Unchanged skipping
2026/09/30 06:18:35 DEBUG : sub/new/index.html: Unchanged skipping
2026/09/30 06:18:35 DEBUG : sub/index.html: Unchanged skipping
2026/09/30 06:18:38 DEBUG : sub/deep/index.html: size = 12598 OK
2026/09/30 06:18:38 INFO  : sub/deep/index.html: Copied (replaced existing)
2026/09/30 06:18:43 INFO  : Linkbox root 'rclone-test-yivowev0gece': Partial index: listing 2 directories and walking 0 changed directories
2026/09/30 06:18:43 DEBUG : sub/index.html: Update: removing old file
2026/09/30 06:18:43 DEBUG : index.html: Unchanged skipping
2026/09/30 06:18:47 DEBUG : sub/index.html: size = 13319 OK
2026/09/30 06:18:47 INFO  : sub/index.html: Copied (replaced existing)
--- PASS: TestIndexChanged (121.26s)
PASS
2026/09/30 06:19:21 DEBUG : Linkbox root 'rclone-test-yivowev0gece': Purge remote
"./operations.test -test.v -test.timeout 1h0m0s -remote TestLinkbox: -verbose -test.run '^TestIndexChanged$'" - Finished OK in 2m3.526601501s (try 2/5)