"./sync.test -test.v -test.timeout 1h0m0s -remote TestLinkbox: -verbose -test.run '^(TestCopy|TestCopyAfterDelete|TestCopyCheckFirst|TestCopyDeleteBefore|TestCopyEmptyDirectories|TestCopyMetadata|TestCopyMetadataNoEmptyDirs|TestCopyMissingDirectory|TestCopyNoEmptyDirectories|TestCopyNoTraverse|TestCopyNoTraverseDeadlock|TestCopyOverSelf|TestCopyRedownload|TestCopyWithDepth|TestCopyWithFilesFrom|TestCopyWithFilesFromAndNoTraverse|TestMoveEmptyDirectories|TestMoveNoEmptyDirectories|TestMoveOverSelf|TestMoveWithDeleteEmptySrcDirs|TestMoveWithIgnoreExisting|TestMoveWithoutDeleteEmptySrcDirs|TestServerSideCopy|TestServerSideCopyOverSelf|TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs|TestServerSideMoveLocal|TestServerSideMoveOverSelf|TestServerSideMoveOverlap|TestServerSideMoveWithFilter|TestSyncAfterAddingAFile|TestSyncAfterChangingContentsOnly|TestSyncAfterChangingFilesSizeOnly|TestSyncAfterChangingModtimeOnly|TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime|TestSyncAfterRemovingAFileAndAddingAFile|TestSyncAfterRemovingAFileAndAddingAFileDryRun|TestSyncAfterRemovingAFileAndAddingAFileSubDir|TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors|TestSyncBackupDir|TestSyncBackupDirSuffixOnly|TestSyncBackupDirWithSuffix|TestSyncBackupDirWithSuffixKeepExtension|TestSyncBasedOnCheckSum|TestSyncCompareDest|TestSyncConcurrentDelete|TestSyncCopyDest|TestSyncDeleteBefore|TestSyncDeleteDuring|TestSyncDoesntUpdateModtime|TestSyncEmptyDirectories|TestSyncIgnoreCase|TestSyncIgnoreErrors|TestSyncIgnoreExisting|TestSyncIgnoreSize|TestSyncIgnoreTimes|TestSyncImmutable|TestSyncMultipleCompareDest|TestSyncNoEmptyDirectories|TestSyncNoTraverse|TestSyncNoUpdateDirModtime|TestSyncOverlap|TestSyncSetDelayedModTimes|TestSyncSizeOnly|TestSyncSuffix|TestSyncSuffixKeepExtension|TestSyncUTFNorm|TestSyncWithExclude|TestSyncWithExcludeAndDeleteExcluded|TestSyncWithTrackRenames|TestSyncWithTrackRenamesStrategyLeaf|TestSyncWithTrackRenamesStrategyModtime|TestSyncWithUpdateOlder)$|^TestMaxTransfer$/^(Cautious|Hard|Soft)$'" - Starting (try 2/5)
2026/07/22 03:29:23 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-wusoveh1hufi"
2026/07/22 03:29:23 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/07/22 03:29:23 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Using cached web token
2026/07/22 03:29:24 DEBUG : Creating backend with remote "/tmp/rclone1180572967"
=== RUN   TestCopy
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:29:24 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2026/07/22 03:29:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/07/22 03:29:26 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:29:26 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:29:30 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:29:30 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:29:31 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:29:31 DEBUG : sub dir/hello world: size = 11 OK
2026/07/22 03:29:31 INFO  : sub dir/hello world: Copied (new)
2026/07/22 03:29:32 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Skipping modtime test as remote does not support DirSetModTime or MkdirMetadata
2026/07/22 03:29:34 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:29:34 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:29:34 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:29:34 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:29:34 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:29:34 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:29:35 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:29:35 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:29:37 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:29:39 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:29:41 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:29:43 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:29:45 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:29:47 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
    run.go:186: removing dir "sub dir" failed - try 1/3: sleeping 1s: getting files failed: invalid character '<' looking for beginning of value
2026/07/22 03:29:49 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:29:51 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:29:54 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:29:54 DEBUG : pacer: Reducing sleep to 843.75ms
--- PASS: TestCopy (29.99s)
=== RUN   TestCopyMetadata
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:98: Skipping as metadata not supported
2026/07/22 03:29:55 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:29:56 DEBUG : pacer: Reducing sleep to 474.609375ms
--- SKIP: TestCopyMetadata (1.97s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:98: Skipping as metadata not supported
2026/07/22 03:29:57 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:29:57 DEBUG : pacer: Reducing sleep to 266.967773ms
--- SKIP: TestCopyMetadataNoEmptyDirs (1.12s)
=== RUN   TestCopyMissingDirectory
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:29:57 DEBUG : Creating backend with remote "/non-existing"
2026/07/22 03:29:58 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:29:58 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2026/07/22 03:29:58 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:29:58 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:29:58 DEBUG : pacer: Reducing sleep to 200ms
--- PASS: TestCopyMissingDirectory (0.82s)
=== RUN   TestCopyNoTraverse
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:29:58 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/07/22 03:29:58 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:29:58 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:30:03 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:30:03 DEBUG : sub dir/hello world: size = 11 OK
2026/07/22 03:30:03 INFO  : sub dir/hello world: Copied (new)
--- PASS: TestCopyNoTraverse (9.53s)
=== RUN   TestCopyNoTraverseDeadlock
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:222: Only runs on local
--- SKIP: TestCopyNoTraverseDeadlock (0.39s)
=== RUN   TestCopyCheckFirst
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:30:08 INFO  : Linkbox root 'rclone-test-wusoveh1hufi': Running all checks before starting transfers
2026/07/22 03:30:08 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/07/22 03:30:08 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:30:08 INFO  : Linkbox root 'rclone-test-wusoveh1hufi': Checks finished, now starting transfers
2026/07/22 03:30:08 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:30:12 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:30:12 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:30:13 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:30:13 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 03:30:14 DEBUG : sub dir/hello world: size = 11 OK
2026/07/22 03:30:14 INFO  : sub dir/hello world: Copied (new)
    run.go:186: removing dir "sub dir" failed - try 1/3: sleeping 1s: directory not empty
    run.go:186: removing dir "sub dir" failed - try 2/3: sleeping 1.5s: directory not empty
    run.go:186: removing dir "sub dir" failed: directory not empty
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3
    fstest.go:301: Flushing the directory cache
    fstest.go:298: Sleeping for 4s for list eventual consistency: 3/3
    fstest.go:301: Flushing the directory cache
    fstest.go:327: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:327
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:191
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:406
        	            				/usr/local/go/src/testing/testing.go:1317
        	            				/usr/local/go/src/testing/testing.go:1667
        	            				/usr/local/go/src/testing/testing.go:2030
        	Error:      	Not equal: 
        	            	expected: []string{}
        	            	actual  : []string{"sub dir"}
        	            	
        	            	Diff:
        	            	--- Expected
        	            	+++ Actual
        	            	@@ -1,2 +1,3 @@
        	            	-([]string) {
        	            	+([]string) (len=1) {
        	            	+ (string) (len=7) "sub dir"
        	            	 }
        	Test:       	TestCopyCheckFirst
        	Messages:   	directories
--- FAIL: TestCopyCheckFirst (21.05s)
=== RUN   TestSyncNoTraverse
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:30:29 ERROR : Ignoring --no-traverse with sync
2026/07/22 03:30:30 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/07/22 03:30:30 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:30:30 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:30:30 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:30:30 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:30:30 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:30:30 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:30:31 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:30:31 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:30:32 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:30:32 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:30:33 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:30:35 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:30:37 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:30:39 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:30:41 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:30:43 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:30:43 DEBUG : sub dir/hello world: Received error: Update err in unmarshaling response: invalid character '<' looking for beginning of value - low level retry 0/10
2026/07/22 03:30:45 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:30:47 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:30:49 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:30:51 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:30:53 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:30:56 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 03:30:56 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:30:56 DEBUG : sub dir/hello world: size = 11 OK
2026/07/22 03:30:56 INFO  : sub dir/hello world: Copied (new)
2026/07/22 03:30:56 DEBUG : Waiting for deletions to finish
2026/07/22 03:30:57 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 03:30:58 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:30:58 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:30:59 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:31:00 DEBUG : pacer: Reducing sleep to 200ms
--- PASS: TestSyncNoTraverse (32.54s)
=== RUN   TestCopyWithDepth
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:31:02 DEBUG : hello world2: Need to transfer - File not found at Destination
2026/07/22 03:31:02 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:31:02 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:31:04 DEBUG : hello world2: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:31:04 DEBUG : hello world2: size = 12 OK
2026/07/22 03:31:04 INFO  : hello world2: Copied (new)
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
--- PASS: TestCopyWithDepth (12.05s)
=== RUN   TestCopyWithFilesFrom
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:31:14 DEBUG : potato2: Need to transfer - File not found at Destination
2026/07/22 03:31:14 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:31:14 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:31:16 DEBUG : potato2: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:31:16 DEBUG : potato2: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:31:17 DEBUG : potato2: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:31:17 DEBUG : potato2: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 03:31:18 DEBUG : potato2: size = 11 OK
2026/07/22 03:31:18 INFO  : potato2: Copied (new)
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
--- PASS: TestCopyWithFilesFrom (14.14s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:31:28 DEBUG : potato2: Need to transfer - File not found at Destination
2026/07/22 03:31:28 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:31:28 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:31:30 DEBUG : potato2: size = 11 OK
2026/07/22 03:31:30 INFO  : potato2: Copied (new)
--- PASS: TestCopyWithFilesFromAndNoTraverse (4.25s)
=== RUN   TestCopyEmptyDirectories
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:31:32 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2026/07/22 03:31:32 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2026/07/22 03:31:32 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2026/07/22 03:31:32 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2026/07/22 03:31:32 INFO  : sub dir2: Making directory
2026/07/22 03:31:32 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:31:32 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:31:33 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:31:33 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:31:33 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:31:33 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:31:34 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:31:34 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:31:35 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:31:37 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:31:39 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:31:41 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:31:43 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:31:45 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:31:45 INFO  : sub dir: Making directory
2026/07/22 03:31:47 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:31:49 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:31:51 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:31:55 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:31:55 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/07/22 03:31:55 INFO  : sub dir2/sub sub dir2: Making directory
2026/07/22 03:31:55 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 03:31:57 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:31:57 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 03:31:59 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:31:59 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:31:59 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:31:59 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:32:00 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:32:01 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 03:32:01 DEBUG : sub dir/hello world: size = 11 OK
2026/07/22 03:32:01 INFO  : sub dir/hello world: Copied (new)
    sync_test.go:355: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:355
        	Error:      	Received unexpected error:
        	            	getting files failed: invalid character '<' looking for beginning of value
        	Test:       	TestCopyEmptyDirectories
--- FAIL: TestCopyEmptyDirectories (36.28s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:32:08 INFO  : sub dir2: Making directory
2026/07/22 03:32:08 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2026/07/22 03:32:08 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2026/07/22 03:32:09 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/07/22 03:32:09 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:32:09 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:32:12 DEBUG : sub dir/hello world: size = 11 OK
2026/07/22 03:32:12 INFO  : sub dir/hello world: Copied (new)
--- PASS: TestCopyNoEmptyDirectories (7.61s)
=== RUN   TestMoveEmptyDirectories
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:32:16 DEBUG : sub dir2: Making directory with metadata
2026/07/22 03:32:16 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2026/07/22 03:32:16 INFO  : sub dir2: Making directory
2026/07/22 03:32:18 INFO  : sub dir: Making directory
2026/07/22 03:32:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/07/22 03:32:19 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:32:19 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:32:21 DEBUG : sub dir/hello world: size = 11 OK
2026/07/22 03:32:21 INFO  : sub dir/hello world: Copied (new)
2026/07/22 03:32:21 INFO  : sub dir/hello world: Deleted
2026/07/22 03:32:22 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Skipping modtime test as remote does not support DirSetModTime or MkdirMetadata
2026/07/22 03:32:22 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Skipping modtime test as remote does not support DirSetModTime or MkdirMetadata
--- PASS: TestMoveEmptyDirectories (11.22s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:438: Skipping test as backend does not support DirSetModTime
2026/07/22 03:32:27 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:32:27 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:32:28 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:32:28 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:32:28 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:32:28 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:32:29 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:32:29 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:32:30 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:32:32 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:32:34 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:32:36 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:32:38 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:32:40 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:32:40 ERROR : error listing: getting files failed: invalid character '<' looking for beginning of value
    fstest.go:282: Error listing: getting files failed: invalid character '<' looking for beginning of value
--- FAIL: TestSyncNoUpdateDirModtime (13.25s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:32:40 INFO  : sub dir2: Making directory
2026/07/22 03:32:42 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:32:44 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:32:46 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:32:48 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:32:50 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:32:53 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:32:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/07/22 03:32:53 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:32:53 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:32:55 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:32:57 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 03:32:57 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:32:58 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 03:33:00 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:33:00 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:33:00 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:33:01 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:33:01 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:33:02 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 03:33:02 DEBUG : sub dir/hello world: size = 11 OK
2026/07/22 03:33:02 INFO  : sub dir/hello world: Copied (new)
2026/07/22 03:33:02 INFO  : sub dir/hello world: Deleted
    run.go:186: removing dir "sub dir" failed - try 1/3: sleeping 1s: directory not empty
--- PASS: TestMoveNoEmptyDirectories (26.62s)
=== RUN   TestSyncEmptyDirectories
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:33:07 DEBUG : sub dir2: Making directory with metadata
2026/07/22 03:33:07 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2026/07/22 03:33:07 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2026/07/22 03:33:07 INFO  : sub dir2: Making directory
2026/07/22 03:33:09 INFO  : sub dir: Making directory
2026/07/22 03:33:10 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/07/22 03:33:10 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:33:10 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:33:12 DEBUG : sub dir/hello world: size = 11 OK
2026/07/22 03:33:12 INFO  : sub dir/hello world: Copied (new)
2026/07/22 03:33:12 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': not deleting files as there were IO errors
2026/07/22 03:33:12 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': not deleting directories as there were IO errors
    sync_test.go:513: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:513
        	Error:      	Received unexpected error:
        	            	not deleting files as there were IO errors
        	Test:       	TestSyncEmptyDirectories
--- FAIL: TestSyncEmptyDirectories (10.63s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:537: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.40s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:33:18 INFO  : sub dir2: Making directory
2026/07/22 03:33:18 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/07/22 03:33:18 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:33:18 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:33:22 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:33:22 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:33:23 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:33:23 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 03:33:24 DEBUG : sub dir/hello world: size = 11 OK
2026/07/22 03:33:24 INFO  : sub dir/hello world: Copied (new)
2026/07/22 03:33:24 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': not deleting files as there were IO errors
2026/07/22 03:33:24 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': not deleting directories as there were IO errors
    sync_test.go:597: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:597
        	Error:      	Received unexpected error:
        	            	not deleting files as there were IO errors
        	Test:       	TestSyncNoEmptyDirectories
    run.go:186: removing dir "sub dir" failed - try 1/3: sleeping 1s: directory not empty
--- FAIL: TestSyncNoEmptyDirectories (11.06s)
=== RUN   TestServerSideCopy
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:33:31 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:33:31 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:33:31 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:33:31 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:33:31 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:33:31 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:33:32 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:33:32 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:33:34 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:33:36 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:33:38 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:33:40 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:33:42 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:33:44 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:33:46 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:33:48 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:33:50 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:33:52 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:33:54 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:33:57 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:33:57 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 03:33:57 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:33:59 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:33:59 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 03:34:00 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:34:00 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-homerab3toce"
2026/07/22 03:34:00 DEBUG : Config file has changed externally - reloading
2026/07/22 03:34:00 DEBUG : Linkbox root 'rclone-test-homerab3toce': Using cached web token
    sync_test.go:620: Server side copy (if possible) Linkbox root 'rclone-test-wusoveh1hufi' -> Linkbox root 'rclone-test-homerab3toce'
2026/07/22 03:34:01 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:34:02 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:34:02 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/07/22 03:34:02 DEBUG : Linkbox root 'rclone-test-homerab3toce': Waiting for checks to finish
2026/07/22 03:34:02 DEBUG : Linkbox root 'rclone-test-homerab3toce': Waiting for transfers to finish
2026/07/22 03:34:02 NOTICE: Time may be set wrong - time from "aht.nuplink3.net" is 960h31m25.322667755s different from this computer
2026/07/22 03:34:02 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 03:34:07 DEBUG : sub dir/hello world: size = 11 OK
2026/07/22 03:34:07 INFO  : sub dir/hello world: Copied (new)
2026/07/22 03:34:07 DEBUG : Linkbox root 'rclone-test-homerab3toce': Purge remote
--- PASS: TestServerSideCopy (42.95s)
=== RUN   TestCopyOverSelf
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:34:16 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:34:16 DEBUG : sub dir/hello world: size = 17 (Local file system at /tmp/rclone1180572967)
2026/07/22 03:34:16 DEBUG : sub dir/hello world: size = 11 (Linkbox root 'rclone-test-wusoveh1hufi')
2026/07/22 03:34:16 DEBUG : sub dir/hello world: Sizes differ
2026/07/22 03:34:16 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:34:16 DEBUG : sub dir/hello world: Update: removing old file
2026/07/22 03:34:20 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:34:20 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:34:20 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:34:21 DEBUG : sub dir/hello world: size = 17 OK
2026/07/22 03:34:21 INFO  : sub dir/hello world: Copied (replaced existing)
--- PASS: TestCopyOverSelf (12.62s)
=== RUN   TestServerSideCopyOverSelf
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:34:27 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:34:27 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:34:27 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:34:27 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:34:28 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:34:28 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:34:28 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:34:28 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:34:30 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:34:32 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:34:34 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:34:36 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:34:38 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:34:40 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
    run.go:299: Retry Put of "sub dir/hello world" to Linkbox root 'rclone-test-wusoveh1hufi': 1/10 (Update second step failed: invalid character '<' looking for beginning of value)
2026/07/22 03:34:42 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:34:44 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:34:46 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:34:48 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:34:50 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:34:52 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:34:54 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:34:56 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:34:59 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 03:34:59 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:35:00 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 03:35:01 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:35:01 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-dudocic5jabi"
2026/07/22 03:35:01 DEBUG : Linkbox root 'rclone-test-dudocic5jabi': Using cached web token
    sync_test.go:656: Server side copy (if possible) Linkbox root 'rclone-test-wusoveh1hufi' -> Linkbox root 'rclone-test-dudocic5jabi'
2026/07/22 03:35:02 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:35:03 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:35:03 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/07/22 03:35:03 DEBUG : Linkbox root 'rclone-test-dudocic5jabi': Waiting for checks to finish
2026/07/22 03:35:03 DEBUG : Linkbox root 'rclone-test-dudocic5jabi': Waiting for transfers to finish
2026/07/22 03:35:03 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 03:35:08 DEBUG : sub dir/hello world: size = 11 OK
2026/07/22 03:35:08 INFO  : sub dir/hello world: Copied (new)
2026/07/22 03:35:09 DEBUG : sub dir/hello world: Update: removing old file
2026/07/22 03:35:13 DEBUG : Linkbox root 'rclone-test-dudocic5jabi': Waiting for checks to finish
2026/07/22 03:35:13 DEBUG : sub dir/hello world: size = 17 (Linkbox root 'rclone-test-wusoveh1hufi')
2026/07/22 03:35:13 DEBUG : sub dir/hello world: size = 11 (Linkbox root 'rclone-test-dudocic5jabi')
2026/07/22 03:35:13 DEBUG : sub dir/hello world: Sizes differ
2026/07/22 03:35:13 DEBUG : Linkbox root 'rclone-test-dudocic5jabi': Waiting for transfers to finish
2026/07/22 03:35:13 DEBUG : sub dir/hello world: Update: removing old file
2026/07/22 03:35:16 DEBUG : sub dir/hello world: size = 17 OK
2026/07/22 03:35:16 INFO  : sub dir/hello world: Copied (replaced existing)
2026/07/22 03:35:16 DEBUG : Linkbox root 'rclone-test-dudocic5jabi': Purge remote
    run.go:186: removing dir "sub dir" failed - try 1/3: sleeping 1s: directory not empty
--- PASS: TestServerSideCopyOverSelf (57.70s)
=== RUN   TestMoveOverSelf
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:35:26 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:35:27 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:35:27 DEBUG : sub dir/hello world: size = 17 (Local file system at /tmp/rclone1180572967)
2026/07/22 03:35:27 DEBUG : sub dir/hello world: size = 11 (Linkbox root 'rclone-test-wusoveh1hufi')
2026/07/22 03:35:27 DEBUG : sub dir/hello world: Sizes differ
2026/07/22 03:35:27 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:35:27 DEBUG : sub dir/hello world: Update: removing old file
2026/07/22 03:35:28 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:35:28 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:35:29 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:35:29 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:35:29 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:35:29 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:35:30 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:35:30 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:35:31 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:35:33 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:35:35 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:35:37 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:35:39 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:35:41 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:35:41 DEBUG : sub dir/hello world: Received error: Update err in unmarshaling response: invalid character '<' looking for beginning of value - low level retry 0/10
2026/07/22 03:35:43 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:35:45 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:35:47 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:35:49 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:35:52 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:35:54 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:35:56 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:35:58 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 03:35:59 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:35:59 DEBUG : sub dir/hello world: size = 17 OK
2026/07/22 03:35:59 INFO  : sub dir/hello world: Copied (replaced existing)
2026/07/22 03:35:59 INFO  : sub dir/hello world: Deleted
2026/07/22 03:35:59 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 03:36:00 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:36:01 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:36:01 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:36:02 DEBUG : pacer: Reducing sleep to 200ms
    run.go:186: removing dir "sub dir" failed - try 1/3: sleeping 1s: directory not empty
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
--- PASS: TestMoveOverSelf (50.87s)
=== RUN   TestServerSideMoveOverSelf
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:36:17 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-ciraruz8kofi"
2026/07/22 03:36:17 DEBUG : Linkbox root 'rclone-test-ciraruz8kofi': Using cached web token
    sync_test.go:701: Server side copy (if possible) Linkbox root 'rclone-test-wusoveh1hufi' -> Linkbox root 'rclone-test-ciraruz8kofi'
2026/07/22 03:36:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/07/22 03:36:19 DEBUG : Linkbox root 'rclone-test-ciraruz8kofi': Waiting for checks to finish
2026/07/22 03:36:19 DEBUG : Linkbox root 'rclone-test-ciraruz8kofi': Waiting for transfers to finish
2026/07/22 03:36:24 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:36:24 DEBUG : sub dir/hello world: size = 11 OK
2026/07/22 03:36:24 INFO  : sub dir/hello world: Copied (new)
2026/07/22 03:36:25 DEBUG : sub dir/hello world: Update: removing old file
2026/07/22 03:36:28 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:36:29 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:36:30 DEBUG : sub dir/hello world: size = 17 (Linkbox root 'rclone-test-wusoveh1hufi')
2026/07/22 03:36:30 DEBUG : sub dir/hello world: size = 11 (Linkbox root 'rclone-test-ciraruz8kofi')
2026/07/22 03:36:30 DEBUG : sub dir/hello world: Sizes differ
2026/07/22 03:36:30 DEBUG : Linkbox root 'rclone-test-ciraruz8kofi': Waiting for checks to finish
2026/07/22 03:36:30 DEBUG : Linkbox root 'rclone-test-ciraruz8kofi': Waiting for transfers to finish
2026/07/22 03:36:30 DEBUG : sub dir/hello world: Update: removing old file
2026/07/22 03:36:33 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:36:33 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:36:33 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:36:33 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:36:34 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:36:34 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:36:35 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:36:35 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:36:36 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:36:38 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:36:40 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:36:42 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:36:44 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:36:46 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:36:46 DEBUG : sub dir/hello world: Received error: Update failed to read object: getting files failed: invalid character '<' looking for beginning of value - low level retry 0/10
2026/07/22 03:36:48 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:36:50 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:36:52 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:36:54 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:36:54 DEBUG : sub dir/hello world: Update: removing old file
2026/07/22 03:36:57 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:36:58 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 03:37:00 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:37:00 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 03:37:00 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:37:01 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:37:01 DEBUG : sub dir/hello world: size = 17 OK
2026/07/22 03:37:01 INFO  : sub dir/hello world: Copied (replaced existing)
2026/07/22 03:37:03 INFO  : sub dir/hello world: Deleted
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
2026/07/22 03:37:11 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:37:12 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:37:14 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:37:14 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:37:14 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:37:15 DEBUG : testing file moves
2026/07/22 03:37:16 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 03:37:16 DEBUG : Linkbox root 'rclone-test-ciraruz8kofi': Waiting for checks to finish
2026/07/22 03:37:16 DEBUG : sub dir/hello world: size = 24 (Linkbox root 'rclone-test-wusoveh1hufi')
2026/07/22 03:37:16 DEBUG : sub dir/hello world: size = 17 (Linkbox root 'rclone-test-ciraruz8kofi')
2026/07/22 03:37:16 DEBUG : sub dir/hello world: Sizes differ
2026/07/22 03:37:16 DEBUG : Linkbox root 'rclone-test-ciraruz8kofi': Waiting for transfers to finish
2026/07/22 03:37:16 DEBUG : sub dir/hello world: Update: removing old file
2026/07/22 03:37:19 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:37:19 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:37:20 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:37:21 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 03:37:22 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 1.6s (5/10)
2026/07/22 03:37:23 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 3.2s (6/10)
2026/07/22 03:37:27 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 6.4s (7/10)
2026/07/22 03:37:33 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 12.8s (8/10)
2026/07/22 03:37:46 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:37:46 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:37:46 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:37:46 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:37:47 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:37:47 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:37:48 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:37:48 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:37:49 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:37:51 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:37:53 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:37:55 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:37:55 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 25.6s (9/10)
2026/07/22 03:38:21 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:38:21 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 51.2s (10/10)
2026/07/22 03:39:13 ERROR : sub dir/hello world: Failed to copy: object not found
2026/07/22 03:39:13 ERROR : sub dir/hello world: Not deleting source as copy failed: object not found
    sync_test.go:726: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:726
        	Error:      	Received unexpected error:
        	            	object not found
        	Test:       	TestServerSideMoveOverSelf
2026/07/22 03:39:13 DEBUG : Linkbox root 'rclone-test-ciraruz8kofi': Purge remote
2026/07/22 03:39:14 DEBUG : pacer: Reducing sleep to 843.75ms
    run.go:186: removing dir "sub dir" failed - try 1/3: sleeping 1s: directory not empty
--- FAIL: TestServerSideMoveOverSelf (185.44s)
=== RUN   TestCopyAfterDelete
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:39:22 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:39:23 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:39:23 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:39:24 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 03:39:25 ERROR : error listing: directory not found
2026/07/22 03:39:25 INFO  : Local file system at /tmp/rclone1180572967: Making directory
2026/07/22 03:39:26 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:39:26 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
    run.go:186: removing dir "sub dir" failed - try 1/3: sleeping 1s: directory not empty
--- PASS: TestCopyAfterDelete (12.10s)
=== RUN   TestCopyRedownload
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:39:34 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:39:34 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:39:34 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:39:34 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:39:35 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:39:35 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:39:36 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:39:36 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:39:37 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:39:39 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:39:41 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:39:43 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:39:45 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:39:47 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
    run.go:299: Retry Put of "sub dir/hello world" to Linkbox root 'rclone-test-wusoveh1hufi': 1/10 (Update failed to read object: getting files failed: invalid character '<' looking for beginning of value)
2026/07/22 03:39:49 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:39:51 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:39:53 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:39:55 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:39:57 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:39:57 DEBUG : sub dir/hello world: Update: removing old file
2026/07/22 03:40:01 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:40:01 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 03:40:03 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:40:03 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 03:40:03 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:40:04 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:40:04 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:40:05 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:40:05 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:40:05 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:40:05 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 03:40:06 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 03:40:06 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 1.6s (5/10)
2026/07/22 03:40:08 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 3.2s (6/10)
2026/07/22 03:40:11 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 6.4s (7/10)
2026/07/22 03:40:18 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 12.8s (8/10)
2026/07/22 03:40:31 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 25.6s (9/10)
2026/07/22 03:40:57 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:40:57 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:40:57 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:40:57 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:40:57 DEBUG : pacer: Reducing sleep to 600ms
2026/07/22 03:40:57 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 51.2s (10/10)
    run.go:303: Failed to put "sub dir/hello world" to "Linkbox root 'rclone-test-wusoveh1hufi'": object not found
2026/07/22 03:41:49 DEBUG : pacer: Reducing sleep to 450ms
2026/07/22 03:41:49 DEBUG : pacer: Reducing sleep to 337.5ms
2026/07/22 03:41:51 DEBUG : pacer: Reducing sleep to 253.125ms
2026/07/22 03:41:51 DEBUG : pacer: Reducing sleep to 200ms
    run.go:186: removing dir "sub dir" failed - try 1/3: sleeping 1s: directory not empty
    run.go:186: removing dir "sub dir" failed - try 2/3: sleeping 1.5s: directory not empty
--- FAIL: TestCopyRedownload (144.74s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:41:56 DEBUG : check sum: Need to transfer - File not found at Destination
2026/07/22 03:41:56 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:41:56 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:41:58 DEBUG : check sum: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:41:58 DEBUG : check sum: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:41:58 DEBUG : check sum: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:41:59 DEBUG : check sum: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 03:42:00 DEBUG : check sum: size = 1 OK
2026/07/22 03:42:00 INFO  : check sum: Copied (new)
2026/07/22 03:42:00 DEBUG : Waiting for deletions to finish
2026/07/22 03:42:01 DEBUG : check sum: size = 1 OK
2026/07/22 03:42:01 NOTICE: Linkbox root 'rclone-test-wusoveh1hufi': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2026/07/22 03:42:01 DEBUG : check sum: Size of src and dst objects identical
2026/07/22 03:42:01 DEBUG : check sum: Unchanged skipping
2026/07/22 03:42:01 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:42:01 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:42:01 DEBUG : Waiting for deletions to finish
2026/07/22 03:42:01 INFO  : There was nothing to transfer
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
--- PASS: TestSyncBasedOnCheckSum (14.69s)
=== RUN   TestSyncSizeOnly
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:42:10 DEBUG : sizeonly: Need to transfer - File not found at Destination
2026/07/22 03:42:10 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:42:10 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:42:12 DEBUG : sizeonly: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:42:13 DEBUG : sizeonly: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:42:13 DEBUG : sizeonly: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:42:14 DEBUG : sizeonly: size = 6 OK
2026/07/22 03:42:14 INFO  : sizeonly: Copied (new)
2026/07/22 03:42:14 DEBUG : Waiting for deletions to finish
2026/07/22 03:42:14 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:42:14 DEBUG : sizeonly: size = 6 OK
2026/07/22 03:42:14 DEBUG : sizeonly: Sizes identical
2026/07/22 03:42:14 DEBUG : sizeonly: Unchanged skipping
2026/07/22 03:42:14 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:42:14 DEBUG : Waiting for deletions to finish
2026/07/22 03:42:14 INFO  : There was nothing to transfer
--- PASS: TestSyncSizeOnly (5.86s)
=== RUN   TestSyncIgnoreSize
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:42:16 DEBUG : ignore-size: Need to transfer - File not found at Destination
2026/07/22 03:42:16 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:42:16 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:42:18 DEBUG : ignore-size: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:42:19 DEBUG : ignore-size: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:42:19 DEBUG : ignore-size: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:42:20 INFO  : ignore-size: Copied (new)
2026/07/22 03:42:20 DEBUG : Waiting for deletions to finish
2026/07/22 03:42:20 DEBUG : ignore-size: Sizes identical
2026/07/22 03:42:20 DEBUG : ignore-size: Unchanged skipping
2026/07/22 03:42:20 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:42:20 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:42:20 DEBUG : Waiting for deletions to finish
2026/07/22 03:42:20 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreSize (6.05s)
=== RUN   TestSyncIgnoreTimes
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:42:24 DEBUG : existing: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:42:24 DEBUG : existing: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:42:25 DEBUG : existing: size = 6 OK
2026/07/22 03:42:25 DEBUG : existing: Sizes identical
2026/07/22 03:42:25 DEBUG : existing: Unchanged skipping
2026/07/22 03:42:25 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:42:25 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:42:25 DEBUG : Waiting for deletions to finish
2026/07/22 03:42:25 INFO  : There was nothing to transfer
2026/07/22 03:42:25 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:42:25 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2026/07/22 03:42:25 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:42:25 DEBUG : existing: Update: removing old file
2026/07/22 03:42:29 DEBUG : existing: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:42:29 DEBUG : existing: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:42:29 DEBUG : existing: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:42:30 DEBUG : existing: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 03:42:31 DEBUG : existing: Trying to read object after upload: try again in 1.6s (5/10)
2026/07/22 03:42:33 DEBUG : existing: Trying to read object after upload: try again in 3.2s (6/10)
2026/07/22 03:42:36 DEBUG : existing: Trying to read object after upload: try again in 6.4s (7/10)
2026/07/22 03:42:43 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:42:43 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:42:43 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:42:43 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:42:43 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:42:43 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:42:44 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:42:44 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:42:46 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:42:48 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:42:50 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:42:52 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:42:54 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:42:56 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:42:56 DEBUG : existing: Received error: Update failed to read object: getting files failed: invalid character '<' looking for beginning of value - low level retry 0/10
2026/07/22 03:42:58 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:43:00 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:43:02 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:43:04 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 03:43:05 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:43:05 DEBUG : existing: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:43:05 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 03:43:05 DEBUG : existing: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:43:06 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:43:06 DEBUG : existing: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:43:07 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:43:07 DEBUG : existing: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 03:43:08 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:43:08 DEBUG : existing: Trying to read object after upload: try again in 1.6s (5/10)
2026/07/22 03:43:10 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 03:43:10 DEBUG : existing: Trying to read object after upload: try again in 3.2s (6/10)
2026/07/22 03:43:13 DEBUG : existing: Trying to read object after upload: try again in 6.4s (7/10)
2026/07/22 03:43:20 DEBUG : existing: Trying to read object after upload: try again in 12.8s (8/10)
2026/07/22 03:43:33 DEBUG : existing: Trying to read object after upload: try again in 25.6s (9/10)
2026/07/22 03:43:58 DEBUG : existing: Trying to read object after upload: try again in 51.2s (10/10)
2026/07/22 03:44:50 ERROR : existing: Failed to copy: object not found
2026/07/22 03:44:50 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': not deleting files as there were IO errors
2026/07/22 03:44:50 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': not deleting directories as there were IO errors
    sync_test.go:905: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:905
        	Error:      	Received unexpected error:
        	            	object not found
        	Test:       	TestSyncIgnoreTimes
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
--- FAIL: TestSyncIgnoreTimes (158.21s)
=== RUN   TestSyncIgnoreExisting
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:45:01 DEBUG : existing: Need to transfer - File not found at Destination
2026/07/22 03:45:01 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:45:01 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:45:03 DEBUG : existing: size = 6 OK
2026/07/22 03:45:03 INFO  : existing: Copied (new)
2026/07/22 03:45:03 DEBUG : Waiting for deletions to finish
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
2026/07/22 03:45:11 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:45:11 DEBUG : existing: Destination exists, skipping
2026/07/22 03:45:11 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:45:11 DEBUG : Waiting for deletions to finish
2026/07/22 03:45:11 INFO  : There was nothing to transfer
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
--- PASS: TestSyncIgnoreExisting (19.80s)
=== RUN   TestSyncIgnoreErrors
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:45:24 DEBUG : b/potato: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:45:28 DEBUG : c/non empty space: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:45:28 DEBUG : c/non empty space: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:45:28 INFO  : d: Making directory
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
2026/07/22 03:45:39 DEBUG : a/potato2: Need to transfer - File not found at Destination
2026/07/22 03:45:40 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:45:40 DEBUG : c/non empty space: size = 5 OK
2026/07/22 03:45:40 DEBUG : c/non empty space: Sizes identical
2026/07/22 03:45:40 DEBUG : c/non empty space: Unchanged skipping
2026/07/22 03:45:40 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:45:41 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:45:41 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:45:41 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:45:41 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:45:42 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:45:42 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:45:43 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:45:43 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:45:44 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:45:46 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:45:48 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:45:50 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:45:52 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:45:54 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:45:54 DEBUG : a/potato2: Received error: Update err in unmarshaling response: invalid character '<' looking for beginning of value - low level retry 0/10
2026/07/22 03:45:56 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:45:58 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:46:00 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:46:02 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:46:04 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:46:07 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 03:46:07 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:46:07 DEBUG : a/potato2: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:46:08 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 03:46:08 DEBUG : a/potato2: size = 60 OK
2026/07/22 03:46:08 INFO  : a/potato2: Copied (new)
2026/07/22 03:46:08 DEBUG : Waiting for deletions to finish
2026/07/22 03:46:10 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:46:10 INFO  : b/potato: Deleted
2026/07/22 03:46:10 INFO  : d: Removing directory
2026/07/22 03:46:10 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:46:12 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:46:12 INFO  : b: Removing directory
2026/07/22 03:46:12 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 03:46:13 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': deleted 2 directories
--- PASS: TestSyncIgnoreErrors (60.05s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:46:22 DEBUG : empty space: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:46:23 DEBUG : empty space: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:46:23 DEBUG : empty space: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:46:24 DEBUG : empty space: size = 1 OK
2026/07/22 03:46:24 DEBUG : empty space: Sizes identical
2026/07/22 03:46:24 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:46:24 DEBUG : empty space: Unchanged skipping
2026/07/22 03:46:24 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:46:24 DEBUG : Waiting for deletions to finish
2026/07/22 03:46:24 INFO  : There was nothing to transfer
2026/07/22 03:46:25 DEBUG : empty space: size = 1 OK
2026/07/22 03:46:25 DEBUG : empty space: Sizes identical
2026/07/22 03:46:25 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:46:25 DEBUG : empty space: Unchanged skipping
2026/07/22 03:46:25 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:46:25 DEBUG : Waiting for deletions to finish
2026/07/22 03:46:25 INFO  : There was nothing to transfer
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
--- PASS: TestSyncAfterChangingModtimeOnly (13.92s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:1046: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.41s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:1072: Can't run this test on fs which doesn't support mod time
--- SKIP: TestSyncDoesntUpdateModtime (0.51s)
=== RUN   TestSyncAfterAddingAFile
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:46:38 DEBUG : empty space: size = 1 OK
2026/07/22 03:46:38 DEBUG : empty space: Sizes identical
2026/07/22 03:46:38 DEBUG : potato: Need to transfer - File not found at Destination
2026/07/22 03:46:38 DEBUG : empty space: Unchanged skipping
2026/07/22 03:46:38 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:46:38 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:46:38 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:46:38 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:46:38 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:46:38 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:46:38 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:46:38 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:46:39 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:46:39 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:46:41 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:46:43 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:46:45 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:46:47 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:46:49 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:46:51 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:46:53 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:46:55 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:46:57 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:46:59 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:47:01 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:47:03 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:47:06 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:47:06 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 03:47:06 DEBUG : potato: size = 60 OK
2026/07/22 03:47:06 INFO  : potato: Copied (new)
2026/07/22 03:47:06 DEBUG : Waiting for deletions to finish
2026/07/22 03:47:07 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:47:08 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 03:47:10 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:47:11 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:47:11 DEBUG : pacer: Reducing sleep to 200.225829ms
--- PASS: TestSyncAfterAddingAFile (36.39s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:47:12 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 03:47:14 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:47:14 DEBUG : potato: size = 21 (Local file system at /tmp/rclone1180572967)
2026/07/22 03:47:14 DEBUG : potato: size = 60 (Linkbox root 'rclone-test-wusoveh1hufi')
2026/07/22 03:47:14 DEBUG : potato: Sizes differ
2026/07/22 03:47:14 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:47:14 DEBUG : potato: Update: removing old file
2026/07/22 03:47:17 DEBUG : potato: size = 21 OK
2026/07/22 03:47:17 INFO  : potato: Copied (replaced existing)
2026/07/22 03:47:17 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncAfterChangingFilesSizeOnly (7.81s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:1136: ModTimeNotSupported so forcing file to be a different size
2026/07/22 03:47:22 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:47:22 DEBUG : potato: size = 21 (Local file system at /tmp/rclone1180572967)
2026/07/22 03:47:22 DEBUG : potato: size = 36 (Linkbox root 'rclone-test-wusoveh1hufi')
2026/07/22 03:47:22 DEBUG : potato: Sizes differ
2026/07/22 03:47:22 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:47:22 DEBUG : potato: Update: removing old file
2026/07/22 03:47:25 DEBUG : potato: size = 21 OK
2026/07/22 03:47:25 INFO  : potato: Copied (replaced existing)
2026/07/22 03:47:25 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncAfterChangingContentsOnly (7.46s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:47:31 DEBUG : potato2: Need to transfer - File not found at Destination
2026/07/22 03:47:31 DEBUG : empty space: size = 1 OK
2026/07/22 03:47:31 DEBUG : empty space: Sizes identical
2026/07/22 03:47:31 DEBUG : empty space: Unchanged skipping
2026/07/22 03:47:31 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2026/07/22 03:47:31 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:47:31 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:47:31 DEBUG : Waiting for deletions to finish
2026/07/22 03:47:31 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (7.58s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:47:37 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:47:37 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:47:37 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:47:37 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:47:37 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:47:37 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:47:38 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:47:38 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:47:40 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:47:42 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:47:44 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:47:46 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:47:48 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:47:50 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
    run.go:299: Retry Put of "empty space" to Linkbox root 'rclone-test-wusoveh1hufi': 1/10 (Update err in unmarshaling response: invalid character '<' looking for beginning of value)
2026/07/22 03:47:52 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:47:54 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:47:56 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:47:58 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:48:00 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:48:02 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:48:04 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:48:06 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:48:08 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 03:48:09 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:48:09 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 03:48:10 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:48:10 DEBUG : potato2: Need to transfer - File not found at Destination
2026/07/22 03:48:10 DEBUG : empty space: size = 1 OK
2026/07/22 03:48:10 DEBUG : empty space: Sizes identical
2026/07/22 03:48:10 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:48:10 DEBUG : empty space: Unchanged skipping
2026/07/22 03:48:10 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:48:11 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:48:11 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:48:12 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 03:48:13 DEBUG : potato2: size = 60 OK
2026/07/22 03:48:13 INFO  : potato2: Copied (new)
2026/07/22 03:48:13 DEBUG : Waiting for deletions to finish
2026/07/22 03:48:14 INFO  : potato: Deleted
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (42.82s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:48:24 INFO  : d: Making directory
2026/07/22 03:48:26 INFO  : d/e: Making directory
2026/07/22 03:48:28 DEBUG : a/potato2: Need to transfer - File not found at Destination
2026/07/22 03:48:29 DEBUG : c/non empty space: size = 5 OK
2026/07/22 03:48:29 DEBUG : c/non empty space: Sizes identical
2026/07/22 03:48:29 DEBUG : c/non empty space: Unchanged skipping
2026/07/22 03:48:31 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:48:31 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:48:33 DEBUG : a/potato2: size = 60 OK
2026/07/22 03:48:33 INFO  : a/potato2: Copied (new)
2026/07/22 03:48:33 DEBUG : Waiting for deletions to finish
2026/07/22 03:48:34 INFO  : b/potato: Deleted
2026/07/22 03:48:34 INFO  : d/e: Removing directory
2026/07/22 03:48:36 INFO  : d: Removing directory
2026/07/22 03:48:37 INFO  : b: Removing directory
2026/07/22 03:48:39 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': deleted 3 directories
2026/07/22 03:48:39 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:48:39 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:48:39 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:48:39 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:48:39 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:48:39 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:48:40 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:48:40 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:48:42 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:48:44 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:48:46 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:48:48 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:48:50 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:48:52 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:48:52 ERROR : error listing: getting files failed: invalid character '<' looking for beginning of value
    fstest.go:282: Error listing: getting files failed: invalid character '<' looking for beginning of value
2026/07/22 03:48:54 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:48:56 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:48:58 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:49:00 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:49:02 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:49:04 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:49:06 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:49:07 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 03:49:10 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:49:11 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 03:49:11 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:49:13 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:49:13 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:49:14 DEBUG : pacer: Reducing sleep to 200ms
--- FAIL: TestSyncAfterRemovingAFileAndAddingAFileSubDir (57.48s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:49:22 INFO  : d: Making directory
2026/07/22 03:49:25 DEBUG : a/potato2: Need to transfer - File not found at Destination
2026/07/22 03:49:25 DEBUG : c/non empty space: size = 5 OK
2026/07/22 03:49:25 DEBUG : c/non empty space: Sizes identical
2026/07/22 03:49:25 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:49:25 DEBUG : c/non empty space: Unchanged skipping
2026/07/22 03:49:25 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:49:29 DEBUG : a/potato2: size = 60 OK
2026/07/22 03:49:29 INFO  : a/potato2: Copied (new)
2026/07/22 03:49:29 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': not deleting files as there were IO errors
2026/07/22 03:49:29 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': not deleting directories as there were IO errors
2026/07/22 03:49:40 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:49:40 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:49:40 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:49:40 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:49:40 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:49:40 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:49:41 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:49:41 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:49:43 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:49:45 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:49:47 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:49:49 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:49:51 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:49:53 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
    run.go:186: removing dir "a" failed - try 1/3: sleeping 1s: purge error: invalid character '<' looking for beginning of value
2026/07/22 03:49:55 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:49:57 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:49:59 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:50:01 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:50:03 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:50:05 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:50:08 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:50:09 DEBUG : pacer: Reducing sleep to 843.75ms
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (53.91s)
=== RUN   TestSyncDeleteDuring
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:50:10 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:50:11 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 03:50:12 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:50:12 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:50:13 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:50:13 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 03:50:15 DEBUG : Waiting for deletions to finish
2026/07/22 03:50:15 DEBUG : potato2: Need to transfer - File not found at Destination
2026/07/22 03:50:15 DEBUG : empty space: size = 1 OK
2026/07/22 03:50:15 DEBUG : empty space: Sizes identical
2026/07/22 03:50:15 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:50:15 DEBUG : empty space: Unchanged skipping
2026/07/22 03:50:15 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:50:16 INFO  : potato: Deleted
2026/07/22 03:50:17 DEBUG : potato2: size = 60 OK
2026/07/22 03:50:17 INFO  : potato2: Copied (new)
--- PASS: TestSyncDeleteDuring (12.25s)
=== RUN   TestSyncDeleteBefore
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:50:25 DEBUG : Waiting for deletions to finish
2026/07/22 03:50:25 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:50:25 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:50:27 INFO  : potato: Deleted
2026/07/22 03:50:27 DEBUG : potato2: Need to transfer - File not found at Destination
2026/07/22 03:50:27 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:50:27 DEBUG : empty space: size = 1 OK
2026/07/22 03:50:27 DEBUG : empty space: Sizes identical
2026/07/22 03:50:27 DEBUG : empty space: Unchanged skipping
2026/07/22 03:50:27 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:50:29 DEBUG : potato2: size = 60 OK
2026/07/22 03:50:29 INFO  : potato2: Copied (new)
--- PASS: TestSyncDeleteBefore (11.22s)
=== RUN   TestCopyDeleteBefore
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:50:35 DEBUG : potato2: Need to transfer - File not found at Destination
2026/07/22 03:50:35 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:50:35 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:50:36 DEBUG : potato2: size = 19 OK
2026/07/22 03:50:36 INFO  : potato2: Copied (new)
2026/07/22 03:50:37 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:50:37 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:50:37 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:50:37 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:50:38 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:50:38 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:50:38 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:50:38 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:50:40 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:50:42 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:50:44 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:50:46 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:50:48 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:50:50 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
    run.go:172: removing file "potato" failed - try 1/3: sleeping 1s: could not Remove: invalid character '<' looking for beginning of value
2026/07/22 03:50:52 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:50:54 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:50:56 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:50:58 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:51:00 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:51:02 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:51:05 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:51:07 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:51:08 DEBUG : pacer: Reducing sleep to 843.75ms
--- PASS: TestCopyDeleteBefore (35.63s)
=== RUN   TestSyncWithExclude
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:51:09 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:51:10 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 03:51:11 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:51:12 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:51:12 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:51:12 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 03:51:14 DEBUG : enormous: Excluded (Size Filter)
2026/07/22 03:51:14 DEBUG : enormous: Excluded
2026/07/22 03:51:14 DEBUG : potato2: Excluded (Size Filter)
2026/07/22 03:51:14 DEBUG : potato2: Excluded
2026/07/22 03:51:14 DEBUG : potato2: Excluded (Size Filter)
2026/07/22 03:51:14 DEBUG : potato2: Excluded
2026/07/22 03:51:14 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:51:14 DEBUG : empty space: size = 1 OK
2026/07/22 03:51:14 DEBUG : empty space: Sizes identical
2026/07/22 03:51:14 DEBUG : empty space: Unchanged skipping
2026/07/22 03:51:14 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:51:14 DEBUG : Waiting for deletions to finish
2026/07/22 03:51:14 INFO  : There was nothing to transfer
2026/07/22 03:51:15 DEBUG : enormous: Excluded (Size Filter)
2026/07/22 03:51:15 DEBUG : enormous: Excluded
2026/07/22 03:51:15 DEBUG : potato2: Excluded (Size Filter)
2026/07/22 03:51:15 DEBUG : potato2: Excluded
2026/07/22 03:51:15 DEBUG : potato2: Excluded (Size Filter)
2026/07/22 03:51:15 DEBUG : potato2: Excluded
2026/07/22 03:51:15 DEBUG : Local file system at /tmp/rclone1180572967: Waiting for checks to finish
2026/07/22 03:51:15 DEBUG : empty space: size = 1 OK
2026/07/22 03:51:15 DEBUG : empty space: Sizes identical
2026/07/22 03:51:15 DEBUG : empty space: Unchanged skipping
2026/07/22 03:51:15 DEBUG : Local file system at /tmp/rclone1180572967: Waiting for transfers to finish
2026/07/22 03:51:15 DEBUG : Waiting for deletions to finish
2026/07/22 03:51:15 INFO  : There was nothing to transfer
--- PASS: TestSyncWithExclude (10.19s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:51:24 DEBUG : enormous: Excluded (Size Filter)
2026/07/22 03:51:24 DEBUG : enormous: Excluded
2026/07/22 03:51:24 DEBUG : potato2: Excluded (Size Filter)
2026/07/22 03:51:24 DEBUG : potato2: Excluded
2026/07/22 03:51:24 DEBUG : empty space: size = 1 OK
2026/07/22 03:51:24 DEBUG : empty space: Sizes identical
2026/07/22 03:51:24 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:51:24 DEBUG : empty space: Unchanged skipping
2026/07/22 03:51:24 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:51:24 DEBUG : Waiting for deletions to finish
2026/07/22 03:51:26 INFO  : potato2: Deleted
2026/07/22 03:51:26 INFO  : enormous: Deleted
2026/07/22 03:51:26 INFO  : There was nothing to transfer
2026/07/22 03:51:26 DEBUG : empty space: size = 1 OK
2026/07/22 03:51:26 DEBUG : empty space: Sizes identical
2026/07/22 03:51:26 DEBUG : empty space: Unchanged skipping
2026/07/22 03:51:26 DEBUG : Local file system at /tmp/rclone1180572967: Waiting for checks to finish
2026/07/22 03:51:26 DEBUG : Local file system at /tmp/rclone1180572967: Waiting for transfers to finish
2026/07/22 03:51:26 DEBUG : Waiting for deletions to finish
2026/07/22 03:51:26 INFO  : enormous: Deleted
2026/07/22 03:51:26 INFO  : potato2: Deleted
2026/07/22 03:51:26 INFO  : There was nothing to transfer
--- PASS: TestSyncWithExcludeAndDeleteExcluded (10.19s)
=== RUN   TestSyncWithUpdateOlder
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:1454: Can't run this test on fs which doesn't support mod time
--- SKIP: TestSyncWithUpdateOlder (0.57s)
=== RUN   TestSyncWithTrackRenames
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:1569: Can track renames: false
2026/07/22 03:51:29 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': Ignoring --track-renames as the destination does not support server-side move or copy
2026/07/22 03:51:29 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': Ignoring --track-renames as the source and destination do not have a common hash
2026/07/22 03:51:29 DEBUG : potato: Need to transfer - File not found at Destination
2026/07/22 03:51:29 DEBUG : yam: Need to transfer - File not found at Destination
2026/07/22 03:51:29 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:51:29 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:51:31 DEBUG : potato: size = 14 OK
2026/07/22 03:51:31 INFO  : potato: Copied (new)
2026/07/22 03:51:31 DEBUG : yam: size = 11 OK
2026/07/22 03:51:31 INFO  : yam: Copied (new)
2026/07/22 03:51:31 DEBUG : Waiting for deletions to finish
2026/07/22 03:51:32 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': Ignoring --track-renames as the destination does not support server-side move or copy
2026/07/22 03:51:32 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': Ignoring --track-renames as the source and destination do not have a common hash
2026/07/22 03:51:32 DEBUG : yaml: Need to transfer - File not found at Destination
2026/07/22 03:51:32 DEBUG : potato: size = 14 OK
2026/07/22 03:51:32 DEBUG : potato: Sizes identical
2026/07/22 03:51:32 DEBUG : potato: Unchanged skipping
2026/07/22 03:51:32 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:51:32 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:51:34 DEBUG : yaml: size = 11 OK
2026/07/22 03:51:34 INFO  : yaml: Copied (new)
2026/07/22 03:51:34 DEBUG : Waiting for deletions to finish
2026/07/22 03:51:35 INFO  : yam: Deleted
2026/07/22 03:51:35 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:51:35 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:51:36 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:51:36 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:51:36 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:51:36 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:51:37 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:51:37 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:51:38 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:51:40 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:51:42 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:51:44 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:51:46 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:51:48 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:51:48 ERROR : error listing: getting files failed: invalid character '<' looking for beginning of value
    run.go:182: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:182
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:406
        	            				/usr/local/go/src/testing/testing.go:1317
        	            				/usr/local/go/src/testing/testing.go:1667
        	            				/usr/local/go/src/testing/testing.go:2030
        	            				/usr/local/go/src/runtime/asm_amd64.s:1771
        	Error:      	Received unexpected error:
        	            	getting files failed: invalid character '<' looking for beginning of value
        	Test:       	TestSyncWithTrackRenames
--- FAIL: TestSyncWithTrackRenames (19.82s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:1641: Can track renames: false
2026/07/22 03:51:48 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': Ignoring --track-renames as the destination does not support server-side move or copy
2026/07/22 03:51:48 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': Ignoring --track-renames as either the source or destination do not support modtime
2026/07/22 03:51:50 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:51:52 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:51:54 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:51:56 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:51:58 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:52:00 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:52:02 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:52:05 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:52:05 DEBUG : potato: size = 14 OK
2026/07/22 03:52:05 DEBUG : potato: Sizes identical
2026/07/22 03:52:05 DEBUG : yam: Need to transfer - File not found at Destination
2026/07/22 03:52:05 DEBUG : potato: Unchanged skipping
2026/07/22 03:52:05 DEBUG : yaml: size = 11 OK
2026/07/22 03:52:05 DEBUG : yaml: Sizes identical
2026/07/22 03:52:05 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:52:05 DEBUG : yaml: Unchanged skipping
2026/07/22 03:52:05 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:52:07 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:52:08 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 03:52:10 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:52:11 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 03:52:11 DEBUG : yam: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:52:11 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:52:11 DEBUG : yam: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:52:12 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:52:12 DEBUG : yam: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:52:12 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:52:12 DEBUG : yam: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 03:52:13 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 03:52:13 DEBUG : yam: Trying to read object after upload: try again in 1.6s (5/10)
2026/07/22 03:52:15 DEBUG : yam: Trying to read object after upload: try again in 3.2s (6/10)
2026/07/22 03:52:19 DEBUG : yam: Trying to read object after upload: try again in 6.4s (7/10)
2026/07/22 03:52:25 DEBUG : yam: Trying to read object after upload: try again in 12.8s (8/10)
2026/07/22 03:52:38 DEBUG : yam: Trying to read object after upload: try again in 25.6s (9/10)
2026/07/22 03:53:04 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:53:04 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:53:04 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:53:04 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:53:04 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:53:04 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:53:05 DEBUG : pacer: Reducing sleep to 1.2s
2026/07/22 03:53:05 DEBUG : yam: Trying to read object after upload: try again in 51.2s (10/10)
2026/07/22 03:53:57 ERROR : yam: Failed to copy: object not found
2026/07/22 03:53:57 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': not deleting files as there were IO errors
2026/07/22 03:53:57 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': not deleting directories as there were IO errors
    sync_test.go:1648: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1648
        	Error:      	Received unexpected error:
        	            	object not found
        	Test:       	TestSyncWithTrackRenamesStrategyModtime
2026/07/22 03:53:57 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:53:57 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:53:58 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:54:00 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:54:02 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:54:04 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:54:06 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:54:09 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:54:11 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 03:54:12 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:54:12 DEBUG : pacer: Reducing sleep to 474.609375ms
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
2026/07/22 03:54:14 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:54:14 DEBUG : pacer: Reducing sleep to 266.967773ms
    fstest.go:292: Sleeping for 6s just to make sure
--- FAIL: TestSyncWithTrackRenamesStrategyModtime (151.42s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:1680: Can track renames: false
2026/07/22 03:54:20 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': Ignoring --track-renames as the destination does not support server-side move or copy
2026/07/22 03:54:20 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:54:20 DEBUG : potato: Need to transfer - File not found at Destination
2026/07/22 03:54:20 DEBUG : sub/yam: Need to transfer - File not found at Destination
2026/07/22 03:54:20 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:54:20 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:54:20 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 03:54:24 DEBUG : potato: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:54:25 DEBUG : potato: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:54:25 DEBUG : sub/yam: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:54:25 DEBUG : potato: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:54:25 DEBUG : sub/yam: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:54:26 DEBUG : sub/yam: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:54:26 DEBUG : potato: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 03:54:26 DEBUG : sub/yam: size = 11 OK
2026/07/22 03:54:26 INFO  : sub/yam: Copied (new)
2026/07/22 03:54:27 DEBUG : potato: size = 14 OK
2026/07/22 03:54:27 INFO  : potato: Copied (new)
2026/07/22 03:54:27 DEBUG : Waiting for deletions to finish
2026/07/22 03:54:27 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': Ignoring --track-renames as the destination does not support server-side move or copy
2026/07/22 03:54:27 DEBUG : potato: size = 14 OK
2026/07/22 03:54:27 DEBUG : potato: Sizes identical
2026/07/22 03:54:27 DEBUG : yam: Need to transfer - File not found at Destination
2026/07/22 03:54:27 DEBUG : potato: Unchanged skipping
2026/07/22 03:54:28 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:54:28 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:54:30 DEBUG : yam: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:54:30 DEBUG : yam: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:54:30 DEBUG : yam: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:54:31 DEBUG : yam: size = 11 OK
2026/07/22 03:54:31 INFO  : yam: Copied (new)
2026/07/22 03:54:31 DEBUG : Waiting for deletions to finish
2026/07/22 03:54:32 INFO  : sub/yam: Deleted
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
2026/07/22 03:54:44 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:54:44 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:54:44 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:54:44 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:54:44 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:54:44 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:54:45 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:54:45 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:54:47 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:54:49 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:54:51 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:54:53 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:54:55 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:54:57 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
    run.go:186: removing dir "sub" failed - try 1/3: sleeping 1s: purge error: invalid character '<' looking for beginning of value
2026/07/22 03:54:59 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:55:01 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:55:03 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:55:05 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:55:07 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:55:10 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:55:10 DEBUG : pacer: Reducing sleep to 843.75ms
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (50.61s)
=== RUN   TestServerSideMoveLocal
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:55:10 DEBUG : Creating backend with remote "/tmp/rclone1180572967/dir1"
2026/07/22 03:55:10 DEBUG : Config file has changed externally - reloading
2026/07/22 03:55:10 DEBUG : Creating backend with remote "/tmp/rclone1180572967/dir2"
2026/07/22 03:55:10 DEBUG : Local file system at /tmp/rclone1180572967/dir2: Using server-side directory move
2026/07/22 03:55:10 INFO  : Local file system at /tmp/rclone1180572967/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2026/07/22 03:55:10 DEBUG : file1.txt: Need to transfer - File not found at Destination
2026/07/22 03:55:10 DEBUG : Local file system at /tmp/rclone1180572967/dir2: Waiting for checks to finish
2026/07/22 03:55:10 DEBUG : Local file system at /tmp/rclone1180572967/dir2: Waiting for transfers to finish
2026/07/22 03:55:10 INFO  : file1.txt: Moved (server-side)
2026/07/22 03:55:12 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:55:12 DEBUG : pacer: Reducing sleep to 474.609375ms
--- PASS: TestServerSideMoveLocal (1.97s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:55:13 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:55:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/07/22 03:55:13 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2026/07/22 03:55:13 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:55:13 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:55:13 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:55:15 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:55:15 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 03:55:20 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:55:20 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:55:21 DEBUG : sub dir/hello world: size = 11 OK
2026/07/22 03:55:21 INFO  : sub dir/hello world: Copied (new)
2026/07/22 03:55:21 INFO  : sub dir/hello world: Deleted
2026/07/22 03:55:21 DEBUG : nested/sub dir/file: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:55:21 DEBUG : nested/sub dir/file: size = 6 OK
2026/07/22 03:55:21 INFO  : nested/sub dir/file: Copied (new)
2026/07/22 03:55:21 INFO  : nested/sub dir/file: Deleted
2026/07/22 03:55:21 INFO  : sub dir: Removing directory
2026/07/22 03:55:21 INFO  : nested/sub dir: Removing directory
2026/07/22 03:55:21 INFO  : nested: Removing directory
2026/07/22 03:55:21 DEBUG : Local file system at /tmp/rclone1180572967: deleted 3 directories
    run.go:186: removing dir "sub dir" failed - try 1/3: sleeping 1s: directory not empty
--- PASS: TestMoveWithDeleteEmptySrcDirs (19.50s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:55:32 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/07/22 03:55:32 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2026/07/22 03:55:32 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:55:32 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:55:39 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:55:39 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:55:39 DEBUG : nested/sub dir/file: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:55:40 DEBUG : sub dir/hello world: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:55:40 DEBUG : nested/sub dir/file: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:55:40 DEBUG : sub dir/hello world: size = 11 OK
2026/07/22 03:55:40 INFO  : sub dir/hello world: Copied (new)
2026/07/22 03:55:40 INFO  : sub dir/hello world: Deleted
2026/07/22 03:55:40 DEBUG : nested/sub dir/file: size = 6 OK
2026/07/22 03:55:40 INFO  : nested/sub dir/file: Copied (new)
2026/07/22 03:55:40 INFO  : nested/sub dir/file: Deleted
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
2026/07/22 03:55:43 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:55:43 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:55:43 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:55:43 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:55:44 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:55:44 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:55:44 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:55:44 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:55:46 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:55:48 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:55:50 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:55:52 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:55:54 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:55:56 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:55:56 ERROR : nested: error listing: getting files failed: invalid character '<' looking for beginning of value
    fstest.go:282: Error listing: getting files failed: invalid character '<' looking for beginning of value
2026/07/22 03:55:58 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:56:00 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:56:02 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:56:04 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:56:06 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:56:08 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:56:10 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:56:12 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 03:56:14 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:56:14 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 03:56:16 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:56:16 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:56:18 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:56:18 DEBUG : pacer: Reducing sleep to 200ms
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
--- FAIL: TestMoveWithoutDeleteEmptySrcDirs (57.12s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:56:29 DEBUG : existing-b: Need to transfer - File not found at Destination
2026/07/22 03:56:29 DEBUG : existing: Need to transfer - File not found at Destination
2026/07/22 03:56:29 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:56:29 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:56:32 DEBUG : existing-b: size = 6 OK
2026/07/22 03:56:32 INFO  : existing-b: Copied (new)
2026/07/22 03:56:32 INFO  : existing-b: Deleted
2026/07/22 03:56:32 DEBUG : existing: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:56:32 DEBUG : existing: size = 6 OK
2026/07/22 03:56:32 INFO  : existing: Copied (new)
2026/07/22 03:56:32 INFO  : existing: Deleted
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
2026/07/22 03:56:40 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 03:56:40 DEBUG : existing: Destination exists, skipping
2026/07/22 03:56:40 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2026/07/22 03:56:40 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 03:56:40 INFO  : There was nothing to transfer
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
--- PASS: TestMoveWithIgnoreExisting (22.34s)
=== RUN   TestServerSideMove
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:56:51 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-moxunow8hinu"
2026/07/22 03:56:51 DEBUG : Linkbox root 'rclone-test-moxunow8hinu': Using cached web token
2026/07/22 03:56:54 DEBUG : potato2: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:56:57 DEBUG : empty space: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:56:57 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:56:57 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:56:57 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:56:57 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:56:57 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:56:57 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:56:58 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:56:58 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:57:00 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:57:02 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:57:04 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:57:06 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:57:08 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 03:57:10 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 03:57:12 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 03:57:14 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 03:57:14 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 03:57:14 DEBUG : potato3: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:57:15 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 03:57:15 DEBUG : potato3: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:57:15 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 03:57:15 DEBUG : potato3: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:57:16 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 03:57:16 DEBUG : potato3: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 03:57:17 DEBUG : pacer: Reducing sleep to 200ms
    sync_test.go:1736: Server side move (if possible) Linkbox root 'rclone-test-wusoveh1hufi' -> Linkbox root 'rclone-test-moxunow8hinu'
2026/07/22 03:57:21 DEBUG : empty space: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:57:23 DEBUG : potato3: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:57:23 DEBUG : potato3: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:57:24 DEBUG : potato3: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:57:24 DEBUG : potato3: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 03:57:25 DEBUG : potato3: Trying to read object after upload: try again in 1.6s (5/10)
2026/07/22 03:57:28 DEBUG : potato2: Need to transfer - File not found at Destination
2026/07/22 03:57:28 DEBUG : empty space: size = 1 OK
2026/07/22 03:57:28 DEBUG : empty space: Sizes identical
2026/07/22 03:57:28 DEBUG : empty space: Unchanged skipping
2026/07/22 03:57:28 DEBUG : potato3: size = 68 (Linkbox root 'rclone-test-wusoveh1hufi')
2026/07/22 03:57:28 DEBUG : potato3: size = 60 (Linkbox root 'rclone-test-moxunow8hinu')
2026/07/22 03:57:28 DEBUG : potato3: Sizes differ
2026/07/22 03:57:28 DEBUG : Linkbox root 'rclone-test-moxunow8hinu': Waiting for checks to finish
2026/07/22 03:57:28 DEBUG : potato3: Update: removing old file
2026/07/22 03:57:29 INFO  : empty space: Deleted
2026/07/22 03:57:29 DEBUG : Linkbox root 'rclone-test-moxunow8hinu': Waiting for transfers to finish
2026/07/22 03:57:30 DEBUG : potato2: size = 60 OK
2026/07/22 03:57:30 INFO  : potato2: Copied (new)
2026/07/22 03:57:31 DEBUG : potato3: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:57:32 INFO  : potato2: Deleted
2026/07/22 03:57:32 DEBUG : potato3: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:57:32 DEBUG : potato3: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:57:33 DEBUG : potato3: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 03:57:34 DEBUG : potato3: Trying to read object after upload: try again in 1.6s (5/10)
2026/07/22 03:57:36 DEBUG : potato3: Trying to read object after upload: try again in 3.2s (6/10)
2026/07/22 03:57:39 DEBUG : potato3: Trying to read object after upload: try again in 6.4s (7/10)
2026/07/22 03:57:46 DEBUG : potato3: Trying to read object after upload: try again in 12.8s (8/10)
2026/07/22 03:57:59 DEBUG : potato3: Trying to read object after upload: try again in 25.6s (9/10)
2026/07/22 03:58:24 DEBUG : potato3: Trying to read object after upload: try again in 51.2s (10/10)
2026/07/22 03:59:16 ERROR : potato3: Failed to copy: object not found
2026/07/22 03:59:16 ERROR : potato3: Not deleting source as copy failed: object not found
    sync_test.go:1747: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1747
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1912
        	Error:      	Received unexpected error:
        	            	object not found
        	Test:       	TestServerSideMove
2026/07/22 03:59:16 DEBUG : Linkbox root 'rclone-test-moxunow8hinu': Purge remote
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
--- FAIL: TestServerSideMove (155.00s)
=== RUN   TestServerSideMoveWithFilter
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 03:59:26 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-baxalaw0nuno"
2026/07/22 03:59:26 DEBUG : Config file has changed externally - reloading
2026/07/22 03:59:26 DEBUG : Linkbox root 'rclone-test-baxalaw0nuno': Using cached web token
2026/07/22 03:59:29 DEBUG : potato2: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:59:30 DEBUG : potato2: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:59:32 DEBUG : empty space: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:59:32 DEBUG : empty space: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:59:33 DEBUG : empty space: Trying to read object after upload: try again in 400ms (3/10)
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
    sync_test.go:1736: Server side move (if possible) Linkbox root 'rclone-test-wusoveh1hufi' -> Linkbox root 'rclone-test-baxalaw0nuno'
2026/07/22 03:59:49 DEBUG : potato3: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 03:59:49 DEBUG : potato3: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 03:59:50 DEBUG : potato3: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 03:59:51 DEBUG : empty space: Excluded (Size Filter)
2026/07/22 03:59:51 DEBUG : empty space: Excluded
2026/07/22 03:59:51 DEBUG : empty space: Excluded (Size Filter)
2026/07/22 03:59:51 DEBUG : empty space: Excluded
2026/07/22 03:59:51 DEBUG : potato2: Need to transfer - File not found at Destination
2026/07/22 03:59:51 DEBUG : potato3: size = 68 (Linkbox root 'rclone-test-wusoveh1hufi')
2026/07/22 03:59:51 DEBUG : potato3: size = 60 (Linkbox root 'rclone-test-baxalaw0nuno')
2026/07/22 03:59:51 DEBUG : potato3: Sizes differ
2026/07/22 03:59:51 DEBUG : Linkbox root 'rclone-test-baxalaw0nuno': Waiting for checks to finish
2026/07/22 03:59:51 DEBUG : Linkbox root 'rclone-test-baxalaw0nuno': Waiting for transfers to finish
2026/07/22 03:59:51 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:59:51 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 03:59:51 DEBUG : potato3: Update: removing old file
2026/07/22 03:59:51 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:59:51 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 03:59:52 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:59:52 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 03:59:52 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:59:52 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 03:59:54 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:59:56 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 03:59:58 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:00:00 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:00:02 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:00:04 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:00:06 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:00:08 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:00:11 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 04:00:12 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 04:00:14 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 04:00:15 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 04:00:17 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 04:00:17 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 04:00:17 DEBUG : potato3: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:00:18 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 04:00:18 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 04:00:18 DEBUG : potato3: size = 68 OK
2026/07/22 04:00:18 INFO  : potato3: Copied (replaced existing)
2026/07/22 04:00:18 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 04:00:18 DEBUG : potato2: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:00:18 DEBUG : potato2: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:00:19 DEBUG : potato2: size = 60 OK
2026/07/22 04:00:19 INFO  : potato2: Copied (new)
2026/07/22 04:00:19 INFO  : potato3: Deleted
2026/07/22 04:00:20 INFO  : potato2: Deleted
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
2026/07/22 04:00:28 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-zekusat3goti"
2026/07/22 04:00:28 DEBUG : Linkbox root 'rclone-test-zekusat3goti': Using cached web token
2026/07/22 04:00:30 DEBUG : empty space: Excluded (Size Filter)
2026/07/22 04:00:30 DEBUG : empty space: Excluded
2026/07/22 04:00:30 DEBUG : potato2: Need to transfer - File not found at Destination
2026/07/22 04:00:30 DEBUG : potato3: Need to transfer - File not found at Destination
2026/07/22 04:00:30 DEBUG : Linkbox root 'rclone-test-zekusat3goti': Waiting for checks to finish
2026/07/22 04:00:30 DEBUG : Linkbox root 'rclone-test-zekusat3goti': Waiting for transfers to finish
2026/07/22 04:00:34 DEBUG : potato2: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:00:34 DEBUG : potato3: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:00:35 DEBUG : potato2: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:00:35 DEBUG : potato3: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:00:35 DEBUG : potato2: size = 60 OK
2026/07/22 04:00:35 INFO  : potato2: Copied (new)
2026/07/22 04:00:35 DEBUG : potato3: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 04:00:36 DEBUG : potato3: size = 68 OK
2026/07/22 04:00:36 INFO  : potato3: Copied (new)
2026/07/22 04:00:36 INFO  : potato2: Deleted
2026/07/22 04:00:37 INFO  : potato3: Deleted
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
2026/07/22 04:00:45 DEBUG : Linkbox root 'rclone-test-zekusat3goti': Purge remote
2026/07/22 04:00:46 DEBUG : Linkbox root 'rclone-test-baxalaw0nuno': Purge remote
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3
    fstest.go:301: Flushing the directory cache
2026/07/22 04:00:53 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:00:53 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 04:00:53 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:00:53 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 04:00:54 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:00:54 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 04:00:55 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:00:55 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 04:00:56 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:00:58 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:01:00 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:01:02 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:01:04 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:01:06 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:01:06 ERROR : error listing: getting files failed: invalid character '<' looking for beginning of value
    fstest.go:282: Error listing: getting files failed: invalid character '<' looking for beginning of value
--- FAIL: TestServerSideMoveWithFilter (99.78s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 04:01:06 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-forogok3jide"
2026/07/22 04:01:06 DEBUG : Linkbox root 'rclone-test-forogok3jide': Using cached web token
2026/07/22 04:01:06 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:01:06 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 04:01:06 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:01:06 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 04:01:07 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:01:07 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 04:01:08 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:01:08 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 04:01:09 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 04:01:12 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 04:01:12 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 04:01:14 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 04:01:15 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 04:01:18 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 04:01:18 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 04:01:18 DEBUG : potato2: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:01:18 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 04:01:18 DEBUG : potato2: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:01:19 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 04:01:19 DEBUG : potato2: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 04:01:20 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 04:01:20 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 04:01:24 INFO  : tomatoDir: Making directory
    sync_test.go:1736: Server side move (if possible) Linkbox root 'rclone-test-wusoveh1hufi' -> Linkbox root 'rclone-test-forogok3jide'
2026/07/22 04:01:26 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 04:01:28 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 04:01:28 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 04:01:29 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 04:01:30 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 04:01:31 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 04:01:31 DEBUG : empty space: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:01:31 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 04:01:31 DEBUG : empty space: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:01:31 DEBUG : empty space: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 04:01:32 DEBUG : empty space: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 04:01:35 DEBUG : potato3: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:01:35 DEBUG : potato3: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:01:36 DEBUG : potato3: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 04:01:36 DEBUG : potato3: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 04:01:38 DEBUG : potato2: Need to transfer - File not found at Destination
2026/07/22 04:01:38 DEBUG : empty space: size = 1 OK
2026/07/22 04:01:38 DEBUG : empty space: Sizes identical
2026/07/22 04:01:38 DEBUG : empty space: Unchanged skipping
2026/07/22 04:01:38 DEBUG : potato3: size = 68 (Linkbox root 'rclone-test-wusoveh1hufi')
2026/07/22 04:01:38 DEBUG : potato3: size = 60 (Linkbox root 'rclone-test-forogok3jide')
2026/07/22 04:01:38 DEBUG : potato3: Sizes differ
2026/07/22 04:01:38 DEBUG : Linkbox root 'rclone-test-forogok3jide': Waiting for checks to finish
2026/07/22 04:01:38 DEBUG : potato3: Update: removing old file
2026/07/22 04:01:39 INFO  : empty space: Deleted
2026/07/22 04:01:39 DEBUG : Linkbox root 'rclone-test-forogok3jide': Waiting for transfers to finish
2026/07/22 04:01:40 DEBUG : potato2: size = 60 OK
2026/07/22 04:01:40 INFO  : potato2: Copied (new)
2026/07/22 04:01:41 DEBUG : potato3: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:01:42 INFO  : potato2: Deleted
2026/07/22 04:01:42 DEBUG : potato3: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:01:42 DEBUG : potato3: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 04:01:43 DEBUG : potato3: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 04:01:44 DEBUG : potato3: Trying to read object after upload: try again in 1.6s (5/10)
2026/07/22 04:01:46 DEBUG : potato3: Trying to read object after upload: try again in 3.2s (6/10)
2026/07/22 04:01:49 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:01:49 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 04:01:49 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:01:49 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 04:01:49 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:01:49 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 04:01:50 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:01:50 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 04:01:52 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:01:54 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:01:56 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:01:58 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:02:00 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:02:02 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:02:02 DEBUG : potato3: Received error: Update failed to read object: getting files failed: invalid character '<' looking for beginning of value - low level retry 0/10
2026/07/22 04:02:04 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:02:06 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:02:08 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:02:10 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 04:02:12 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 04:02:15 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 04:02:15 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 04:02:15 DEBUG : potato3: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:02:16 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 04:02:16 DEBUG : potato3: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:02:16 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 04:02:16 DEBUG : potato3: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 04:02:17 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 04:02:17 DEBUG : potato3: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 04:02:18 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 04:02:18 DEBUG : potato3: Trying to read object after upload: try again in 1.6s (5/10)
2026/07/22 04:02:20 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 04:02:20 DEBUG : potato3: Trying to read object after upload: try again in 3.2s (6/10)
2026/07/22 04:02:23 DEBUG : potato3: Trying to read object after upload: try again in 6.4s (7/10)
2026/07/22 04:02:30 DEBUG : potato3: Trying to read object after upload: try again in 12.8s (8/10)
2026/07/22 04:02:43 DEBUG : potato3: Trying to read object after upload: try again in 25.6s (9/10)
2026/07/22 04:03:09 DEBUG : potato3: Trying to read object after upload: try again in 51.2s (10/10)
2026/07/22 04:04:00 ERROR : potato3: Failed to copy: object not found
2026/07/22 04:04:00 ERROR : potato3: Not deleting source as copy failed: object not found
2026/07/22 04:04:00 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': not deleting directories as there were IO errors
    sync_test.go:1747: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1747
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1932
        	Error:      	Received unexpected error:
        	            	not deleting directories as there were IO errors
        	Test:       	TestServerSideMoveDeleteEmptySourceDirs
2026/07/22 04:04:00 DEBUG : Linkbox root 'rclone-test-forogok3jide': Purge remote
--- FAIL: TestServerSideMoveDeleteEmptySourceDirs (179.02s)
=== RUN   TestServerSideMoveOverlap
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 04:04:05 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-wusoveh1hufi/rclone-move-test"
2026/07/22 04:04:05 DEBUG : Config file has changed externally - reloading
2026/07/22 04:04:05 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi/rclone-move-test': Using cached web token
2026/07/22 04:04:07 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:04:07 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 04:04:07 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:04:07 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 04:04:07 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:04:07 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 04:04:08 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:04:08 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 04:04:10 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:04:12 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 04:04:15 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 04:04:15 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 04:04:15 DEBUG : potato2: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:04:17 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 04:04:17 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 04:04:18 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 04:04:20 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 04:04:20 DEBUG : pacer: Reducing sleep to 200.225829ms
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
2026/07/22 04:04:21 DEBUG : pacer: Reducing sleep to 200ms
    fstest.go:292: Sleeping for 6s just to make sure
--- PASS: TestServerSideMoveOverlap (22.23s)
=== RUN   TestSyncOverlap
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 04:04:27 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-wusoveh1hufi/rclone-sync-test"
2026/07/22 04:04:27 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi/rclone-sync-test': Using cached web token
--- PASS: TestSyncOverlap (1.75s)
=== RUN   TestSyncCompareDest
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 04:04:29 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-wusoveh1hufi/dst"
2026/07/22 04:04:29 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi/dst': Using cached web token
2026/07/22 04:04:31 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-wusoveh1hufi/CompareDest"
2026/07/22 04:04:31 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi/CompareDest': Using cached web token
2026/07/22 04:04:32 DEBUG : one: Need to transfer - File not found at Destination
2026/07/22 04:04:32 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi/dst': Waiting for checks to finish
2026/07/22 04:04:32 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi/dst': Waiting for transfers to finish
2026/07/22 04:04:36 DEBUG : one: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:04:36 DEBUG : one: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:04:37 DEBUG : one: size = 3 OK
2026/07/22 04:04:37 INFO  : one: Copied (new)
2026/07/22 04:04:37 DEBUG : Waiting for deletions to finish
2026/07/22 04:04:38 DEBUG : one: size = 5 (Local file system at /tmp/rclone1180572967)
2026/07/22 04:04:38 DEBUG : one: size = 3 (Linkbox root 'rclone-test-wusoveh1hufi/dst')
2026/07/22 04:04:38 DEBUG : one: Sizes differ
2026/07/22 04:04:38 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi/dst': Waiting for checks to finish
2026/07/22 04:04:38 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi/dst': Waiting for transfers to finish
2026/07/22 04:04:38 DEBUG : one: Update: removing old file
2026/07/22 04:04:41 DEBUG : one: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:04:42 DEBUG : one: size = 5 OK
2026/07/22 04:04:42 INFO  : one: Copied (replaced existing)
2026/07/22 04:04:42 DEBUG : Waiting for deletions to finish
2026/07/22 04:04:42 DEBUG : dst/one: Update: removing old file
2026/07/22 04:04:45 DEBUG : dst/one: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:04:46 DEBUG : dst/one: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:04:46 DEBUG : dst/one: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 04:04:47 DEBUG : dst/one: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 04:04:48 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:04:48 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 04:04:48 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:04:48 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 04:04:48 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:04:48 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 04:04:49 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:04:49 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 04:04:51 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:04:53 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:04:55 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:04:57 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:04:59 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:05:01 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-wusoveh1hufi': 1/10 (Update failed to read object: getting files failed: invalid character '<' looking for beginning of value)
2026/07/22 04:05:03 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:05:05 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:05:07 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:05:09 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:05:11 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 04:05:13 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 04:05:15 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 04:05:16 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 04:05:16 DEBUG : dst/one: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:05:17 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 04:05:17 DEBUG : dst/one: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:05:17 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 04:05:17 DEBUG : dst/one: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 04:05:18 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 04:05:18 DEBUG : dst/one: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 04:05:19 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 04:05:19 DEBUG : dst/one: Trying to read object after upload: try again in 1.6s (5/10)
2026/07/22 04:05:21 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 04:05:21 DEBUG : dst/one: Trying to read object after upload: try again in 3.2s (6/10)
2026/07/22 04:05:24 DEBUG : dst/one: Trying to read object after upload: try again in 6.4s (7/10)
2026/07/22 04:05:31 DEBUG : dst/one: Trying to read object after upload: try again in 12.8s (8/10)
2026/07/22 04:05:44 DEBUG : dst/one: Trying to read object after upload: try again in 25.6s (9/10)
2026/07/22 04:06:09 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:06:09 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 04:06:09 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:06:09 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 04:06:10 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:06:10 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 04:06:11 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:06:11 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 04:06:12 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 04:06:12 DEBUG : dst/one: Trying to read object after upload: try again in 51.2s (10/10)
    run.go:303: Failed to put "dst/one" to "Linkbox root 'rclone-test-wusoveh1hufi'": object not found
2026/07/22 04:07:04 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 04:07:05 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 04:07:06 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:07:06 DEBUG : pacer: Rate limited, increasing sleep to 1.6875s
2026/07/22 04:07:07 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:07:07 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 04:07:09 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:07:11 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:07:14 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 04:07:16 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 04:07:16 DEBUG : pacer: Reducing sleep to 843.75ms
    run.go:186: removing dir "dst" failed - try 1/3: sleeping 1s: directory not empty
2026/07/22 04:07:18 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 04:07:20 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 04:07:20 DEBUG : pacer: Reducing sleep to 355.957031ms
--- FAIL: TestSyncCompareDest (170.66s)
=== RUN   TestSyncMultipleCompareDest
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 04:07:20 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 04:07:22 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 04:07:22 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 04:07:32 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-wusoveh1hufi/dest"
2026/07/22 04:07:32 DEBUG : Config file has changed externally - reloading
2026/07/22 04:07:32 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi/dest': Using cached web token
2026/07/22 04:07:34 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-wusoveh1hufi/pre-dest1"
2026/07/22 04:07:34 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi/pre-dest1': Using cached web token
2026/07/22 04:07:34 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-wusoveh1hufi/pre-dest2"
2026/07/22 04:07:34 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi/pre-dest2': Using cached web token
2026/07/22 04:07:36 DEBUG : 1: size = 1 OK
2026/07/22 04:07:36 DEBUG : 1: Sizes identical
2026/07/22 04:07:36 DEBUG : 1: Destination found in --compare-dest, skipping
2026/07/22 04:07:36 DEBUG : 2: size = 1 OK
2026/07/22 04:07:36 DEBUG : 2: Sizes identical
2026/07/22 04:07:36 DEBUG : 2: Destination found in --compare-dest, skipping
2026/07/22 04:07:36 DEBUG : 3: Need to transfer - File not found at Destination
2026/07/22 04:07:36 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi/dest': Waiting for checks to finish
2026/07/22 04:07:36 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi/dest': Waiting for transfers to finish
2026/07/22 04:07:40 DEBUG : 3: size = 1 OK
2026/07/22 04:07:40 INFO  : 3: Copied (new)
2026/07/22 04:07:40 DEBUG : Waiting for deletions to finish
2026/07/22 04:07:46 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:07:46 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 04:07:46 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:07:46 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 04:07:46 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:07:46 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 04:07:47 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:07:47 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 04:07:49 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:07:51 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:07:53 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:07:55 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:07:57 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:07:59 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
    run.go:186: removing dir "pre-dest2" failed - try 1/3: sleeping 1s: getting files failed: invalid character '<' looking for beginning of value
2026/07/22 04:08:01 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:08:03 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:08:05 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:08:07 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:08:09 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:08:11 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:08:13 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 04:08:16 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 04:08:17 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 04:08:19 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 04:08:19 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 04:08:21 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 04:08:21 DEBUG : pacer: Reducing sleep to 266.967773ms
--- PASS: TestSyncMultipleCompareDest (61.16s)
=== RUN   TestSyncCopyDest
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:2266: Skipping test as remote does not support server-side copy
2026/07/22 04:08:21 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 04:08:22 DEBUG : pacer: Reducing sleep to 200ms
--- SKIP: TestSyncCopyDest (0.62s)
=== RUN   TestSyncBackupDir
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:2379: Skipping test as remote does not support server-side move
--- SKIP: TestSyncBackupDir (0.41s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:2379: Skipping test as remote does not support server-side move
--- SKIP: TestSyncBackupDirWithSuffix (0.40s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:2379: Skipping test as remote does not support server-side move
--- SKIP: TestSyncBackupDirWithSuffixKeepExtension (0.45s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:2379: Skipping test as remote does not support server-side move
--- SKIP: TestSyncBackupDirSuffixOnly (0.41s)
=== RUN   TestSyncSuffix
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:2480: Skipping test as remote does not support server-side move
--- SKIP: TestSyncSuffix (0.40s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:2480: Skipping test as remote does not support server-side move
--- SKIP: TestSyncSuffixKeepExtension (0.43s)
=== RUN   TestSyncUTFNorm
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 04:08:26 DEBUG : Testêé: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:08:26 DEBUG : Testêé: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:08:27 DEBUG : Testêé: size = 14 (Local file system at /tmp/rclone1180572967)
2026/07/22 04:08:27 DEBUG : Testêé: size = 18 (Linkbox root 'rclone-test-wusoveh1hufi')
2026/07/22 04:08:27 DEBUG : Testêé: Sizes differ
2026/07/22 04:08:27 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 04:08:27 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 04:08:27 DEBUG : Testêé: Update: removing old file
2026/07/22 04:08:30 DEBUG : Testêé: size = 14 OK
2026/07/22 04:08:30 INFO  : Testêé: Copied (replaced existing) to: Testêé
2026/07/22 04:08:30 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (8.20s)
=== RUN   TestSyncImmutable
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 04:08:33 DEBUG : existing: Need to transfer - File not found at Destination
2026/07/22 04:08:33 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 04:08:33 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 04:08:35 DEBUG : existing: size = 6 OK
2026/07/22 04:08:35 INFO  : existing: Copied (new)
2026/07/22 04:08:35 DEBUG : Waiting for deletions to finish
2026/07/22 04:08:35 DEBUG : existing: size = 8 (Local file system at /tmp/rclone1180572967)
2026/07/22 04:08:35 DEBUG : existing: size = 6 (Linkbox root 'rclone-test-wusoveh1hufi')
2026/07/22 04:08:35 DEBUG : existing: Sizes differ
2026/07/22 04:08:35 ERROR : existing: Source and destination exist but do not match: immutable file modified
2026/07/22 04:08:35 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 04:08:35 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 04:08:35 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': not deleting files as there were IO errors
2026/07/22 04:08:35 ERROR : Linkbox root 'rclone-test-wusoveh1hufi': not deleting directories as there were IO errors
--- PASS: TestSyncImmutable (5.04s)
=== RUN   TestSyncIgnoreCase
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:2637: Skipping test as local or remote are case-insensitive
--- SKIP: TestSyncIgnoreCase (0.43s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:2705: This test only runs on local
=== RUN   TestMaxTransfer/Soft
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:2705: This test only runs on local
=== RUN   TestMaxTransfer/Cautious
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
    sync_test.go:2705: This test only runs on local
--- PASS: TestMaxTransfer (1.21s)
    --- SKIP: TestMaxTransfer/Hard (0.40s)
    --- SKIP: TestMaxTransfer/Soft (0.40s)
    --- SKIP: TestMaxTransfer/Cautious (0.41s)
=== RUN   TestSyncConcurrentDelete
    run.go:198: Remote "Linkbox root 'rclone-test-wusoveh1hufi'", Local "Local file system at /tmp/rclone1180572967", Modify Window "876000h0m0s"
2026/07/22 04:08:44 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:08:44 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 04:08:44 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:08:44 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 04:08:44 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:08:44 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 04:08:45 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:08:45 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 04:08:47 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:08:49 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:08:51 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:08:53 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:08:55 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:08:57 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
    run.go:299: Retry Put of "both1" to Linkbox root 'rclone-test-wusoveh1hufi': 1/10 (Update second step failed: invalid character '<' looking for beginning of value)
2026/07/22 04:08:59 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:09:01 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:09:03 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:09:05 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:09:07 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:09:09 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:09:11 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:09:13 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:09:15 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 04:09:17 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 04:09:20 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 04:09:20 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 04:09:20 DEBUG : both1: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:09:21 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 04:09:21 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 04:09:22 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 04:09:23 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 04:09:23 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 04:09:25 DEBUG : both2: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:09:30 DEBUG : both3: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:09:30 DEBUG : both3: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:09:32 DEBUG : only3: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:09:35 DEBUG : both4: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:09:35 DEBUG : both4: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:09:35 DEBUG : both4: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 04:09:46 DEBUG : only6: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:09:46 DEBUG : only6: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:09:51 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:09:51 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 04:09:52 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:09:52 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 04:09:52 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:09:52 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 04:09:53 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:09:53 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 04:09:54 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:09:56 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:09:58 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:10:00 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:10:02 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:10:04 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
    run.go:299: Retry Put of "both8" to Linkbox root 'rclone-test-wusoveh1hufi': 1/10 (Update second step failed: invalid character '<' looking for beginning of value)
2026/07/22 04:10:06 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:10:08 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:10:11 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:10:13 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:10:15 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 04:10:17 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 04:10:19 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 04:10:20 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 04:10:20 DEBUG : both8: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:10:20 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 04:10:21 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 04:10:22 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 04:10:23 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 04:10:23 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 04:10:25 DEBUG : both9: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:10:26 DEBUG : both9: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:10:30 DEBUG : both10: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:10:30 DEBUG : both10: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:10:33 DEBUG : only10: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:10:38 DEBUG : only11: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:10:52 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:10:52 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 04:10:53 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:10:53 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 04:10:53 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:10:53 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 04:10:54 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:10:54 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 04:10:55 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:10:57 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:10:59 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:11:01 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:11:03 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:11:05 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:11:07 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:11:09 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:11:11 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:11:13 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:11:16 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 04:11:19 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 04:11:19 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 04:11:20 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 04:11:21 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 04:11:23 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 04:11:23 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 04:11:23 DEBUG : only15: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:11:24 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 04:11:24 DEBUG : pacer: Reducing sleep to 200ms
2026/07/22 04:11:26 DEBUG : both16: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:11:26 DEBUG : both16: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:11:27 DEBUG : both16: Trying to read object after upload: try again in 400ms (3/10)
2026/07/22 04:11:28 DEBUG : both16: Trying to read object after upload: try again in 800ms (4/10)
2026/07/22 04:11:41 DEBUG : only18: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:11:42 DEBUG : only18: Trying to read object after upload: try again in 200ms (2/10)
2026/07/22 04:11:45 DEBUG : both19: Trying to read object after upload: try again in 100ms (1/10)
2026/07/22 04:11:48 DEBUG : both0: size = 6 OK
2026/07/22 04:11:48 DEBUG : both0: Sizes identical
2026/07/22 04:11:48 DEBUG : both10: size = 6 OK
2026/07/22 04:11:48 DEBUG : both10: Sizes identical
2026/07/22 04:11:48 DEBUG : both11: size = 6 OK
2026/07/22 04:11:48 DEBUG : both11: Sizes identical
2026/07/22 04:11:48 DEBUG : both12: size = 6 OK
2026/07/22 04:11:48 DEBUG : both12: Sizes identical
2026/07/22 04:11:48 DEBUG : both0: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both13: size = 6 OK
2026/07/22 04:11:48 DEBUG : both13: Sizes identical
2026/07/22 04:11:48 DEBUG : both13: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both14: size = 6 OK
2026/07/22 04:11:48 DEBUG : both14: Sizes identical
2026/07/22 04:11:48 DEBUG : both14: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both15: size = 6 OK
2026/07/22 04:11:48 DEBUG : both15: Sizes identical
2026/07/22 04:11:48 DEBUG : both15: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both16: size = 6 OK
2026/07/22 04:11:48 DEBUG : both16: Sizes identical
2026/07/22 04:11:48 DEBUG : both16: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both17: size = 6 OK
2026/07/22 04:11:48 DEBUG : both17: Sizes identical
2026/07/22 04:11:48 DEBUG : both17: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both18: size = 6 OK
2026/07/22 04:11:48 DEBUG : both18: Sizes identical
2026/07/22 04:11:48 DEBUG : both18: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both19: size = 6 OK
2026/07/22 04:11:48 DEBUG : both19: Sizes identical
2026/07/22 04:11:48 DEBUG : both19: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both1: size = 6 OK
2026/07/22 04:11:48 DEBUG : both1: Sizes identical
2026/07/22 04:11:48 DEBUG : both10: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both2: size = 6 OK
2026/07/22 04:11:48 DEBUG : both2: Sizes identical
2026/07/22 04:11:48 DEBUG : both11: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both3: size = 6 OK
2026/07/22 04:11:48 DEBUG : both3: Sizes identical
2026/07/22 04:11:48 DEBUG : both12: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both4: size = 6 OK
2026/07/22 04:11:48 DEBUG : both4: Sizes identical
2026/07/22 04:11:48 DEBUG : both2: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both5: size = 6 OK
2026/07/22 04:11:48 DEBUG : both5: Sizes identical
2026/07/22 04:11:48 DEBUG : both5: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both6: size = 6 OK
2026/07/22 04:11:48 DEBUG : both6: Sizes identical
2026/07/22 04:11:48 DEBUG : both1: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both7: size = 6 OK
2026/07/22 04:11:48 DEBUG : both7: Sizes identical
2026/07/22 04:11:48 DEBUG : both6: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both8: size = 6 OK
2026/07/22 04:11:48 DEBUG : both8: Sizes identical
2026/07/22 04:11:48 DEBUG : both8: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both9: size = 6 OK
2026/07/22 04:11:48 DEBUG : both9: Sizes identical
2026/07/22 04:11:48 DEBUG : both9: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both3: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both4: Unchanged skipping
2026/07/22 04:11:48 DEBUG : both7: Unchanged skipping
2026/07/22 04:11:48 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for checks to finish
2026/07/22 04:11:48 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Waiting for transfers to finish
2026/07/22 04:11:48 DEBUG : Waiting for deletions to finish
2026/07/22 04:11:50 INFO  : only12: Deleted
2026/07/22 04:11:50 INFO  : only13: Deleted
2026/07/22 04:11:50 INFO  : only1: Deleted
2026/07/22 04:11:50 INFO  : only2: Deleted
2026/07/22 04:11:51 INFO  : only6: Deleted
2026/07/22 04:11:51 INFO  : only11: Deleted
2026/07/22 04:11:51 INFO  : only14: Deleted
2026/07/22 04:11:51 INFO  : only19: Deleted
2026/07/22 04:11:52 INFO  : only3: Deleted
2026/07/22 04:11:52 INFO  : only5: Deleted
2026/07/22 04:11:53 INFO  : only10: Deleted
2026/07/22 04:11:53 INFO  : only16: Deleted
2026/07/22 04:11:53 INFO  : only17: Deleted
2026/07/22 04:11:54 INFO  : only4: Deleted
2026/07/22 04:11:54 INFO  : only7: Deleted
2026/07/22 04:11:54 INFO  : only15: Deleted
2026/07/22 04:11:55 INFO  : only18: Deleted
2026/07/22 04:11:55 INFO  : only8: Deleted
2026/07/22 04:11:55 INFO  : only9: Deleted
2026/07/22 04:11:55 INFO  : only0: Deleted
2026/07/22 04:11:55 INFO  : There was nothing to transfer
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3
    fstest.go:301: Flushing the directory cache
2026/07/22 04:12:00 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:12:00 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/07/22 04:12:00 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:12:00 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/07/22 04:12:00 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:12:00 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/07/22 04:12:01 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:12:01 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/07/22 04:12:03 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:12:05 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:12:07 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:12:09 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:12:11 DEBUG : pacer: low level retry 9/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:12:13 DEBUG : pacer: low level retry 10/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:12:13 ERROR : error listing: getting files failed: invalid character '<' looking for beginning of value
    fstest.go:282: Error listing: getting files failed: invalid character '<' looking for beginning of value
2026/07/22 04:12:15 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/07/22 04:12:17 DEBUG : pacer: Reducing sleep to 1.5s
2026/07/22 04:12:19 DEBUG : pacer: Reducing sleep to 1.125s
2026/07/22 04:12:21 DEBUG : pacer: Reducing sleep to 843.75ms
2026/07/22 04:12:23 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/07/22 04:12:24 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/07/22 04:12:25 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/07/22 04:12:27 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/07/22 04:12:28 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/07/22 04:12:29 DEBUG : pacer: Reducing sleep to 200ms
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
--- FAIL: TestSyncConcurrentDelete (255.78s)
FAIL
2026/07/22 04:12:55 DEBUG : Linkbox root 'rclone-test-wusoveh1hufi': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestLinkbox: -verbose -test.run '^(TestCopy|TestCopyAfterDelete|TestCopyCheckFirst|TestCopyDeleteBefore|TestCopyEmptyDirectories|TestCopyMetadata|TestCopyMetadataNoEmptyDirs|TestCopyMissingDirectory|TestCopyNoEmptyDirectories|TestCopyNoTraverse|TestCopyNoTraverseDeadlock|TestCopyOverSelf|TestCopyRedownload|TestCopyWithDepth|TestCopyWithFilesFrom|TestCopyWithFilesFromAndNoTraverse|TestMoveEmptyDirectories|TestMoveNoEmptyDirectories|TestMoveOverSelf|TestMoveWithDeleteEmptySrcDirs|TestMoveWithIgnoreExisting|TestMoveWithoutDeleteEmptySrcDirs|TestServerSideCopy|TestServerSideCopyOverSelf|TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs|TestServerSideMoveLocal|TestServerSideMoveOverSelf|TestServerSideMoveOverlap|TestServerSideMoveWithFilter|TestSyncAfterAddingAFile|TestSyncAfterChangingContentsOnly|TestSyncAfterChangingFilesSizeOnly|TestSyncAfterChangingModtimeOnly|TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime|TestSyncAfterRemovingAFileAndAddingAFile|TestSyncAfterRemovingAFileAndAddingAFileDryRun|TestSyncAfterRemovingAFileAndAddingAFileSubDir|TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors|TestSyncBackupDir|TestSyncBackupDirSuffixOnly|TestSyncBackupDirWithSuffix|TestSyncBackupDirWithSuffixKeepExtension|TestSyncBasedOnCheckSum|TestSyncCompareDest|TestSyncConcurrentDelete|TestSyncCopyDest|TestSyncDeleteBefore|TestSyncDeleteDuring|TestSyncDoesntUpdateModtime|TestSyncEmptyDirectories|TestSyncIgnoreCase|TestSyncIgnoreErrors|TestSyncIgnoreExisting|TestSyncIgnoreSize|TestSyncIgnoreTimes|TestSyncImmutable|TestSyncMultipleCompareDest|TestSyncNoEmptyDirectories|TestSyncNoTraverse|TestSyncNoUpdateDirModtime|TestSyncOverlap|TestSyncSetDelayedModTimes|TestSyncSizeOnly|TestSyncSuffix|TestSyncSuffixKeepExtension|TestSyncUTFNorm|TestSyncWithExclude|TestSyncWithExcludeAndDeleteExcluded|TestSyncWithTrackRenames|TestSyncWithTrackRenamesStrategyLeaf|TestSyncWithTrackRenamesStrategyModtime|TestSyncWithUpdateOlder)$|^TestMaxTransfer$/^(Cautious|Hard|Soft)$'" - Finished ERROR in 43m32.740855726s (try 2/5): exit status 1: Failed [TestCopyCheckFirst TestCopyEmptyDirectories TestSyncNoUpdateDirModtime TestSyncEmptyDirectories TestSyncNoEmptyDirectories TestServerSideMoveOverSelf TestCopyRedownload TestSyncIgnoreTimes TestSyncAfterRemovingAFileAndAddingAFileSubDir TestSyncWithTrackRenames TestSyncWithTrackRenamesStrategyModtime TestMoveWithoutDeleteEmptySrcDirs TestServerSideMove TestServerSideMoveWithFilter TestServerSideMoveDeleteEmptySourceDirs TestSyncCompareDest TestSyncConcurrentDelete]