"./sync.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestMoveOverSelf|TestMoveWithoutDeleteEmptySrcDirs|TestSyncCompareDest)$'" - Starting (try 2/5)
2025/07/20 01:26:51 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-tuxefav5cula"
2025/07/20 01:26:51 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/07/20 01:26:52 DEBUG : Creating backend with remote "/tmp/rclone1470868586"
=== RUN   TestMoveOverSelf
    run.go:180: Remote "files root 'rclone-test-tuxefav5cula'", Local "Local file system at /tmp/rclone1470868586", Modify Window "1s"
2025/07/20 01:26:54 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/07/20 01:26:54 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/07/20 01:26:54 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/07/20 01:26:54 DEBUG : files root 'rclone-test-tuxefav5cula': Waiting for checks to finish
2025/07/20 01:26:54 DEBUG : files root 'rclone-test-tuxefav5cula': Waiting for transfers to finish
2025/07/20 01:26:55 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/07/20 01:26:55 INFO  : sub dir/hello world: Copied (replaced existing)
2025/07/20 01:26:55 INFO  : sub dir/hello world: Deleted
2025/07/20 01:26:55 INFO  : sub dir: Set directory modification time (using DirSetModTime)
--- PASS: TestMoveOverSelf (4.86s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "files root 'rclone-test-tuxefav5cula'", Local "Local file system at /tmp/rclone1470868586", Modify Window "1s"
2025/07/20 01:26:57 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/07/20 01:26:57 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/07/20 01:26:57 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/07/20 01:26:57 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/07/20 01:26:57 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/07/20 01:26:57 DEBUG : files root 'rclone-test-tuxefav5cula': Waiting for checks to finish
2025/07/20 01:26:57 DEBUG : files root 'rclone-test-tuxefav5cula': Waiting for transfers to finish
2025/07/20 01:26:57 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/07/20 01:26:57 INFO  : sub dir/hello world: Copied (new)
2025/07/20 01:26:57 INFO  : sub dir/hello world: Deleted
2025/07/20 01:26:58 DEBUG : nested/sub dir/file: md5 = 83d3784ea62518eafc60e98d84f877ad OK
2025/07/20 01:26:58 INFO  : nested/sub dir/file: Copied (new)
2025/07/20 01:26:58 INFO  : nested/sub dir/file: Deleted
2025/07/20 01:26:58 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/07/20 01:26:58 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/07/20 01:26:58 INFO  : nested: Set directory modification time (using DirSetModTime)
2025/07/20 01:26:59 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-tuxefav5cula/nested not empty`)
2025/07/20 01:26:59 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/07/20 01:27:00 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-tuxefav5cula/nested not empty`)
2025/07/20 01:27:00 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/07/20 01:27:00 DEBUG : pacer: Reducing sleep to 30ms
2025/07/20 01:27:00 DEBUG : pacer: Reducing sleep to 22.5ms
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (3.41s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "files root 'rclone-test-tuxefav5cula'", Local "Local file system at /tmp/rclone1470868586", Modify Window "1s"
2025/07/20 01:27:00 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-tuxefav5cula/dst"
2025/07/20 01:27:01 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-tuxefav5cula/CompareDest"
2025/07/20 01:27:02 DEBUG : one: Need to transfer - File not found at Destination
2025/07/20 01:27:02 DEBUG : files root 'rclone-test-tuxefav5cula/dst': Waiting for checks to finish
2025/07/20 01:27:02 DEBUG : files root 'rclone-test-tuxefav5cula/dst': Waiting for transfers to finish
2025/07/20 01:27:03 DEBUG : one: Dst hash empty - aborting Src hash check
2025/07/20 01:27:03 INFO  : one: Copied (new)
2025/07/20 01:27:03 DEBUG : Waiting for deletions to finish
2025/07/20 01:27:03 DEBUG : pacer: Reducing sleep to 16.875ms
2025/07/20 01:27:04 DEBUG : pacer: Reducing sleep to 12.65625ms
2025/07/20 01:27:04 DEBUG : pacer: Reducing sleep to 10ms
2025/07/20 01:27:04 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/07/20 01:27:04 DEBUG : files root 'rclone-test-tuxefav5cula/dst': Waiting for checks to finish
2025/07/20 01:27:05 DEBUG : files root 'rclone-test-tuxefav5cula/dst': Waiting for transfers to finish
2025/07/20 01:27:05 DEBUG : one: Dst hash empty - aborting Src hash check
2025/07/20 01:27:05 INFO  : one: Copied (replaced existing)
2025/07/20 01:27:05 DEBUG : Waiting for deletions to finish
2025/07/20 01:27:08 DEBUG : files root 'rclone-test-tuxefav5cula/dst': Waiting for checks to finish
2025/07/20 01:27:08 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/07/20 01:27:09 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/07/20 01:27:09 DEBUG : one: Destination found in --compare-dest, skipping
2025/07/20 01:27:09 DEBUG : files root 'rclone-test-tuxefav5cula/dst': Waiting for transfers to finish
2025/07/20 01:27:09 DEBUG : Waiting for deletions to finish
2025/07/20 01:27:09 INFO  : There was nothing to transfer
2025/07/20 01:27:10 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/07/20 01:27:10 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/07/20 01:27:10 DEBUG : two: Destination found in --compare-dest, skipping
2025/07/20 01:27:10 DEBUG : files root 'rclone-test-tuxefav5cula/dst': Waiting for checks to finish
2025/07/20 01:27:10 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/07/20 01:27:10 DEBUG : one: Destination found in --compare-dest, skipping
2025/07/20 01:27:10 DEBUG : files root 'rclone-test-tuxefav5cula/dst': Waiting for transfers to finish
2025/07/20 01:27:10 DEBUG : Waiting for deletions to finish
2025/07/20 01:27:10 INFO  : There was nothing to transfer
2025/07/20 01:27:11 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/07/20 01:27:11 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/07/20 01:27:11 DEBUG : two: Destination found in --compare-dest, skipping
2025/07/20 01:27:11 DEBUG : files root 'rclone-test-tuxefav5cula/dst': Waiting for checks to finish
2025/07/20 01:27:11 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/07/20 01:27:11 DEBUG : one: Destination found in --compare-dest, skipping
2025/07/20 01:27:11 DEBUG : files root 'rclone-test-tuxefav5cula/dst': Waiting for transfers to finish
2025/07/20 01:27:11 DEBUG : Waiting for deletions to finish
2025/07/20 01:27:11 INFO  : There was nothing to transfer
2025/07/20 01:27:12 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/07/20 01:27:12 DEBUG : two: Modification times differ by -120h0m0s: 2011-12-30 12:59:59 +0000 UTC, 2011-12-25 12:59:59 +0000 UTC
2025/07/20 01:27:12 DEBUG : two: md5 = b8a9f715dbb64fd5c56e7783c6820a61 OK
2025/07/20 01:27:12 DEBUG : two: Destination found in --compare-dest, skipping
2025/07/20 01:27:12 DEBUG : files root 'rclone-test-tuxefav5cula/dst': Waiting for checks to finish
2025/07/20 01:27:12 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/07/20 01:27:12 DEBUG : one: Destination found in --compare-dest, skipping
2025/07/20 01:27:12 DEBUG : files root 'rclone-test-tuxefav5cula/dst': Waiting for transfers to finish
2025/07/20 01:27:12 DEBUG : Waiting for deletions to finish
2025/07/20 01:27:12 INFO  : There was nothing to transfer
2025/07/20 01:27:13 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/07/20 01:27:13 DEBUG : two: Sizes differ (src 5 vs dst 3)
2025/07/20 01:27:13 DEBUG : two: Need to transfer - File not found at Destination
2025/07/20 01:27:13 DEBUG : files root 'rclone-test-tuxefav5cula/dst': Waiting for checks to finish
2025/07/20 01:27:13 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/07/20 01:27:13 DEBUG : one: Destination found in --compare-dest, skipping
2025/07/20 01:27:13 DEBUG : files root 'rclone-test-tuxefav5cula/dst': Waiting for transfers to finish
2025/07/20 01:27:14 DEBUG : two: Dst hash empty - aborting Src hash check
2025/07/20 01:27:14 INFO  : two: Copied (new)
2025/07/20 01:27:14 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncCompareDest (15.85s)
PASS
2025/07/20 01:27:16 DEBUG : files root 'rclone-test-tuxefav5cula': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestMoveOverSelf|TestMoveWithoutDeleteEmptySrcDirs|TestSyncCompareDest)$'" - Finished OK in 25.090281329s (try 2/5)