"./sync.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestMoveEmptyDirectories|TestMoveOverSelf|TestNoTag|TestServerSideMoveOverSelf|TestSyncWithTrackRenames)$'" - Starting (try 2/5)
2025/11/23 04:28:09 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-jisomov3yeja"
2025/11/23 04:28:09 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/11/23 04:28:10 DEBUG : Creating backend with remote "/tmp/rclone2427926295"
=== RUN   TestMoveEmptyDirectories
    run.go:185: Remote "files root 'rclone-test-jisomov3yeja'", Local "Local file system at /tmp/rclone2427926295", Modify Window "1s"
2025/11/23 04:28:10 DEBUG : sub dir2: Making directory with metadata
2025/11/23 04:28:10 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/11/23 04:28:11 INFO  : sub dir2: Making directory
2025/11/23 04:28:11 INFO  : sub dir2: Made directory with modification time 2011-12-25 12:59:59.123456789 +0000 UTC
2025/11/23 04:28:11 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/11/23 04:28:11 INFO  : sub dir: Making directory
2025/11/23 04:28:12 INFO  : sub dir: Made directory with modification time 2025-11-23 04:28:10.57782519 +0000 UTC
2025/11/23 04:28:12 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/11/23 04:28:12 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/11/23 04:28:12 DEBUG : files root 'rclone-test-jisomov3yeja': Waiting for checks to finish
2025/11/23 04:28:12 DEBUG : files root 'rclone-test-jisomov3yeja': Waiting for transfers to finish
2025/11/23 04:28:13 DEBUG : sub dir/hello world: size = 11 OK
2025/11/23 04:28:13 DEBUG : sub dir/hello world: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK
2025/11/23 04:28:13 INFO  : sub dir/hello world: Copied (new)
2025/11/23 04:28:13 INFO  : sub dir/hello world: Deleted
2025/11/23 04:28:14 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/11/23 04:28:14 INFO  : sub dir: Set directory modification time (using DirSetModTime)
--- PASS: TestMoveEmptyDirectories (5.03s)
=== RUN   TestMoveOverSelf
    run.go:185: Remote "files root 'rclone-test-jisomov3yeja'", Local "Local file system at /tmp/rclone2427926295", Modify Window "1s"
2025/11/23 04:28:16 DEBUG : sub dir: Directory modification time the same (differ by -681.825359ms, within tolerance 1s)
2025/11/23 04:28:16 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/11/23 04:28:16 DEBUG : sub dir/hello world: size = 17 (Local file system at /tmp/rclone2427926295)
2025/11/23 04:28:16 DEBUG : sub dir/hello world: size = 11 (files root 'rclone-test-jisomov3yeja')
2025/11/23 04:28:16 DEBUG : sub dir/hello world: Sizes differ
2025/11/23 04:28:16 DEBUG : files root 'rclone-test-jisomov3yeja': Waiting for checks to finish
2025/11/23 04:28:16 DEBUG : files root 'rclone-test-jisomov3yeja': Waiting for transfers to finish
2025/11/23 04:28:17 DEBUG : sub dir/hello world: size = 17 OK
2025/11/23 04:28:17 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/11/23 04:28:17 INFO  : sub dir/hello world: Copied (replaced existing)
2025/11/23 04:28:17 INFO  : sub dir/hello world: Deleted
2025/11/23 04:28:17 INFO  : sub dir: Set directory modification time (using DirSetModTime)
--- PASS: TestMoveOverSelf (3.24s)
=== RUN   TestServerSideMoveOverSelf
    run.go:185: Remote "files root 'rclone-test-jisomov3yeja'", Local "Local file system at /tmp/rclone2427926295", Modify Window "1s"
2025/11/23 04:28:19 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-cepaleg6wuhe"
    sync_test.go:701: Server side copy (if possible) files root 'rclone-test-jisomov3yeja' -> files root 'rclone-test-cepaleg6wuhe'
2025/11/23 04:28:20 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/11/23 04:28:20 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/11/23 04:28:20 DEBUG : files root 'rclone-test-cepaleg6wuhe': Waiting for checks to finish
2025/11/23 04:28:20 DEBUG : files root 'rclone-test-cepaleg6wuhe': Waiting for transfers to finish
2025/11/23 04:28:23 DEBUG : sub dir/hello world: size = 11 OK
2025/11/23 04:28:23 DEBUG : sub dir/hello world: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK
2025/11/23 04:28:23 INFO  : sub dir/hello world: Copied (server-side copy)
2025/11/23 04:28:23 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/11/23 04:28:27 DEBUG : files root 'rclone-test-cepaleg6wuhe': Using server-side directory move
2025/11/23 04:28:27 INFO  : files root 'rclone-test-cepaleg6wuhe': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/11/23 04:28:27 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/11/23 04:28:27 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/11/23 04:28:28 DEBUG : sub dir/hello world: size = 17 (files root 'rclone-test-jisomov3yeja')
2025/11/23 04:28:28 DEBUG : files root 'rclone-test-cepaleg6wuhe': Waiting for checks to finish
2025/11/23 04:28:28 DEBUG : sub dir/hello world: size = 11 (files root 'rclone-test-cepaleg6wuhe')
2025/11/23 04:28:28 DEBUG : sub dir/hello world: Sizes differ
2025/11/23 04:28:28 DEBUG : files root 'rclone-test-cepaleg6wuhe': Waiting for transfers to finish
2025/11/23 04:28:28 INFO  : sub dir/hello world: Deleted
2025/11/23 04:28:29 INFO  : sub dir/hello world: Moved (server-side)
2025/11/23 04:28:29 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/11/23 04:28:32 DEBUG : testing file moves
2025/11/23 04:28:32 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/11/23 04:28:32 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/11/23 04:28:32 DEBUG : sub dir/hello world: size = 24 (files root 'rclone-test-jisomov3yeja')
2025/11/23 04:28:32 DEBUG : sub dir/hello world: size = 17 (files root 'rclone-test-cepaleg6wuhe')
2025/11/23 04:28:32 DEBUG : sub dir/hello world: Sizes differ
2025/11/23 04:28:32 DEBUG : files root 'rclone-test-cepaleg6wuhe': Waiting for checks to finish
2025/11/23 04:28:32 DEBUG : files root 'rclone-test-cepaleg6wuhe': Waiting for transfers to finish
2025/11/23 04:28:32 INFO  : sub dir/hello world: Deleted
2025/11/23 04:28:33 INFO  : sub dir/hello world: Moved (server-side)
2025/11/23 04:28:33 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/11/23 04:28:34 DEBUG : files root 'rclone-test-cepaleg6wuhe': Purge remote
--- PASS: TestServerSideMoveOverSelf (16.81s)
=== RUN   TestSyncWithTrackRenames
    run.go:185: Remote "files root 'rclone-test-jisomov3yeja'", Local "Local file system at /tmp/rclone2427926295", Modify Window "1s"
    sync_test.go:1568: Can track renames: true
2025/11/23 04:28:35 INFO  : files root 'rclone-test-jisomov3yeja': Making map for --track-renames
2025/11/23 04:28:35 INFO  : files root 'rclone-test-jisomov3yeja': Finished making map for --track-renames
2025/11/23 04:28:35 DEBUG : files root 'rclone-test-jisomov3yeja': Waiting for checks to finish
2025/11/23 04:28:35 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/11/23 04:28:35 DEBUG : yam: Need to transfer - No matching file found at Destination
2025/11/23 04:28:35 DEBUG : files root 'rclone-test-jisomov3yeja': Waiting for renames to finish
2025/11/23 04:28:35 DEBUG : files root 'rclone-test-jisomov3yeja': Waiting for transfers to finish
2025/11/23 04:28:36 DEBUG : potato: size = 14 OK
2025/11/23 04:28:36 DEBUG : potato: Dst hash empty - aborting Src hash check
2025/11/23 04:28:36 INFO  : potato: Copied (new)
2025/11/23 04:28:36 DEBUG : yam: size = 11 OK
2025/11/23 04:28:36 DEBUG : yam: Dst hash empty - aborting Src hash check
2025/11/23 04:28:36 INFO  : yam: Copied (new)
2025/11/23 04:28:36 DEBUG : Waiting for deletions to finish
2025/11/23 04:28:36 DEBUG : potato: size = 14 OK
2025/11/23 04:28:36 DEBUG : potato: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/11/23 04:28:36 INFO  : files root 'rclone-test-jisomov3yeja': Making map for --track-renames
2025/11/23 04:28:36 DEBUG : potato: Unchanged skipping
2025/11/23 04:28:36 INFO  : files root 'rclone-test-jisomov3yeja': Finished making map for --track-renames
2025/11/23 04:28:36 DEBUG : files root 'rclone-test-jisomov3yeja': Waiting for checks to finish
2025/11/23 04:28:36 DEBUG : files root 'rclone-test-jisomov3yeja': Waiting for renames to finish
2025/11/23 04:28:37 INFO  : yam: Moved (server-side) to: yaml
2025/11/23 04:28:37 INFO  : yaml: Renamed from "yam"
2025/11/23 04:28:37 DEBUG : files root 'rclone-test-jisomov3yeja': Waiting for transfers to finish
2025/11/23 04:28:37 DEBUG : Waiting for deletions to finish
2025/11/23 04:28:37 INFO  : There was nothing to transfer
--- PASS: TestSyncWithTrackRenames (2.60s)
=== RUN   TestNoTag
    run.go:185: Remote "files root 'rclone-test-jisomov3yeja'", Local "Local file system at /tmp/rclone2427926295", Modify Window "1s"
2025/11/23 04:28:38 INFO  : toe: Making directory
2025/11/23 04:28:38 INFO  : toe: Made directory with modification time 2025-11-23 04:28:38.246825945 +0000 UTC
2025/11/23 04:28:38 DEBUG : Added delayed dir = "toe", newDst=<nil>
2025/11/23 04:28:38 INFO  : toe/toe: Making directory
2025/11/23 04:28:38 INFO  : toe/toe: Made directory with modification time 2025-11-23 04:28:38.247825945 +0000 UTC
2025/11/23 04:28:38 DEBUG : Added delayed dir = "toe/toe", newDst=<nil>
2025/11/23 04:28:38 DEBUG : toe: transformed to: tictactoe
2025/11/23 04:28:38 DEBUG : toe/toe/toe: transformed to: toe/toe/tictactoe
2025/11/23 04:28:38 DEBUG : toe/toe/toe: Need to transfer - File not found at Destination
2025/11/23 04:28:38 DEBUG : toe/toe/toe: transformed to: toe/toe/tictactoe
2025/11/23 04:28:38 DEBUG : files root 'rclone-test-jisomov3yeja': Waiting for checks to finish
2025/11/23 04:28:38 DEBUG : files root 'rclone-test-jisomov3yeja': Waiting for transfers to finish
2025/11/23 04:28:39 DEBUG : toe/toe/tictactoe: size = 11 OK
2025/11/23 04:28:39 DEBUG : toe/toe/tictactoe: Dst hash empty - aborting Src hash check
2025/11/23 04:28:39 INFO  : toe/toe/toe: Copied (new) to: toe/toe/tictactoe
2025/11/23 04:28:39 DEBUG : Waiting for deletions to finish
2025/11/23 04:28:39 INFO  : toe/toe: Set directory modification time (using DirSetModTime)
2025/11/23 04:28:39 INFO  : toe: Set directory modification time (using DirSetModTime)
--- PASS: TestNoTag (3.23s)
PASS
2025/11/23 04:28:41 DEBUG : files root 'rclone-test-jisomov3yeja': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestMoveEmptyDirectories|TestMoveOverSelf|TestNoTag|TestServerSideMoveOverSelf|TestSyncWithTrackRenames)$'" - Finished OK in 32.185035477s (try 2/5)