"./sync.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestNothingToTransferWithEmptyDirs|TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime|TestSyncWithTrackRenames)$'" - Starting (try 2/5)
2025/10/20 04:59:27 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-yikodew1qalo"
2025/10/20 04:59:27 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/10/20 04:59:28 DEBUG : Creating backend with remote "/tmp/rclone1883946292"
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "files root 'rclone-test-yikodew1qalo'", Local "Local file system at /tmp/rclone1883946292", Modify Window "1s"
2025/10/20 04:59:31 DEBUG : files root 'rclone-test-yikodew1qalo': Waiting for checks to finish
2025/10/20 04:59:31 DEBUG : empty space: Modification times differ by -95456h54m53.123456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06 +0000 UTC
2025/10/20 04:59:31 DEBUG : empty space: md5 = 336d5ebc5436534e61d16e63ddfca327 OK
2025/10/20 04:59:31 DEBUG : empty space: Unchanged skipping
2025/10/20 04:59:31 DEBUG : files root 'rclone-test-yikodew1qalo': Waiting for transfers to finish
2025/10/20 04:59:31 DEBUG : Waiting for deletions to finish
2025/10/20 04:59:31 INFO  : There was nothing to transfer
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (3.59s)
=== RUN   TestSyncWithTrackRenames
    run.go:180: Remote "files root 'rclone-test-yikodew1qalo'", Local "Local file system at /tmp/rclone1883946292", Modify Window "1s"
    sync_test.go:1568: Can track renames: true
2025/10/20 04:59:32 INFO  : files root 'rclone-test-yikodew1qalo': Making map for --track-renames
2025/10/20 04:59:32 INFO  : files root 'rclone-test-yikodew1qalo': Finished making map for --track-renames
2025/10/20 04:59:32 DEBUG : files root 'rclone-test-yikodew1qalo': Waiting for checks to finish
2025/10/20 04:59:32 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/10/20 04:59:32 DEBUG : yam: Need to transfer - No matching file found at Destination
2025/10/20 04:59:32 DEBUG : files root 'rclone-test-yikodew1qalo': Waiting for renames to finish
2025/10/20 04:59:32 DEBUG : files root 'rclone-test-yikodew1qalo': Waiting for transfers to finish
2025/10/20 04:59:33 DEBUG : yam: Dst hash empty - aborting Src hash check
2025/10/20 04:59:33 INFO  : yam: Copied (new)
2025/10/20 04:59:33 DEBUG : potato: Dst hash empty - aborting Src hash check
2025/10/20 04:59:33 INFO  : potato: Copied (new)
2025/10/20 04:59:33 DEBUG : Waiting for deletions to finish
2025/10/20 04:59:33 DEBUG : potato: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/10/20 04:59:33 INFO  : files root 'rclone-test-yikodew1qalo': Making map for --track-renames
2025/10/20 04:59:33 INFO  : files root 'rclone-test-yikodew1qalo': Finished making map for --track-renames
2025/10/20 04:59:33 DEBUG : files root 'rclone-test-yikodew1qalo': Waiting for checks to finish
2025/10/20 04:59:33 DEBUG : potato: Unchanged skipping
2025/10/20 04:59:33 DEBUG : files root 'rclone-test-yikodew1qalo': Waiting for renames to finish
2025/10/20 04:59:34 INFO  : yam: Moved (server-side) to: yaml
2025/10/20 04:59:34 INFO  : yaml: Renamed from "yam"
2025/10/20 04:59:34 DEBUG : files root 'rclone-test-yikodew1qalo': Waiting for transfers to finish
2025/10/20 04:59:34 DEBUG : Waiting for deletions to finish
2025/10/20 04:59:34 INFO  : There was nothing to transfer
--- PASS: TestSyncWithTrackRenames (2.84s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "files root 'rclone-test-yikodew1qalo'", Local "Local file system at /tmp/rclone1883946292", Modify Window "1s"
2025/10/20 04:59:35 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/10/20 04:59:35 INFO  : sub dir: Making directory
2025/10/20 04:59:35 INFO  : sub dir: Made directory with modification time 2011-12-30 12:59:59 +0000 UTC
2025/10/20 04:59:45 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/10/20 04:59:45 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/10/20 04:59:45 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/10/20 04:59:45 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
2025/10/20 04:59:51 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-yikodew1qalo/sub dirEmpty not empty`)
2025/10/20 04:59:51 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/10/20 04:59:51 DEBUG : pacer: Reducing sleep to 15ms
2025/10/20 04:59:51 DEBUG : pacer: Reducing sleep to 11.25ms
2025/10/20 04:59:51 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-yikodew1qalo/sub dir2/very/very/very/very/very/nested not empty`)
2025/10/20 04:59:51 DEBUG : pacer: Rate limited, increasing sleep to 22.5ms
2025/10/20 04:59:52 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-yikodew1qalo/sub dir2/very/very/very/very/very/nested not empty`)
2025/10/20 04:59:52 DEBUG : pacer: Rate limited, increasing sleep to 45ms
2025/10/20 04:59:52 DEBUG : pacer: Reducing sleep to 33.75ms
2025/10/20 04:59:52 DEBUG : pacer: Reducing sleep to 25.3125ms
2025/10/20 04:59:52 DEBUG : pacer: Reducing sleep to 18.984375ms
2025/10/20 04:59:52 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-yikodew1qalo/sub dir2/very/very/very not empty`)
2025/10/20 04:59:52 DEBUG : pacer: Rate limited, increasing sleep to 37.96875ms
2025/10/20 04:59:52 DEBUG : pacer: Reducing sleep to 28.476562ms
2025/10/20 04:59:53 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-yikodew1qalo/sub dir2/very/very not empty`)
2025/10/20 04:59:53 DEBUG : pacer: Rate limited, increasing sleep to 56.953124ms
2025/10/20 04:59:53 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-yikodew1qalo/sub dir2/very/very not empty`)
2025/10/20 04:59:53 DEBUG : pacer: Rate limited, increasing sleep to 113.906248ms
2025/10/20 04:59:53 DEBUG : pacer: Reducing sleep to 85.429686ms
2025/10/20 04:59:53 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-yikodew1qalo/sub dir2/very not empty`)
2025/10/20 04:59:53 DEBUG : pacer: Rate limited, increasing sleep to 170.859372ms
2025/10/20 04:59:53 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-yikodew1qalo/sub dir2/very not empty`)
2025/10/20 04:59:53 DEBUG : pacer: Rate limited, increasing sleep to 341.718744ms
2025/10/20 04:59:53 DEBUG : pacer: Reducing sleep to 256.289058ms
2025/10/20 04:59:54 DEBUG : pacer: Reducing sleep to 192.216793ms
2025/10/20 04:59:54 DEBUG : pacer: Reducing sleep to 144.162594ms
2025/10/20 04:59:54 DEBUG : pacer: Reducing sleep to 108.121945ms
2025/10/20 04:59:54 DEBUG : pacer: Reducing sleep to 81.091458ms
--- PASS: TestNothingToTransferWithEmptyDirs (19.68s)
PASS
2025/10/20 04:59:54 DEBUG : files root 'rclone-test-yikodew1qalo': Purge remote
2025/10/20 04:59:54 DEBUG : pacer: Reducing sleep to 60.818593ms
"./sync.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestNothingToTransferWithEmptyDirs|TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime|TestSyncWithTrackRenames)$'" - Finished OK in 27.412873143s (try 2/5)