"./sync.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestServerSideMoveOverSelf|TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime|TestSyncCompareDest)$'" - Starting (try 2/5)
2025/08/20 02:54:02 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-dumubuq8teba"
2025/08/20 02:54:02 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/08/20 02:54:03 DEBUG : Creating backend with remote "/tmp/rclone4274325925"
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "files root 'rclone-test-dumubuq8teba'", Local "Local file system at /tmp/rclone4274325925", Modify Window "1s"
2025/08/20 02:54:06 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-koxurix6mevo"
    sync_test.go:701: Server side copy (if possible) files root 'rclone-test-dumubuq8teba' -> files root 'rclone-test-koxurix6mevo'
2025/08/20 02:54:07 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/08/20 02:54:07 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/08/20 02:54:07 DEBUG : files root 'rclone-test-koxurix6mevo': Waiting for checks to finish
2025/08/20 02:54:07 DEBUG : files root 'rclone-test-koxurix6mevo': Waiting for transfers to finish
2025/08/20 02:54:10 DEBUG : sub dir/hello world: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK
2025/08/20 02:54:10 INFO  : sub dir/hello world: Copied (server-side copy)
2025/08/20 02:54:10 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/08/20 02:54:12 DEBUG : files root 'rclone-test-koxurix6mevo': Using server-side directory move
2025/08/20 02:54:13 INFO  : files root 'rclone-test-koxurix6mevo': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/08/20 02:54:13 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/08/20 02:54:13 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/08/20 02:54:13 DEBUG : files root 'rclone-test-koxurix6mevo': Waiting for checks to finish
2025/08/20 02:54:13 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/08/20 02:54:13 DEBUG : files root 'rclone-test-koxurix6mevo': Waiting for transfers to finish
2025/08/20 02:54:13 INFO  : sub dir/hello world: Deleted
2025/08/20 02:54:14 INFO  : sub dir/hello world: Moved (server-side)
2025/08/20 02:54:14 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/08/20 02:54:16 DEBUG : testing file moves
2025/08/20 02:54:16 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/08/20 02:54:16 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/08/20 02:54:16 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2025/08/20 02:54:16 DEBUG : files root 'rclone-test-koxurix6mevo': Waiting for checks to finish
2025/08/20 02:54:16 DEBUG : files root 'rclone-test-koxurix6mevo': Waiting for transfers to finish
2025/08/20 02:54:16 INFO  : sub dir/hello world: Deleted
2025/08/20 02:54:17 INFO  : sub dir/hello world: Moved (server-side)
2025/08/20 02:54:17 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/08/20 02:54:18 DEBUG : files root 'rclone-test-koxurix6mevo': Purge remote
--- PASS: TestServerSideMoveOverSelf (15.19s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "files root 'rclone-test-dumubuq8teba'", Local "Local file system at /tmp/rclone4274325925", Modify Window "1s"
2025/08/20 02:54:20 DEBUG : files root 'rclone-test-dumubuq8teba': Waiting for checks to finish
2025/08/20 02:54:20 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/08/20 02:54:20 DEBUG : empty space: md5 = 336d5ebc5436534e61d16e63ddfca327 OK
2025/08/20 02:54:20 DEBUG : empty space: Unchanged skipping
2025/08/20 02:54:20 DEBUG : files root 'rclone-test-dumubuq8teba': Waiting for transfers to finish
2025/08/20 02:54:20 DEBUG : Waiting for deletions to finish
2025/08/20 02:54:20 INFO  : There was nothing to transfer
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (1.63s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "files root 'rclone-test-dumubuq8teba'", Local "Local file system at /tmp/rclone4274325925", Modify Window "1s"
2025/08/20 02:54:20 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-dumubuq8teba/dst"
2025/08/20 02:54:21 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-dumubuq8teba/CompareDest"
2025/08/20 02:54:22 DEBUG : one: Need to transfer - File not found at Destination
2025/08/20 02:54:22 DEBUG : files root 'rclone-test-dumubuq8teba/dst': Waiting for checks to finish
2025/08/20 02:54:22 DEBUG : files root 'rclone-test-dumubuq8teba/dst': Waiting for transfers to finish
2025/08/20 02:54:24 DEBUG : one: md5 = f97c5d29941bfb1b2fdab0874906ab82 OK
2025/08/20 02:54:24 INFO  : one: Copied (new)
2025/08/20 02:54:24 DEBUG : Waiting for deletions to finish
2025/08/20 02:54:25 DEBUG : files root 'rclone-test-dumubuq8teba/dst': Waiting for checks to finish
2025/08/20 02:54:25 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/08/20 02:54:25 DEBUG : files root 'rclone-test-dumubuq8teba/dst': Waiting for transfers to finish
2025/08/20 02:54:26 DEBUG : one: Dst hash empty - aborting Src hash check
2025/08/20 02:54:26 INFO  : one: Copied (replaced existing)
2025/08/20 02:54:26 DEBUG : Waiting for deletions to finish
2025/08/20 02:54:29 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/08/20 02:54:29 DEBUG : files root 'rclone-test-dumubuq8teba/dst': Waiting for checks to finish
2025/08/20 02:54:29 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/08/20 02:54:29 DEBUG : one: Destination found in --compare-dest, skipping
2025/08/20 02:54:29 DEBUG : files root 'rclone-test-dumubuq8teba/dst': Waiting for transfers to finish
2025/08/20 02:54:29 DEBUG : Waiting for deletions to finish
2025/08/20 02:54:29 INFO  : There was nothing to transfer
2025/08/20 02:54:31 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/08/20 02:54:31 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/08/20 02:54:31 DEBUG : two: Destination found in --compare-dest, skipping
2025/08/20 02:54:31 DEBUG : files root 'rclone-test-dumubuq8teba/dst': Waiting for checks to finish
2025/08/20 02:54:31 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/08/20 02:54:31 DEBUG : one: Destination found in --compare-dest, skipping
2025/08/20 02:54:31 DEBUG : files root 'rclone-test-dumubuq8teba/dst': Waiting for transfers to finish
2025/08/20 02:54:31 DEBUG : Waiting for deletions to finish
2025/08/20 02:54:31 INFO  : There was nothing to transfer
2025/08/20 02:54:31 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/08/20 02:54:32 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/08/20 02:54:32 DEBUG : two: Destination found in --compare-dest, skipping
2025/08/20 02:54:32 DEBUG : files root 'rclone-test-dumubuq8teba/dst': Waiting for checks to finish
2025/08/20 02:54:32 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/08/20 02:54:32 DEBUG : one: Destination found in --compare-dest, skipping
2025/08/20 02:54:32 DEBUG : files root 'rclone-test-dumubuq8teba/dst': Waiting for transfers to finish
2025/08/20 02:54:32 DEBUG : Waiting for deletions to finish
2025/08/20 02:54:32 INFO  : There was nothing to transfer
2025/08/20 02:54:32 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/08/20 02:54:33 DEBUG : two: Modification times differ by -120h0m0s: 2011-12-30 12:59:59 +0000 UTC, 2011-12-25 12:59:59 +0000 UTC
2025/08/20 02:54:33 DEBUG : two: md5 = b8a9f715dbb64fd5c56e7783c6820a61 OK
2025/08/20 02:54:33 DEBUG : two: Destination found in --compare-dest, skipping
2025/08/20 02:54:33 DEBUG : files root 'rclone-test-dumubuq8teba/dst': Waiting for checks to finish
2025/08/20 02:54:33 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/08/20 02:54:33 DEBUG : one: Destination found in --compare-dest, skipping
2025/08/20 02:54:33 DEBUG : files root 'rclone-test-dumubuq8teba/dst': Waiting for transfers to finish
2025/08/20 02:54:33 DEBUG : Waiting for deletions to finish
2025/08/20 02:54:33 INFO  : There was nothing to transfer
2025/08/20 02:54:33 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/08/20 02:54:34 DEBUG : two: Sizes differ (src 5 vs dst 3)
2025/08/20 02:54:34 DEBUG : two: Need to transfer - File not found at Destination
2025/08/20 02:54:34 DEBUG : files root 'rclone-test-dumubuq8teba/dst': Waiting for checks to finish
2025/08/20 02:54:34 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/08/20 02:54:34 DEBUG : one: Destination found in --compare-dest, skipping
2025/08/20 02:54:34 DEBUG : files root 'rclone-test-dumubuq8teba/dst': Waiting for transfers to finish
2025/08/20 02:54:35 DEBUG : two: Dst hash empty - aborting Src hash check
2025/08/20 02:54:35 INFO  : two: Copied (new)
2025/08/20 02:54:35 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncCompareDest (16.17s)
PASS
2025/08/20 02:54:36 DEBUG : files root 'rclone-test-dumubuq8teba': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestServerSideMoveOverSelf|TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime|TestSyncCompareDest)$'" - Finished OK in 34.319441607s (try 2/5)