"./sync.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestNothingToTransferWithoutEmptyDirs|TestServerSideMoveOverSelf|TestSyncWithTrackRenames)$'" - Starting (try 2/5) 2025/09/03 02:20:28 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-qunukat1colo" 2025/09/03 02:20:28 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/09/03 02:20:29 DEBUG : Creating backend with remote "/tmp/rclone107012846" === RUN TestServerSideMoveOverSelf run.go:180: Remote "files root 'rclone-test-qunukat1colo'", Local "Local file system at /tmp/rclone107012846", Modify Window "1s" 2025/09/03 02:20:31 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-gobogos1mane" sync_test.go:701: Server side copy (if possible) files root 'rclone-test-qunukat1colo' -> files root 'rclone-test-gobogos1mane' 2025/09/03 02:20:32 DEBUG : Added delayed dir = "sub dir", newDst= 2025/09/03 02:20:32 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/09/03 02:20:32 DEBUG : files root 'rclone-test-gobogos1mane': Waiting for checks to finish 2025/09/03 02:20:32 DEBUG : files root 'rclone-test-gobogos1mane': Waiting for transfers to finish 2025/09/03 02:20:34 DEBUG : sub dir/hello world: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2025/09/03 02:20:34 INFO : sub dir/hello world: Copied (server-side copy) 2025/09/03 02:20:34 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/09/03 02:20:36 DEBUG : files root 'rclone-test-gobogos1mane': Using server-side directory move 2025/09/03 02:20:36 INFO : files root 'rclone-test-gobogos1mane': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/09/03 02:20:36 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/09/03 02:20:36 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/09/03 02:20:36 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/09/03 02:20:36 DEBUG : files root 'rclone-test-gobogos1mane': Waiting for checks to finish 2025/09/03 02:20:36 DEBUG : files root 'rclone-test-gobogos1mane': Waiting for transfers to finish 2025/09/03 02:20:36 INFO : sub dir/hello world: Deleted 2025/09/03 02:20:37 INFO : sub dir/hello world: Moved (server-side) 2025/09/03 02:20:37 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/09/03 02:20:39 DEBUG : testing file moves 2025/09/03 02:20:39 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/09/03 02:20:39 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/09/03 02:20:39 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/09/03 02:20:39 DEBUG : files root 'rclone-test-gobogos1mane': Waiting for checks to finish 2025/09/03 02:20:39 DEBUG : files root 'rclone-test-gobogos1mane': Waiting for transfers to finish 2025/09/03 02:20:39 INFO : sub dir/hello world: Deleted 2025/09/03 02:20:40 INFO : sub dir/hello world: Moved (server-side) 2025/09/03 02:20:40 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/09/03 02:20:41 DEBUG : files root 'rclone-test-gobogos1mane': Purge remote --- PASS: TestServerSideMoveOverSelf (12.84s) === RUN TestSyncWithTrackRenames run.go:180: Remote "files root 'rclone-test-qunukat1colo'", Local "Local file system at /tmp/rclone107012846", Modify Window "1s" sync_test.go:1568: Can track renames: true 2025/09/03 02:20:42 INFO : files root 'rclone-test-qunukat1colo': Making map for --track-renames 2025/09/03 02:20:42 INFO : files root 'rclone-test-qunukat1colo': Finished making map for --track-renames 2025/09/03 02:20:42 DEBUG : files root 'rclone-test-qunukat1colo': Waiting for checks to finish 2025/09/03 02:20:42 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/09/03 02:20:42 DEBUG : files root 'rclone-test-qunukat1colo': Waiting for renames to finish 2025/09/03 02:20:42 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/09/03 02:20:42 DEBUG : files root 'rclone-test-qunukat1colo': Waiting for transfers to finish 2025/09/03 02:20:43 DEBUG : potato: Dst hash empty - aborting Src hash check 2025/09/03 02:20:43 INFO : potato: Copied (new) 2025/09/03 02:20:43 DEBUG : yam: Dst hash empty - aborting Src hash check 2025/09/03 02:20:43 INFO : yam: Copied (new) 2025/09/03 02:20:43 DEBUG : Waiting for deletions to finish 2025/09/03 02:20:43 DEBUG : potato: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2025/09/03 02:20:43 INFO : files root 'rclone-test-qunukat1colo': Making map for --track-renames 2025/09/03 02:20:43 INFO : files root 'rclone-test-qunukat1colo': Finished making map for --track-renames 2025/09/03 02:20:43 DEBUG : files root 'rclone-test-qunukat1colo': Waiting for checks to finish 2025/09/03 02:20:43 DEBUG : yaml: Need to transfer - No matching file found at Destination 2025/09/03 02:20:43 DEBUG : potato: Unchanged skipping 2025/09/03 02:20:43 DEBUG : files root 'rclone-test-qunukat1colo': Waiting for renames to finish 2025/09/03 02:20:43 DEBUG : files root 'rclone-test-qunukat1colo': Waiting for transfers to finish 2025/09/03 02:20:44 DEBUG : yaml: Dst hash empty - aborting Src hash check 2025/09/03 02:20:44 INFO : yaml: Copied (new) 2025/09/03 02:20:44 DEBUG : Waiting for deletions to finish 2025/09/03 02:20:44 INFO : yam: Deleted sync_test.go:1594: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1594 Error: Not equal: expected: true actual : false Test: TestSyncWithTrackRenames Messages: canTrackRenames=true, renames=0 --- FAIL: TestSyncWithTrackRenames (3.17s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "files root 'rclone-test-qunukat1colo'", Local "Local file system at /tmp/rclone107012846", Modify Window "1s" 2025/09/03 02:20:45 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/09/03 02:20:45 INFO : sub dir: Making directory 2025/09/03 02:20:45 INFO : sub dir: Made directory with modification time 2011-12-30 12:59:59 +0000 UTC 2025/09/03 02:20:53 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/09/03 02:20:53 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/09/03 02:20:53 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/09/03 02:20:53 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) 2025/09/03 02:20:59 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-qunukat1colo/sub dir2/very/very/very/very/very/nested not empty`) 2025/09/03 02:20:59 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/09/03 02:20:59 DEBUG : pacer: Reducing sleep to 15ms 2025/09/03 02:20:59 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-qunukat1colo/sub dir2/very/very/very/very/very not empty`) 2025/09/03 02:20:59 DEBUG : pacer: Rate limited, increasing sleep to 30ms 2025/09/03 02:20:59 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-qunukat1colo/sub dir2/very/very/very/very/very not empty`) 2025/09/03 02:20:59 DEBUG : pacer: Rate limited, increasing sleep to 60ms 2025/09/03 02:20:59 DEBUG : pacer: Reducing sleep to 45ms 2025/09/03 02:20:59 DEBUG : pacer: Reducing sleep to 33.75ms 2025/09/03 02:20:59 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-qunukat1colo/sub dir2/very/very/very not empty`) 2025/09/03 02:20:59 DEBUG : pacer: Rate limited, increasing sleep to 67.5ms 2025/09/03 02:21:00 DEBUG : pacer: Reducing sleep to 50.625ms 2025/09/03 02:21:00 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-qunukat1colo/sub dir2/very/very not empty`) 2025/09/03 02:21:00 DEBUG : pacer: Rate limited, increasing sleep to 101.25ms 2025/09/03 02:21:00 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-qunukat1colo/sub dir2/very/very not empty`) 2025/09/03 02:21:00 DEBUG : pacer: Rate limited, increasing sleep to 202.5ms 2025/09/03 02:21:00 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-qunukat1colo/sub dir2/very/very not empty`) 2025/09/03 02:21:00 DEBUG : pacer: Rate limited, increasing sleep to 405ms 2025/09/03 02:21:00 DEBUG : pacer: Reducing sleep to 303.75ms 2025/09/03 02:21:01 DEBUG : pacer: Reducing sleep to 227.8125ms 2025/09/03 02:21:01 DEBUG : pacer: Reducing sleep to 170.859375ms 2025/09/03 02:21:01 DEBUG : pacer: Reducing sleep to 128.144531ms 2025/09/03 02:21:01 DEBUG : pacer: Reducing sleep to 96.108398ms 2025/09/03 02:21:01 DEBUG : pacer: Reducing sleep to 72.081298ms --- PASS: TestNothingToTransferWithoutEmptyDirs (16.75s) FAIL 2025/09/03 02:21:02 DEBUG : files root 'rclone-test-qunukat1colo': Purge remote 2025/09/03 02:21:02 DEBUG : pacer: Reducing sleep to 54.060973ms "./sync.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestNothingToTransferWithoutEmptyDirs|TestServerSideMoveOverSelf|TestSyncWithTrackRenames)$'" - Finished ERROR in 33.806127324s (try 2/5): exit status 1: Failed [TestSyncWithTrackRenames]