"./sync.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose" - Starting (try 1/5)
2025/04/13 03:27:30 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu"
2025/04/13 03:27:30 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/13 03:27:31 DEBUG : Creating backend with remote "/tmp/rclone2741615887"
=== RUN   TestPipe
--- PASS: TestPipe (0.00s)
=== RUN   TestPipeConcurrent
--- PASS: TestPipeConcurrent (0.04s)
=== RUN   TestPipeOrderBy
=== RUN   TestPipeOrderBy/#00
=== RUN   TestPipeOrderBy/size
=== RUN   TestPipeOrderBy/name
=== RUN   TestPipeOrderBy/modtime
=== RUN   TestPipeOrderBy/size,ascending
=== RUN   TestPipeOrderBy/name,asc
=== RUN   TestPipeOrderBy/modtime,ascending
=== RUN   TestPipeOrderBy/size,descending
=== RUN   TestPipeOrderBy/name,desc
=== RUN   TestPipeOrderBy/modtime,descending
=== RUN   TestPipeOrderBy/size,mixed,50
=== RUN   TestPipeOrderBy/size,mixed,51
--- PASS: TestPipeOrderBy (0.00s)
    --- PASS: TestPipeOrderBy/#00 (0.00s)
    --- PASS: TestPipeOrderBy/size (0.00s)
    --- PASS: TestPipeOrderBy/name (0.00s)
    --- PASS: TestPipeOrderBy/modtime (0.00s)
    --- PASS: TestPipeOrderBy/size,ascending (0.00s)
    --- PASS: TestPipeOrderBy/name,asc (0.00s)
    --- PASS: TestPipeOrderBy/modtime,ascending (0.00s)
    --- PASS: TestPipeOrderBy/size,descending (0.00s)
    --- PASS: TestPipeOrderBy/name,desc (0.00s)
    --- PASS: TestPipeOrderBy/modtime,descending (0.00s)
    --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s)
    --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s)
=== RUN   TestNewLess
=== RUN   TestNewLess/blankOK
=== RUN   TestNewLess/tooManyParts
=== RUN   TestNewLess/tooManyParts2
=== RUN   TestNewLess/badMixed
=== RUN   TestNewLess/unknownComparison
=== RUN   TestNewLess/unknownSortDirection
=== RUN   TestNewLess/size
=== RUN   TestNewLess/name
=== RUN   TestNewLess/modtime
=== RUN   TestNewLess/size,ascending
=== RUN   TestNewLess/name,asc
=== RUN   TestNewLess/modtime,ascending
=== RUN   TestNewLess/size,descending
=== RUN   TestNewLess/name,desc
=== RUN   TestNewLess/modtime,descending
=== RUN   TestNewLess/modtime,mixed
=== RUN   TestNewLess/modtime,mixed,30
--- PASS: TestNewLess (0.00s)
    --- PASS: TestNewLess/blankOK (0.00s)
    --- PASS: TestNewLess/tooManyParts (0.00s)
    --- PASS: TestNewLess/tooManyParts2 (0.00s)
    --- PASS: TestNewLess/badMixed (0.00s)
    --- PASS: TestNewLess/unknownComparison (0.00s)
    --- PASS: TestNewLess/unknownSortDirection (0.00s)
    --- PASS: TestNewLess/size (0.00s)
    --- PASS: TestNewLess/name (0.00s)
    --- PASS: TestNewLess/modtime (0.00s)
    --- PASS: TestNewLess/size,ascending (0.00s)
    --- PASS: TestNewLess/name,asc (0.00s)
    --- PASS: TestNewLess/modtime,ascending (0.00s)
    --- PASS: TestNewLess/size,descending (0.00s)
    --- PASS: TestNewLess/name,desc (0.00s)
    --- PASS: TestNewLess/modtime,descending (0.00s)
    --- PASS: TestNewLess/modtime,mixed (0.00s)
    --- PASS: TestNewLess/modtime,mixed,30 (0.00s)
=== RUN   TestRcCopy
    rc_test.go:16: Skipping test on non local remote
--- SKIP: TestRcCopy (0.00s)
=== RUN   TestRcMove
    rc_test.go:16: Skipping test on non local remote
--- SKIP: TestRcMove (0.00s)
=== RUN   TestRcSync
    rc_test.go:16: Skipping test on non local remote
--- SKIP: TestRcSync (0.00s)
=== RUN   TestCopyWithDryRun
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:27:31 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/13 03:27:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/13 03:27:31 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2025/04/13 03:27:31 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:27:31 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:27:31 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestCopyWithDryRun (1.69s)
=== RUN   TestCopy
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:27:32 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/13 03:27:32 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/13 03:27:32 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/13 03:27:32 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:27:32 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:27:33 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/04/13 03:27:33 INFO  : sub dir/hello world: Copied (new)
2025/04/13 03:27:34 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestCopy (2.67s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    sync_test.go:97: Skipping as metadata not supported
--- SKIP: TestCopyMetadata (0.26s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    sync_test.go:97: Skipping as metadata not supported
--- SKIP: TestCopyMetadataNoEmptyDirs (0.27s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:27:36 DEBUG : Creating backend with remote "/non-existing"
2025/04/13 03:27:36 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2025/04/13 03:27:36 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:27:36 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestCopyMissingDirectory (0.64s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:27:36 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/13 03:27:36 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/13 03:27:36 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:27:36 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:27:37 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/04/13 03:27:37 INFO  : sub dir/hello world: Copied (new)
2025/04/13 03:27:37 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestCopyNoTraverse (2.47s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:27:39 INFO  : files root 'rclone-test-waseqex3zogu': Running all checks before starting transfers
2025/04/13 03:27:39 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/13 03:27:39 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/13 03:27:39 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:27:39 INFO  : files root 'rclone-test-waseqex3zogu': Checks finished, now starting transfers
2025/04/13 03:27:39 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:27:40 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/04/13 03:27:40 INFO  : sub dir/hello world: Copied (new)
2025/04/13 03:27:40 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestCopyCheckFirst (2.31s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:27:41 ERROR : Ignoring --no-traverse with sync
2025/04/13 03:27:41 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/13 03:27:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/13 03:27:41 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:27:41 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:27:42 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/04/13 03:27:42 INFO  : sub dir/hello world: Copied (new)
2025/04/13 03:27:42 DEBUG : Waiting for deletions to finish
2025/04/13 03:27:42 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncNoTraverse (2.36s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:27:43 DEBUG : hello world2: Need to transfer - File not found at Destination
2025/04/13 03:27:43 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/13 03:27:43 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:27:43 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:27:44 DEBUG : hello world2: Dst hash empty - aborting Src hash check
2025/04/13 03:27:44 INFO  : hello world2: Copied (new)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestCopyWithDepth (1.73s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:27:45 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/13 03:27:45 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:27:45 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:27:46 DEBUG : potato2: Dst hash empty - aborting Src hash check
2025/04/13 03:27:46 INFO  : potato2: Copied (new)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestCopyWithFilesFrom (1.70s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:27:47 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/13 03:27:47 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:27:47 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:27:48 DEBUG : potato2: Dst hash empty - aborting Src hash check
2025/04/13 03:27:48 INFO  : potato2: Copied (new)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestCopyWithFilesFromAndNoTraverse (1.75s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:27:48 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/04/13 03:27:48 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/13 03:27:48 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/04/13 03:27:48 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/13 03:27:49 INFO  : sub dir: Making directory
2025/04/13 03:27:49 INFO  : sub dir: Made directory with modification time 2001-02-03 04:05:06.499999999 +0000 UTC
2025/04/13 03:27:49 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/13 03:27:49 INFO  : sub dir2: Making directory
2025/04/13 03:27:49 INFO  : sub dir2: Made directory with modification time 2011-12-25 12:59:59.123456789 +0000 UTC
2025/04/13 03:27:49 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/04/13 03:27:49 INFO  : sub dir2/sub sub dir2: Making directory
2025/04/13 03:27:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/13 03:27:50 INFO  : sub dir2/sub sub dir2: Made directory with modification time 2011-12-25 12:59:59.123456789 +0000 UTC
2025/04/13 03:27:50 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2025/04/13 03:27:50 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:27:50 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:27:50 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/04/13 03:27:50 INFO  : sub dir/hello world: Copied (new)
2025/04/13 03:27:50 INFO  : sub dir2/sub sub dir2: Set directory modification time (using DirSetModTime)
2025/04/13 03:27:50 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/04/13 03:27:50 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestCopyEmptyDirectories (4.23s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:27:53 INFO  : sub dir2: Making directory
2025/04/13 03:27:53 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/04/13 03:27:53 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/13 03:27:53 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/13 03:27:53 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/04/13 03:27:53 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2025/04/13 03:27:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/13 03:27:53 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:27:53 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:27:54 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/04/13 03:27:54 INFO  : sub dir/hello world: Copied (new)
2025/04/13 03:27:54 INFO  : sub dir: Set directory modification time (using DirSetModTime)
--- PASS: TestCopyNoEmptyDirectories (2.05s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:27:55 DEBUG : sub dir2: Making directory with metadata
2025/04/13 03:27:55 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/13 03:27:55 INFO  : sub dir: Making directory
2025/04/13 03:27:55 INFO  : sub dir: Made directory with modification time 2025-04-13 03:27:55.275641414 +0000 UTC
2025/04/13 03:27:55 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/13 03:27:55 INFO  : sub dir2: Making directory
2025/04/13 03:27:56 INFO  : sub dir2: Made directory with modification time 2011-12-25 12:59:59.123456789 +0000 UTC
2025/04/13 03:27:56 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/04/13 03:27:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/13 03:27:56 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:27:56 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:27:56 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/04/13 03:27:56 INFO  : sub dir/hello world: Copied (new)
2025/04/13 03:27:56 INFO  : sub dir/hello world: Deleted
2025/04/13 03:27:56 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/04/13 03:27:56 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestMoveEmptyDirectories (3.35s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:27:58 DEBUG : sub dir no update dir modtime: Making directory with metadata
2025/04/13 03:27:58 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/04/13 03:27:59 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:27:59 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:27:59 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncNoUpdateDirModtime (1.81s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:28:00 INFO  : sub dir2: Making directory
2025/04/13 03:28:00 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/13 03:28:00 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/04/13 03:28:00 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/13 03:28:00 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:28:00 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:28:01 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/04/13 03:28:01 INFO  : sub dir/hello world: Copied (new)
2025/04/13 03:28:01 INFO  : sub dir/hello world: Deleted
2025/04/13 03:28:01 INFO  : sub dir: Set directory modification time (using DirSetModTime)
--- PASS: TestMoveNoEmptyDirectories (2.08s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:28:02 DEBUG : sub dir2: Making directory with metadata
2025/04/13 03:28:02 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/13 03:28:02 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:02 INFO  : sub dir: Making directory
2025/04/13 03:28:02 INFO  : sub dir: Made directory with modification time 2001-02-03 04:05:06.499999999 +0000 UTC
2025/04/13 03:28:02 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/13 03:28:02 INFO  : sub dir2: Making directory
2025/04/13 03:28:03 INFO  : sub dir2: Made directory with modification time 2011-12-25 12:59:59.123456789 +0000 UTC
2025/04/13 03:28:03 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/04/13 03:28:03 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/13 03:28:03 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:28:03 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:28:04 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/04/13 03:28:04 INFO  : sub dir/hello world: Copied (new)
2025/04/13 03:28:04 DEBUG : Waiting for deletions to finish
2025/04/13 03:28:04 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:04 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncEmptyDirectories (3.33s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:28:05 INFO  : a1/b2/c1/d1/e1/f1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:05 INFO  : a1/b2/c1/d1/e1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:05 INFO  : a1/b2/c1/d1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:05 INFO  : a1/b2/c1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:05 INFO  : a1/b2: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:05 INFO  : a1/b1/c1/d2/e1/f2: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:05 INFO  : a1/b1/c1/d2/e1/f1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:05 INFO  : a1/b1/c1/d2/e1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:05 INFO  : a1/b1/c1/d2: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:05 INFO  : a1/b1/c1/d1/e1/f1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:05 INFO  : a1/b1/c1/d1/e1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:05 INFO  : a1/b1/c1/d1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:05 INFO  : a1/b1/c1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:05 INFO  : a1/b1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:05 INFO  : a1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:05 INFO  : a1: Making directory
2025/04/13 03:28:06 INFO  : a1: Made directory with modification time 2001-02-03 04:19:06.499999999 +0000 UTC
2025/04/13 03:28:06 DEBUG : Added delayed dir = "a1", newDst=<nil>
2025/04/13 03:28:06 INFO  : a1/b1: Making directory
2025/04/13 03:28:06 INFO  : a1/b1: Made directory with modification time 2001-02-03 04:18:06.499999999 +0000 UTC
2025/04/13 03:28:06 DEBUG : Added delayed dir = "a1/b1", newDst=<nil>
2025/04/13 03:28:06 INFO  : a1/b2: Making directory
2025/04/13 03:28:06 INFO  : a1/b2: Made directory with modification time 2001-02-03 04:09:06.499999999 +0000 UTC
2025/04/13 03:28:06 DEBUG : Added delayed dir = "a1/b2", newDst=<nil>
2025/04/13 03:28:06 INFO  : a1/b1/c1: Making directory
2025/04/13 03:28:06 INFO  : a1/b2/c1: Making directory
2025/04/13 03:28:07 INFO  : a1/b2/c1: Made directory with modification time 2001-02-03 04:08:06.499999999 +0000 UTC
2025/04/13 03:28:07 DEBUG : Added delayed dir = "a1/b2/c1", newDst=<nil>
2025/04/13 03:28:07 INFO  : a1/b2/c1/d1: Making directory
2025/04/13 03:28:07 INFO  : a1/b1/c1: Made directory with modification time 2001-02-03 04:17:06.499999999 +0000 UTC
2025/04/13 03:28:07 DEBUG : Added delayed dir = "a1/b1/c1", newDst=<nil>
2025/04/13 03:28:07 INFO  : a1/b1/c1/d1: Making directory
2025/04/13 03:28:07 INFO  : a1/b1/c1/d1: Made directory with modification time 2001-02-03 04:16:06.499999999 +0000 UTC
2025/04/13 03:28:07 DEBUG : Added delayed dir = "a1/b1/c1/d1", newDst=<nil>
2025/04/13 03:28:07 INFO  : a1/b1/c1/d2: Making directory
2025/04/13 03:28:07 INFO  : a1/b2/c1/d1: Made directory with modification time 2001-02-03 04:07:06.499999999 +0000 UTC
2025/04/13 03:28:07 DEBUG : Added delayed dir = "a1/b2/c1/d1", newDst=<nil>
2025/04/13 03:28:07 INFO  : a1/b2/c1/d1/e1: Making directory
2025/04/13 03:28:07 INFO  : a1/b1/c1/d2: Made directory with modification time 2001-02-03 04:13:06.499999999 +0000 UTC
2025/04/13 03:28:07 DEBUG : Added delayed dir = "a1/b1/c1/d2", newDst=<nil>
2025/04/13 03:28:07 INFO  : a1/b1/c1/d2/e1: Making directory
2025/04/13 03:28:07 INFO  : a1/b1/c1/d1/e1: Making directory
2025/04/13 03:28:07 INFO  : a1/b2/c1/d1/e1: Made directory with modification time 2001-02-03 04:06:06.499999999 +0000 UTC
2025/04/13 03:28:07 DEBUG : Added delayed dir = "a1/b2/c1/d1/e1", newDst=<nil>
2025/04/13 03:28:07 INFO  : a1/b2/c1/d1/e1/f1: Making directory
2025/04/13 03:28:08 INFO  : a1/b1/c1/d2/e1: Made directory with modification time 2001-02-03 04:12:06.499999999 +0000 UTC
2025/04/13 03:28:08 DEBUG : Added delayed dir = "a1/b1/c1/d2/e1", newDst=<nil>
2025/04/13 03:28:08 INFO  : a1/b1/c1/d2/e1/f1: Making directory
2025/04/13 03:28:08 INFO  : a1/b1/c1/d1/e1: Made directory with modification time 2001-02-03 04:15:06.499999999 +0000 UTC
2025/04/13 03:28:08 DEBUG : Added delayed dir = "a1/b1/c1/d1/e1", newDst=<nil>
2025/04/13 03:28:08 INFO  : a1/b1/c1/d1/e1/f1: Making directory
2025/04/13 03:28:08 INFO  : a1/b2/c1/d1/e1/f1: Made directory with modification time 2001-02-03 04:05:06.499999999 +0000 UTC
2025/04/13 03:28:08 DEBUG : Added delayed dir = "a1/b2/c1/d1/e1/f1", newDst=<nil>
2025/04/13 03:28:08 INFO  : a1/b1/c1/d1/e1/f1: Made directory with modification time 2001-02-03 04:14:06.499999999 +0000 UTC
2025/04/13 03:28:08 DEBUG : Added delayed dir = "a1/b1/c1/d1/e1/f1", newDst=<nil>
2025/04/13 03:28:08 INFO  : a1/b1/c1/d2/e1/f1: Made directory with modification time 2001-02-03 04:11:06.499999999 +0000 UTC
2025/04/13 03:28:08 DEBUG : Added delayed dir = "a1/b1/c1/d2/e1/f1", newDst=<nil>
2025/04/13 03:28:08 INFO  : a1/b1/c1/d2/e1/f2: Making directory
2025/04/13 03:28:09 INFO  : a1/b1/c1/d2/e1/f2: Made directory with modification time 2001-02-03 04:10:06.499999999 +0000 UTC
2025/04/13 03:28:09 DEBUG : Added delayed dir = "a1/b1/c1/d2/e1/f2", newDst=<nil>
2025/04/13 03:28:09 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:28:09 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:28:09 DEBUG : Waiting for deletions to finish
2025/04/13 03:28:09 INFO  : a1/b1/c1/d2/e1/f2: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:09 INFO  : a1/b1/c1/d1/e1/f1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:09 INFO  : a1/b2/c1/d1/e1/f1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:09 INFO  : a1/b1/c1/d2/e1/f1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:09 INFO  : a1/b1/c1/d1/e1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:09 INFO  : a1/b2/c1/d1/e1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:09 INFO  : a1/b1/c1/d2/e1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:09 INFO  : a1/b1/c1/d2: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:09 INFO  : a1/b1/c1/d1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:09 INFO  : a1/b2/c1/d1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:09 INFO  : a1/b1/c1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:09 INFO  : a1/b2/c1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:09 INFO  : a1/b2: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:09 INFO  : a1/b1: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:10 INFO  : a1: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:28:14 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/a1/b2/c1/d1/e1 not empty`)
2025/04/13 03:28:14 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/04/13 03:28:14 DEBUG : pacer: Reducing sleep to 15ms
2025/04/13 03:28:14 DEBUG : pacer: Reducing sleep to 11.25ms
2025/04/13 03:28:14 DEBUG : pacer: Reducing sleep to 10ms
2025/04/13 03:28:15 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/a1/b1/c1/d2/e1 not empty`)
2025/04/13 03:28:15 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/04/13 03:28:15 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/a1/b1/c1/d2/e1 not empty`)
2025/04/13 03:28:15 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/04/13 03:28:15 DEBUG : pacer: Reducing sleep to 30ms
2025/04/13 03:28:15 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/a1/b1/c1/d2 not empty`)
2025/04/13 03:28:15 DEBUG : pacer: Rate limited, increasing sleep to 60ms
2025/04/13 03:28:15 DEBUG : pacer: Reducing sleep to 45ms
2025/04/13 03:28:16 DEBUG : pacer: Reducing sleep to 33.75ms
2025/04/13 03:28:16 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/a1/b1/c1/d1/e1 not empty`)
2025/04/13 03:28:16 DEBUG : pacer: Rate limited, increasing sleep to 67.5ms
2025/04/13 03:28:16 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/a1/b1/c1/d1/e1 not empty`)
2025/04/13 03:28:16 DEBUG : pacer: Rate limited, increasing sleep to 135ms
2025/04/13 03:28:16 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/a1/b1/c1/d1/e1 not empty`)
2025/04/13 03:28:16 DEBUG : pacer: Rate limited, increasing sleep to 270ms
2025/04/13 03:28:16 DEBUG : pacer: Reducing sleep to 202.5ms
2025/04/13 03:28:16 DEBUG : pacer: Reducing sleep to 151.875ms
2025/04/13 03:28:17 DEBUG : pacer: Reducing sleep to 113.90625ms
2025/04/13 03:28:17 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/a1/b1 not empty`)
2025/04/13 03:28:17 DEBUG : pacer: Rate limited, increasing sleep to 227.8125ms
2025/04/13 03:28:17 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/a1/b1 not empty`)
2025/04/13 03:28:17 DEBUG : pacer: Rate limited, increasing sleep to 455.625ms
2025/04/13 03:28:17 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/a1/b1 not empty`)
2025/04/13 03:28:17 DEBUG : pacer: Rate limited, increasing sleep to 911.25ms
2025/04/13 03:28:18 DEBUG : pacer: Reducing sleep to 683.4375ms
2025/04/13 03:28:19 DEBUG : pacer: Reducing sleep to 512.578125ms
2025/04/13 03:28:19 DEBUG : pacer: Reducing sleep to 384.433593ms
2025/04/13 03:28:20 DEBUG : pacer: Reducing sleep to 288.325194ms
2025/04/13 03:28:20 DEBUG : pacer: Reducing sleep to 216.243895ms
--- PASS: TestSyncSetDelayedModTimes (14.73s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:28:20 INFO  : sub dir2: Making directory
2025/04/13 03:28:20 DEBUG : pacer: Reducing sleep to 162.182921ms
2025/04/13 03:28:20 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/13 03:28:20 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/04/13 03:28:20 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/13 03:28:20 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:28:20 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:28:21 DEBUG : pacer: Reducing sleep to 121.63719ms
2025/04/13 03:28:21 DEBUG : pacer: Reducing sleep to 91.227892ms
2025/04/13 03:28:21 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/04/13 03:28:21 INFO  : sub dir/hello world: Copied (new)
2025/04/13 03:28:21 DEBUG : Waiting for deletions to finish
2025/04/13 03:28:22 DEBUG : pacer: Reducing sleep to 68.420919ms
2025/04/13 03:28:22 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:22 DEBUG : pacer: Reducing sleep to 51.315689ms
2025/04/13 03:28:22 DEBUG : pacer: Reducing sleep to 38.486766ms
2025/04/13 03:28:22 DEBUG : pacer: Reducing sleep to 28.865074ms
2025/04/13 03:28:22 DEBUG : pacer: Reducing sleep to 21.648805ms
2025/04/13 03:28:22 DEBUG : pacer: Reducing sleep to 16.236603ms
2025/04/13 03:28:22 DEBUG : pacer: Reducing sleep to 12.177452ms
2025/04/13 03:28:22 DEBUG : pacer: Reducing sleep to 10ms
--- PASS: TestSyncNoEmptyDirectories (2.52s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:28:24 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-cagifeg9capo"
    sync_test.go:590: Server side copy (if possible) files root 'rclone-test-waseqex3zogu' -> files root 'rclone-test-cagifeg9capo'
2025/04/13 03:28:25 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/13 03:28:25 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/13 03:28:25 DEBUG : files root 'rclone-test-cagifeg9capo': Waiting for checks to finish
2025/04/13 03:28:25 DEBUG : files root 'rclone-test-cagifeg9capo': Waiting for transfers to finish
2025/04/13 03:28:27 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/04/13 03:28:27 DEBUG : sub dir/hello world: Src hash empty - aborting Dst hash check
2025/04/13 03:28:27 INFO  : sub dir/hello world: Copied (server-side copy)
2025/04/13 03:28:27 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:28:27 DEBUG : files root 'rclone-test-cagifeg9capo': Purge remote
--- PASS: TestServerSideCopy (5.88s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:28:30 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:30 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/04/13 03:28:30 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:28:30 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/04/13 03:28:30 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:28:31 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/04/13 03:28:31 INFO  : sub dir/hello world: Copied (replaced existing)
2025/04/13 03:28:31 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestCopyOverSelf (3.64s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:28:33 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-kabucoc8vuko"
    sync_test.go:626: Server side copy (if possible) files root 'rclone-test-waseqex3zogu' -> files root 'rclone-test-kabucoc8vuko'
2025/04/13 03:28:34 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/13 03:28:34 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/13 03:28:34 DEBUG : files root 'rclone-test-kabucoc8vuko': Waiting for checks to finish
2025/04/13 03:28:34 DEBUG : files root 'rclone-test-kabucoc8vuko': Waiting for transfers to finish
2025/04/13 03:28:36 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/04/13 03:28:36 DEBUG : sub dir/hello world: Src hash empty - aborting Dst hash check
2025/04/13 03:28:36 INFO  : sub dir/hello world: Copied (server-side copy)
2025/04/13 03:28:36 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:28:38 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:38 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/04/13 03:28:38 DEBUG : files root 'rclone-test-kabucoc8vuko': Waiting for checks to finish
2025/04/13 03:28:38 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/04/13 03:28:38 DEBUG : files root 'rclone-test-kabucoc8vuko': Waiting for transfers to finish
2025/04/13 03:28:40 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/04/13 03:28:40 DEBUG : sub dir/hello world: Src hash empty - aborting Dst hash check
2025/04/13 03:28:40 INFO  : sub dir/hello world: Copied (server-side copy)
2025/04/13 03:28:40 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:28:40 DEBUG : files root 'rclone-test-kabucoc8vuko': Purge remote
--- PASS: TestServerSideCopyOverSelf (9.29s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:28:43 DEBUG : sub dir: Directory modification time the same (differ by -951.60612ms, within tolerance 1s)
2025/04/13 03:28:43 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/04/13 03:28:43 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:28:43 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/04/13 03:28:43 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:28:43 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/04/13 03:28:43 INFO  : sub dir/hello world: Copied (replaced existing)
2025/04/13 03:28:43 INFO  : sub dir/hello world: Deleted
2025/04/13 03:28:44 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestMoveOverSelf (3.50s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:28:46 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-joyadir0mozu"
    sync_test.go:671: Server side copy (if possible) files root 'rclone-test-waseqex3zogu' -> files root 'rclone-test-joyadir0mozu'
2025/04/13 03:28:47 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/13 03:28:47 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/13 03:28:47 DEBUG : files root 'rclone-test-joyadir0mozu': Waiting for checks to finish
2025/04/13 03:28:47 DEBUG : files root 'rclone-test-joyadir0mozu': Waiting for transfers to finish
2025/04/13 03:28:49 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/04/13 03:28:49 DEBUG : sub dir/hello world: Src hash empty - aborting Dst hash check
2025/04/13 03:28:49 INFO  : sub dir/hello world: Copied (server-side copy)
2025/04/13 03:28:49 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:28:50 DEBUG : files root 'rclone-test-joyadir0mozu': Using server-side directory move
2025/04/13 03:28:50 INFO  : files root 'rclone-test-joyadir0mozu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/04/13 03:28:50 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:50 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/04/13 03:28:51 DEBUG : files root 'rclone-test-joyadir0mozu': Waiting for checks to finish
2025/04/13 03:28:51 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/04/13 03:28:51 DEBUG : files root 'rclone-test-joyadir0mozu': Waiting for transfers to finish
2025/04/13 03:28:51 INFO  : sub dir/hello world: Deleted
2025/04/13 03:28:51 INFO  : sub dir/hello world: Moved (server-side)
2025/04/13 03:28:51 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:53 DEBUG : testing file moves
2025/04/13 03:28:53 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/13 03:28:53 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/04/13 03:28:53 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2025/04/13 03:28:53 DEBUG : files root 'rclone-test-joyadir0mozu': Waiting for checks to finish
2025/04/13 03:28:53 DEBUG : files root 'rclone-test-joyadir0mozu': Waiting for transfers to finish
2025/04/13 03:28:54 INFO  : sub dir/hello world: Deleted
2025/04/13 03:28:54 INFO  : sub dir/hello world: Moved (server-side)
2025/04/13 03:28:54 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:28:55 DEBUG : files root 'rclone-test-joyadir0mozu': Purge remote
--- PASS: TestServerSideMoveOverSelf (11.13s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:28:57 ERROR : : error listing: directory not found
    fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3
    fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3
    fstest.go:299: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:299
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:709
        	Error:      	Should be true
        	Test:       	TestCopyAfterDelete
        	Messages:   	listing wrong, want
        	            	  sub dir/hello world (11) got
        	            	  
    fstest.go:197: Not found "sub dir/hello world"
    fstest.go:200: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:200
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:304
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:709
        	Error:      	Not equal: 
        	            	expected: 0
        	            	actual  : 1
        	Test:       	TestCopyAfterDelete
        	Messages:   	1 objects not found
2025/04/13 03:29:04 INFO  : Local file system at /tmp/rclone2741615887: Making directory
2025/04/13 03:29:04 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:04 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3
    fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3
    fstest.go:299: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:299
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:720
        	Error:      	Should be true
        	Test:       	TestCopyAfterDelete
        	Messages:   	listing wrong, want
        	            	  sub dir/hello world (11) got
        	            	  
    fstest.go:197: Not found "sub dir/hello world"
    fstest.go:200: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:200
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:304
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:720
        	Error:      	Not equal: 
        	            	expected: 0
        	            	actual  : 1
        	Test:       	TestCopyAfterDelete
        	Messages:   	1 objects not found
--- FAIL: TestCopyAfterDelete (17.24s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:15 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/13 03:29:15 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/13 03:29:15 DEBUG : Local file system at /tmp/rclone2741615887: Waiting for checks to finish
2025/04/13 03:29:15 DEBUG : Local file system at /tmp/rclone2741615887: Waiting for transfers to finish
2025/04/13 03:29:15 DEBUG : sub dir/hello world: Src hash empty - aborting Dst hash check
2025/04/13 03:29:15 DEBUG : sub dir/hello world.9e820094.partial: renamed to: sub dir/hello world
2025/04/13 03:29:15 INFO  : sub dir/hello world: Copied (new)
2025/04/13 03:29:15 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestCopyRedownload (2.79s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:16 DEBUG : check sum: Need to transfer - File not found at Destination
2025/04/13 03:29:16 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:16 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:17 DEBUG : check sum: Dst hash empty - aborting Src hash check
2025/04/13 03:29:17 INFO  : check sum: Copied (new)
2025/04/13 03:29:17 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:17 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:17 DEBUG : check sum: Dst hash empty - aborting Src hash check
2025/04/13 03:29:17 DEBUG : check sum: Size of src and dst objects identical
2025/04/13 03:29:17 DEBUG : check sum: Unchanged skipping
2025/04/13 03:29:17 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:17 DEBUG : Waiting for deletions to finish
2025/04/13 03:29:17 INFO  : There was nothing to transfer
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncBasedOnCheckSum (2.27s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:18 DEBUG : sizeonly: Need to transfer - File not found at Destination
2025/04/13 03:29:18 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:18 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:19 DEBUG : sizeonly: Dst hash empty - aborting Src hash check
2025/04/13 03:29:19 INFO  : sizeonly: Copied (new)
2025/04/13 03:29:19 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:19 DEBUG : sizeonly: Sizes identical
2025/04/13 03:29:19 DEBUG : sizeonly: Unchanged skipping
2025/04/13 03:29:19 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:19 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:19 DEBUG : Waiting for deletions to finish
2025/04/13 03:29:19 INFO  : There was nothing to transfer
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncSizeOnly (2.23s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:21 DEBUG : ignore-size: Need to transfer - File not found at Destination
2025/04/13 03:29:21 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:21 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:21 DEBUG : ignore-size: Dst hash empty - aborting Src hash check
2025/04/13 03:29:21 INFO  : ignore-size: Copied (new)
2025/04/13 03:29:21 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:22 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:22 DEBUG : ignore-size: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:29:22 DEBUG : ignore-size: Unchanged skipping
2025/04/13 03:29:22 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:22 DEBUG : Waiting for deletions to finish
2025/04/13 03:29:22 INFO  : There was nothing to transfer
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncIgnoreSize (2.20s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:24 DEBUG : existing: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:29:24 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:24 DEBUG : existing: Unchanged skipping
2025/04/13 03:29:24 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:24 DEBUG : Waiting for deletions to finish
2025/04/13 03:29:24 INFO  : There was nothing to transfer
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:24 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:24 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2025/04/13 03:29:24 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:25 DEBUG : existing: Dst hash empty - aborting Src hash check
2025/04/13 03:29:25 INFO  : existing: Copied (replaced existing)
2025/04/13 03:29:25 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncIgnoreTimes (2.88s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:26 DEBUG : existing: Need to transfer - File not found at Destination
2025/04/13 03:29:26 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:26 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:27 DEBUG : existing: Dst hash empty - aborting Src hash check
2025/04/13 03:29:27 INFO  : existing: Copied (new)
2025/04/13 03:29:27 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:27 DEBUG : existing: Destination exists, skipping
2025/04/13 03:29:27 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:27 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:27 DEBUG : Waiting for deletions to finish
2025/04/13 03:29:27 INFO  : There was nothing to transfer
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncIgnoreExisting (2.29s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:30 INFO  : d: Making directory
2025/04/13 03:29:30 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/04/13 03:29:30 DEBUG : c: Directory modification time the same (differ by -323.579143ms, within tolerance 1s)
2025/04/13 03:29:30 DEBUG : Added delayed dir = "c", newDst=c
2025/04/13 03:29:30 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/04/13 03:29:30 DEBUG : c/non empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:29:30 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:30 DEBUG : c/non empty space: Unchanged skipping
2025/04/13 03:29:30 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:31 DEBUG : a/potato2: Dst hash empty - aborting Src hash check
2025/04/13 03:29:31 INFO  : a/potato2: Copied (new)
2025/04/13 03:29:31 DEBUG : Waiting for deletions to finish
2025/04/13 03:29:31 INFO  : b/potato: Deleted
2025/04/13 03:29:31 INFO  : a: Set directory modification time (using DirSetModTime)
2025/04/13 03:29:31 INFO  : d: Removing directory
2025/04/13 03:29:32 INFO  : b: Removing directory
2025/04/13 03:29:32 DEBUG : files root 'rclone-test-waseqex3zogu': deleted 2 directories
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncIgnoreErrors (5.39s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:34 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:34 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/04/13 03:29:34 DEBUG : empty space: Dst hash empty - aborting Src hash check
2025/04/13 03:29:34 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:34 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2025/04/13 03:29:34 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:35 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:35 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/04/13 03:29:35 DEBUG : empty space: Dst hash empty - aborting Src hash check
2025/04/13 03:29:35 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:35 DEBUG : empty space: Dst hash empty - aborting Src hash check
2025/04/13 03:29:35 INFO  : empty space: Copied (replaced existing)
2025/04/13 03:29:35 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncAfterChangingModtimeOnly (3.08s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:37 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/04/13 03:29:37 DEBUG : empty space: Dst hash empty - aborting Src hash check
2025/04/13 03:29:37 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:37 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:38 DEBUG : empty space: Dst hash empty - aborting Src hash check
2025/04/13 03:29:38 INFO  : empty space: Copied (replaced existing)
2025/04/13 03:29:38 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    fstest.go:121: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:121
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:126
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:145
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:189
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1035
        	Error:      	Should be true
        	Test:       	TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
        	Messages:   	empty space: Modification time difference too big |-95456h54m52.500000001s| > 1s (want 2001-02-03 04:05:06.499999999 +0000 UTC vs got 2011-12-25 12:59:59 +0000 UTC) (precision 1s)
--- FAIL: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (2.53s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:40 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:40 DEBUG : foo: Modification times differ by -95456h54m53.123456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06 +0000 UTC
2025/04/13 03:29:40 DEBUG : foo: Dst hash empty - aborting Src hash check
2025/04/13 03:29:40 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:41 DEBUG : foo: Dst hash empty - aborting Src hash check
2025/04/13 03:29:41 INFO  : foo: Copied (replaced existing)
2025/04/13 03:29:41 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncDoesntUpdateModtime (2.54s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:42 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:29:42 DEBUG : potato: Need to transfer - File not found at Destination
2025/04/13 03:29:42 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:42 DEBUG : empty space: Unchanged skipping
2025/04/13 03:29:42 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:43 DEBUG : potato: Dst hash empty - aborting Src hash check
2025/04/13 03:29:43 INFO  : potato: Copied (new)
2025/04/13 03:29:43 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncAfterAddingAFile (2.71s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:45 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2025/04/13 03:29:45 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:45 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:46 DEBUG : potato: Dst hash empty - aborting Src hash check
2025/04/13 03:29:46 INFO  : potato: Copied (replaced existing)
2025/04/13 03:29:46 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncAfterChangingFilesSizeOnly (2.59s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:48 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC
2025/04/13 03:29:48 DEBUG : potato: Dst hash empty - aborting Src hash check
2025/04/13 03:29:48 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:48 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:48 DEBUG : potato: Dst hash empty - aborting Src hash check
2025/04/13 03:29:48 INFO  : potato: Copied (replaced existing)
2025/04/13 03:29:48 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncAfterChangingContentsOnly (2.53s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:51 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/13 03:29:51 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:29:51 DEBUG : empty space: Unchanged skipping
2025/04/13 03:29:51 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:51 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2025/04/13 03:29:51 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:51 DEBUG : Waiting for deletions to finish
2025/04/13 03:29:51 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (2.51s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:54 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:29:54 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/13 03:29:54 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:54 DEBUG : empty space: Unchanged skipping
2025/04/13 03:29:54 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:54 DEBUG : potato2: Dst hash empty - aborting Src hash check
2025/04/13 03:29:54 INFO  : potato2: Copied (new)
2025/04/13 03:29:54 DEBUG : Waiting for deletions to finish
2025/04/13 03:29:54 INFO  : potato: Deleted
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (3.62s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:29:57 INFO  : d: Making directory
2025/04/13 03:29:57 INFO  : d/e: Making directory
2025/04/13 03:29:58 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/04/13 03:29:58 DEBUG : c: Directory modification time the same (differ by 332.433626ms, within tolerance 1s)
2025/04/13 03:29:58 DEBUG : Added delayed dir = "c", newDst=c
2025/04/13 03:29:58 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/04/13 03:29:58 DEBUG : c/non empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:29:58 DEBUG : c/non empty space: Unchanged skipping
2025/04/13 03:29:58 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:29:58 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:29:59 DEBUG : a/potato2: Dst hash empty - aborting Src hash check
2025/04/13 03:29:59 INFO  : a/potato2: Copied (new)
2025/04/13 03:29:59 DEBUG : Waiting for deletions to finish
2025/04/13 03:29:59 INFO  : b/potato: Deleted
2025/04/13 03:29:59 INFO  : a: Set directory modification time (using DirSetModTime)
2025/04/13 03:29:59 INFO  : d/e: Removing directory
2025/04/13 03:29:59 INFO  : d: Removing directory
2025/04/13 03:29:59 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/d not empty`)
2025/04/13 03:29:59 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/04/13 03:29:59 DEBUG : pacer: Reducing sleep to 15ms
2025/04/13 03:29:59 INFO  : b: Removing directory
2025/04/13 03:30:00 DEBUG : pacer: Reducing sleep to 11.25ms
2025/04/13 03:30:00 DEBUG : files root 'rclone-test-waseqex3zogu': deleted 3 directories
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:30:00 DEBUG : pacer: Reducing sleep to 10ms
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (5.84s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:30:04 INFO  : d: Making directory
2025/04/13 03:30:05 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/04/13 03:30:05 INFO  : c: Set directory modification time (using DirSetModTime)
2025/04/13 03:30:05 DEBUG : Added delayed dir = "c", newDst=c
2025/04/13 03:30:05 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/04/13 03:30:05 DEBUG : c/non empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:30:05 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:05 DEBUG : c/non empty space: Unchanged skipping
2025/04/13 03:30:05 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:06 DEBUG : a/potato2: Dst hash empty - aborting Src hash check
2025/04/13 03:30:06 INFO  : a/potato2: Copied (new)
2025/04/13 03:30:06 ERROR : files root 'rclone-test-waseqex3zogu': not deleting files as there were IO errors
2025/04/13 03:30:06 INFO  : a: Set directory modification time (using DirSetModTime)
2025/04/13 03:30:06 ERROR : files root 'rclone-test-waseqex3zogu': not deleting directories as there were IO errors
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (7.19s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:30:10 DEBUG : Waiting for deletions to finish
2025/04/13 03:30:10 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:30:10 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/13 03:30:10 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:10 DEBUG : empty space: Unchanged skipping
2025/04/13 03:30:10 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:10 INFO  : potato: Deleted
2025/04/13 03:30:11 DEBUG : potato2: Dst hash empty - aborting Src hash check
2025/04/13 03:30:11 INFO  : potato2: Copied (new)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncDeleteDuring (3.72s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:30:14 DEBUG : Waiting for deletions to finish
2025/04/13 03:30:14 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:14 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:14 INFO  : potato: Deleted
2025/04/13 03:30:14 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:30:14 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/13 03:30:14 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:14 DEBUG : empty space: Unchanged skipping
2025/04/13 03:30:14 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:15 DEBUG : potato2: Dst hash empty - aborting Src hash check
2025/04/13 03:30:15 INFO  : potato2: Copied (new)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncDeleteBefore (3.77s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:30:17 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/13 03:30:17 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:17 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:18 DEBUG : potato2: Dst hash empty - aborting Src hash check
2025/04/13 03:30:18 INFO  : potato2: Copied (new)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestCopyDeleteBefore (2.83s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:30:20 DEBUG : enormous: Excluded (Size Filter)
2025/04/13 03:30:20 DEBUG : enormous: Excluded
2025/04/13 03:30:20 DEBUG : potato2: Excluded (Size Filter)
2025/04/13 03:30:20 DEBUG : potato2: Excluded
2025/04/13 03:30:21 DEBUG : potato2: Excluded (Size Filter)
2025/04/13 03:30:21 DEBUG : potato2: Excluded
2025/04/13 03:30:21 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:21 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:30:21 DEBUG : empty space: Unchanged skipping
2025/04/13 03:30:21 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:21 DEBUG : Waiting for deletions to finish
2025/04/13 03:30:21 INFO  : There was nothing to transfer
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:30:21 DEBUG : enormous: Excluded (Size Filter)
2025/04/13 03:30:21 DEBUG : enormous: Excluded
2025/04/13 03:30:21 DEBUG : potato2: Excluded (Size Filter)
2025/04/13 03:30:21 DEBUG : potato2: Excluded
2025/04/13 03:30:21 DEBUG : potato2: Excluded (Size Filter)
2025/04/13 03:30:21 DEBUG : potato2: Excluded
2025/04/13 03:30:21 DEBUG : empty space: Size and modification time the same (differ by 123.456789ms, within tolerance 1s)
2025/04/13 03:30:21 DEBUG : empty space: Unchanged skipping
2025/04/13 03:30:21 DEBUG : Local file system at /tmp/rclone2741615887: Waiting for checks to finish
2025/04/13 03:30:21 DEBUG : Local file system at /tmp/rclone2741615887: Waiting for transfers to finish
2025/04/13 03:30:21 DEBUG : Waiting for deletions to finish
2025/04/13 03:30:21 INFO  : There was nothing to transfer
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncWithExclude (3.29s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:30:24 DEBUG : enormous: Excluded (Size Filter)
2025/04/13 03:30:24 DEBUG : enormous: Excluded
2025/04/13 03:30:24 DEBUG : potato2: Excluded (Size Filter)
2025/04/13 03:30:24 DEBUG : potato2: Excluded
2025/04/13 03:30:25 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:30:25 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:25 DEBUG : empty space: Unchanged skipping
2025/04/13 03:30:25 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:25 DEBUG : Waiting for deletions to finish
2025/04/13 03:30:25 INFO  : enormous: Deleted
2025/04/13 03:30:25 INFO  : potato2: Deleted
2025/04/13 03:30:25 INFO  : There was nothing to transfer
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:30:25 DEBUG : empty space: Size and modification time the same (differ by 123.456789ms, within tolerance 1s)
2025/04/13 03:30:25 DEBUG : empty space: Unchanged skipping
2025/04/13 03:30:25 DEBUG : Local file system at /tmp/rclone2741615887: Waiting for checks to finish
2025/04/13 03:30:25 DEBUG : Local file system at /tmp/rclone2741615887: Waiting for transfers to finish
2025/04/13 03:30:25 DEBUG : Waiting for deletions to finish
2025/04/13 03:30:25 INFO  : enormous: Deleted
2025/04/13 03:30:25 INFO  : potato2: Deleted
2025/04/13 03:30:25 INFO  : There was nothing to transfer
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (3.82s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:30:29 DEBUG : five: Need to transfer - File not found at Destination
2025/04/13 03:30:29 DEBUG : four: Sizes differ (src 4 vs dst 8)
2025/04/13 03:30:29 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:29 DEBUG : one: Destination is newer than source, skipping
2025/04/13 03:30:29 DEBUG : two: Dst hash empty - aborting Src hash check
2025/04/13 03:30:29 DEBUG : three: Sizes identical
2025/04/13 03:30:29 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2025/04/13 03:30:29 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2025/04/13 03:30:29 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:30 DEBUG : five: Dst hash empty - aborting Src hash check
2025/04/13 03:30:30 INFO  : five: Copied (new)
2025/04/13 03:30:30 DEBUG : four: Dst hash empty - aborting Src hash check
2025/04/13 03:30:30 INFO  : four: Copied (replaced existing)
2025/04/13 03:30:30 DEBUG : two: Dst hash empty - aborting Src hash check
2025/04/13 03:30:30 INFO  : two: Copied (replaced existing)
2025/04/13 03:30:30 DEBUG : Waiting for deletions to finish
2025/04/13 03:30:31 DEBUG : five: Dst hash empty - aborting Src hash check
2025/04/13 03:30:31 DEBUG : four: Dst hash empty - aborting Src hash check
2025/04/13 03:30:31 DEBUG : one: Destination is newer than source, skipping
2025/04/13 03:30:31 DEBUG : two: Dst hash empty - aborting Src hash check
2025/04/13 03:30:31 DEBUG : three: Dst hash empty - aborting Src hash check
2025/04/13 03:30:31 DEBUG : five: Size of src and dst objects identical
2025/04/13 03:30:31 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:31 DEBUG : four: Size of src and dst objects identical
2025/04/13 03:30:31 DEBUG : five: Destination mod time is within 1s of source and files identical, skipping
2025/04/13 03:30:31 DEBUG : four: Destination mod time is within 1s of source and files identical, skipping
2025/04/13 03:30:31 DEBUG : two: Size of src and dst objects identical
2025/04/13 03:30:31 DEBUG : two: Destination mod time is within 1s of source and files identical, skipping
2025/04/13 03:30:31 DEBUG : three: Size of src and dst objects identical
2025/04/13 03:30:31 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2025/04/13 03:30:31 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:31 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncWithUpdateOlder (5.80s)
=== RUN   TestSyncWithMaxDuration
=== RUN   TestSyncWithMaxDuration/Hard
    sync_test.go:1466: Skipping test on non local remote
=== RUN   TestSyncWithMaxDuration/Soft
    sync_test.go:1466: Skipping test on non local remote
--- PASS: TestSyncWithMaxDuration (0.00s)
    --- SKIP: TestSyncWithMaxDuration/Hard (0.00s)
    --- SKIP: TestSyncWithMaxDuration/Soft (0.00s)
=== RUN   TestSyncWithTrackRenames
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    sync_test.go:1538: Can track renames: true
2025/04/13 03:30:32 INFO  : files root 'rclone-test-waseqex3zogu': Making map for --track-renames
2025/04/13 03:30:32 INFO  : files root 'rclone-test-waseqex3zogu': Finished making map for --track-renames
2025/04/13 03:30:32 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:32 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/04/13 03:30:32 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for renames to finish
2025/04/13 03:30:32 DEBUG : yam: Need to transfer - No matching file found at Destination
2025/04/13 03:30:32 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:33 DEBUG : potato: Dst hash empty - aborting Src hash check
2025/04/13 03:30:33 INFO  : potato: Copied (new)
2025/04/13 03:30:33 DEBUG : yam: Dst hash empty - aborting Src hash check
2025/04/13 03:30:33 INFO  : yam: Copied (new)
2025/04/13 03:30:33 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:30:33 DEBUG : potato: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:30:33 INFO  : files root 'rclone-test-waseqex3zogu': Making map for --track-renames
2025/04/13 03:30:33 INFO  : files root 'rclone-test-waseqex3zogu': Finished making map for --track-renames
2025/04/13 03:30:33 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:33 DEBUG : yaml: Need to transfer - No matching file found at Destination
2025/04/13 03:30:33 DEBUG : potato: Unchanged skipping
2025/04/13 03:30:33 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for renames to finish
2025/04/13 03:30:33 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:34 DEBUG : yaml: Dst hash empty - aborting Src hash check
2025/04/13 03:30:34 INFO  : yaml: Copied (new)
2025/04/13 03:30:34 DEBUG : Waiting for deletions to finish
2025/04/13 03:30:34 INFO  : yam: Deleted
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    sync_test.go:1564: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1564
        	Error:      	Not equal: 
        	            	expected: true
        	            	actual  : false
        	Test:       	TestSyncWithTrackRenames
        	Messages:   	canTrackRenames=true, renames=0
--- FAIL: TestSyncWithTrackRenames (3.53s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    sync_test.go:1610: Can track renames: true
2025/04/13 03:30:35 INFO  : files root 'rclone-test-waseqex3zogu': Making map for --track-renames
2025/04/13 03:30:35 INFO  : files root 'rclone-test-waseqex3zogu': Finished making map for --track-renames
2025/04/13 03:30:35 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:35 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/04/13 03:30:35 DEBUG : yam: Need to transfer - No matching file found at Destination
2025/04/13 03:30:35 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for renames to finish
2025/04/13 03:30:35 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:36 DEBUG : yam: Dst hash empty - aborting Src hash check
2025/04/13 03:30:36 INFO  : yam: Copied (new)
2025/04/13 03:30:36 DEBUG : potato: Dst hash empty - aborting Src hash check
2025/04/13 03:30:36 INFO  : potato: Copied (new)
2025/04/13 03:30:36 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:30:36 DEBUG : potato: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:30:36 INFO  : files root 'rclone-test-waseqex3zogu': Making map for --track-renames
2025/04/13 03:30:36 INFO  : files root 'rclone-test-waseqex3zogu': Finished making map for --track-renames
2025/04/13 03:30:36 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:36 DEBUG : potato: Unchanged skipping
2025/04/13 03:30:36 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for renames to finish
2025/04/13 03:30:37 INFO  : yam: Moved (server-side) to: yaml
2025/04/13 03:30:37 INFO  : yaml: Renamed from "yam"
2025/04/13 03:30:37 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:37 DEBUG : Waiting for deletions to finish
2025/04/13 03:30:37 INFO  : There was nothing to transfer
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (3.01s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    sync_test.go:1649: Can track renames: true
2025/04/13 03:30:38 DEBUG : Added delayed dir = "sub", newDst=<nil>
2025/04/13 03:30:38 INFO  : files root 'rclone-test-waseqex3zogu': Making map for --track-renames
2025/04/13 03:30:38 INFO  : files root 'rclone-test-waseqex3zogu': Finished making map for --track-renames
2025/04/13 03:30:38 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:38 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/04/13 03:30:38 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for renames to finish
2025/04/13 03:30:38 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2025/04/13 03:30:38 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:39 DEBUG : sub/yam: Dst hash empty - aborting Src hash check
2025/04/13 03:30:39 INFO  : sub/yam: Copied (new)
2025/04/13 03:30:39 DEBUG : potato: Dst hash empty - aborting Src hash check
2025/04/13 03:30:39 INFO  : potato: Copied (new)
2025/04/13 03:30:39 DEBUG : Waiting for deletions to finish
2025/04/13 03:30:39 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:30:40 DEBUG : potato: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:30:40 DEBUG : potato: Unchanged skipping
2025/04/13 03:30:40 INFO  : sub: Set directory modification time (using DirSetModTime)
2025/04/13 03:30:40 DEBUG : Added delayed dir = "sub", newDst=sub
2025/04/13 03:30:40 INFO  : files root 'rclone-test-waseqex3zogu': Making map for --track-renames
2025/04/13 03:30:40 INFO  : files root 'rclone-test-waseqex3zogu': Finished making map for --track-renames
2025/04/13 03:30:40 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:40 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for renames to finish
2025/04/13 03:30:41 INFO  : sub/yam: Moved (server-side) to: yam
2025/04/13 03:30:41 INFO  : yam: Renamed from "sub/yam"
2025/04/13 03:30:41 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:41 DEBUG : Waiting for deletions to finish
2025/04/13 03:30:41 INFO  : There was nothing to transfer
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (4.96s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:30:43 DEBUG : Creating backend with remote "/tmp/rclone2741615887/dir1"
2025/04/13 03:30:43 DEBUG : Config file has changed externally - reloading
2025/04/13 03:30:43 DEBUG : Creating backend with remote "/tmp/rclone2741615887/dir2"
2025/04/13 03:30:43 DEBUG : Local file system at /tmp/rclone2741615887/dir2: Using server-side directory move
2025/04/13 03:30:43 INFO  : Local file system at /tmp/rclone2741615887/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/04/13 03:30:43 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/04/13 03:30:43 DEBUG : Local file system at /tmp/rclone2741615887/dir2: Waiting for checks to finish
2025/04/13 03:30:43 INFO  : file1.txt: Moved (server-side)
2025/04/13 03:30:43 DEBUG : Local file system at /tmp/rclone2741615887/dir2: Waiting for transfers to finish
--- PASS: TestServerSideMoveLocal (0.26s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:30:44 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/04/13 03:30:44 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/13 03:30:44 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/04/13 03:30:44 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/13 03:30:44 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/04/13 03:30:44 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:44 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:44 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/04/13 03:30:44 INFO  : sub dir/hello world: Copied (new)
2025/04/13 03:30:44 INFO  : sub dir/hello world: Deleted
2025/04/13 03:30:44 DEBUG : nested/sub dir/file: Dst hash empty - aborting Src hash check
2025/04/13 03:30:44 INFO  : nested/sub dir/file: Copied (new)
2025/04/13 03:30:44 INFO  : nested/sub dir/file: Deleted
2025/04/13 03:30:45 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/04/13 03:30:45 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/13 03:30:45 INFO  : nested: Set directory modification time (using DirSetModTime)
2025/04/13 03:30:45 INFO  : sub dir: Removing directory
2025/04/13 03:30:45 INFO  : nested/sub dir: Removing directory
2025/04/13 03:30:45 INFO  : nested: Removing directory
2025/04/13 03:30:45 DEBUG : Local file system at /tmp/rclone2741615887: deleted 3 directories
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestMoveWithDeleteEmptySrcDirs (3.33s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:30:47 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/04/13 03:30:47 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/13 03:30:47 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/13 03:30:47 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/04/13 03:30:47 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/04/13 03:30:47 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:47 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:48 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/04/13 03:30:48 INFO  : sub dir/hello world: Copied (new)
2025/04/13 03:30:48 INFO  : sub dir/hello world: Deleted
2025/04/13 03:30:48 DEBUG : nested/sub dir/file: Dst hash empty - aborting Src hash check
2025/04/13 03:30:48 INFO  : nested/sub dir/file: Copied (new)
2025/04/13 03:30:48 INFO  : nested/sub dir/file: Deleted
2025/04/13 03:30:48 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/04/13 03:30:48 INFO  : nested: Set directory modification time (using DirSetModTime)
2025/04/13 03:30:48 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (3.40s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:30:50 DEBUG : existing: Need to transfer - File not found at Destination
2025/04/13 03:30:50 DEBUG : existing-b: Need to transfer - File not found at Destination
2025/04/13 03:30:50 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:50 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:51 DEBUG : existing: Dst hash empty - aborting Src hash check
2025/04/13 03:30:51 INFO  : existing: Copied (new)
2025/04/13 03:30:51 INFO  : existing: Deleted
2025/04/13 03:30:51 DEBUG : existing-b: Dst hash empty - aborting Src hash check
2025/04/13 03:30:51 INFO  : existing-b: Copied (new)
2025/04/13 03:30:51 INFO  : existing-b: Deleted
2025/04/13 03:30:52 DEBUG : existing: Destination exists, skipping
2025/04/13 03:30:52 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2025/04/13 03:30:52 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:30:52 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:30:52 INFO  : There was nothing to transfer
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestMoveWithIgnoreExisting (2.30s)
=== RUN   TestServerSideMove
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:30:52 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-leyojib7jano"
    sync_test.go:1705: Server side move (if possible) files root 'rclone-test-waseqex3zogu' -> files root 'rclone-test-leyojib7jano'
2025/04/13 03:30:58 DEBUG : files root 'rclone-test-leyojib7jano': Using server-side directory move
2025/04/13 03:30:58 INFO  : files root 'rclone-test-leyojib7jano': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/04/13 03:30:58 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/13 03:30:58 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1s)
2025/04/13 03:30:58 DEBUG : empty space: Unchanged skipping
2025/04/13 03:30:58 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/04/13 03:30:58 DEBUG : files root 'rclone-test-leyojib7jano': Waiting for checks to finish
2025/04/13 03:30:58 INFO  : potato3: Deleted
2025/04/13 03:30:59 INFO  : potato2: Moved (server-side)
2025/04/13 03:30:59 INFO  : empty space: Deleted
2025/04/13 03:30:59 DEBUG : files root 'rclone-test-leyojib7jano': Waiting for transfers to finish
2025/04/13 03:30:59 INFO  : potato3: Moved (server-side)
2025/04/13 03:30:59 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-tihibef9hore"
2025/04/13 03:31:00 DEBUG : files root 'rclone-test-tihibef9hore': Using server-side directory move
2025/04/13 03:31:01 INFO  : files root 'rclone-test-tihibef9hore': Server side directory move succeeded
2025/04/13 03:31:01 ERROR : : error listing: directory not found
2025/04/13 03:31:01 DEBUG : files root 'rclone-test-tihibef9hore': Purge remote
2025/04/13 03:31:01 DEBUG : files root 'rclone-test-leyojib7jano': Purge remote
2025/04/13 03:31:02 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (9.62s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:31:02 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-futadid3quru"
    sync_test.go:1705: Server side move (if possible) files root 'rclone-test-waseqex3zogu' -> files root 'rclone-test-futadid3quru'
2025/04/13 03:31:09 DEBUG : empty space: Excluded (Size Filter)
2025/04/13 03:31:09 DEBUG : empty space: Excluded
2025/04/13 03:31:09 DEBUG : empty space: Excluded (Size Filter)
2025/04/13 03:31:09 DEBUG : empty space: Excluded
2025/04/13 03:31:09 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/13 03:31:09 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/04/13 03:31:09 DEBUG : files root 'rclone-test-futadid3quru': Waiting for checks to finish
2025/04/13 03:31:09 DEBUG : files root 'rclone-test-futadid3quru': Waiting for transfers to finish
2025/04/13 03:31:10 INFO  : potato3: Deleted
2025/04/13 03:31:10 INFO  : potato3: Moved (server-side)
2025/04/13 03:31:10 INFO  : potato2: Moved (server-side)
2025/04/13 03:31:11 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-japafus0davo"
2025/04/13 03:31:11 DEBUG : empty space: Excluded (Size Filter)
2025/04/13 03:31:11 DEBUG : empty space: Excluded
2025/04/13 03:31:11 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/13 03:31:11 DEBUG : potato3: Need to transfer - File not found at Destination
2025/04/13 03:31:11 DEBUG : files root 'rclone-test-japafus0davo': Waiting for checks to finish
2025/04/13 03:31:11 DEBUG : files root 'rclone-test-japafus0davo': Waiting for transfers to finish
2025/04/13 03:31:12 INFO  : potato2: Moved (server-side)
2025/04/13 03:31:12 INFO  : potato3: Moved (server-side)
2025/04/13 03:31:12 DEBUG : files root 'rclone-test-japafus0davo': Purge remote
2025/04/13 03:31:12 DEBUG : files root 'rclone-test-futadid3quru': Purge remote
--- PASS: TestServerSideMoveWithFilter (11.51s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:31:14 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-tobihix6time"
2025/04/13 03:31:17 INFO  : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) files root 'rclone-test-waseqex3zogu' -> files root 'rclone-test-tobihix6time'
2025/04/13 03:31:21 DEBUG : files root 'rclone-test-tobihix6time': Using server-side directory move
2025/04/13 03:31:21 INFO  : files root 'rclone-test-tobihix6time': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/04/13 03:31:21 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/13 03:31:21 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2025/04/13 03:31:21 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1s)
2025/04/13 03:31:21 DEBUG : empty space: Unchanged skipping
2025/04/13 03:31:21 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/04/13 03:31:21 DEBUG : files root 'rclone-test-tobihix6time': Waiting for checks to finish
2025/04/13 03:31:21 INFO  : potato3: Deleted
2025/04/13 03:31:21 INFO  : empty space: Deleted
2025/04/13 03:31:21 DEBUG : files root 'rclone-test-tobihix6time': Waiting for transfers to finish
2025/04/13 03:31:22 INFO  : potato2: Moved (server-side)
2025/04/13 03:31:22 INFO  : potato3: Moved (server-side)
2025/04/13 03:31:22 INFO  : tomatoDir: Removing directory
2025/04/13 03:31:22 DEBUG : files root 'rclone-test-waseqex3zogu': deleted 1 directories
2025/04/13 03:31:22 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-vuqabax8peke"
2025/04/13 03:31:23 INFO  : tomatoDir: Making directory
2025/04/13 03:31:23 DEBUG : files root 'rclone-test-vuqabax8peke': Using server-side directory move
2025/04/13 03:31:24 INFO  : files root 'rclone-test-vuqabax8peke': Server side directory move succeeded
2025/04/13 03:31:24 ERROR : : error listing: directory not found
2025/04/13 03:31:24 ERROR : : error listing: directory not found
2025/04/13 03:31:24 DEBUG : files root 'rclone-test-vuqabax8peke': Purge remote
2025/04/13 03:31:24 DEBUG : files root 'rclone-test-tobihix6time': Purge remote
2025/04/13 03:31:24 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (11.37s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.26s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:31:25 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/rclone-sync-test"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncOverlap (2.02s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:31:27 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/rclone-sync-test"
2025/04/13 03:31:28 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/rclone-sync-test-include/layer2"
2025/04/13 03:31:29 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/rclone-sync-test-ignore-file"
2025/04/13 03:31:31 DEBUG : rclone-sync-test: Excluded
2025/04/13 03:31:31 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/04/13 03:31:31 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/04/13 03:31:31 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/04/13 03:31:31 DEBUG : files root 'rclone-test-waseqex3zogu/rclone-sync-test': Waiting for checks to finish
2025/04/13 03:31:31 DEBUG : files root 'rclone-test-waseqex3zogu/rclone-sync-test': Waiting for transfers to finish
2025/04/13 03:31:31 DEBUG : Waiting for deletions to finish
2025/04/13 03:31:31 INFO  : There was nothing to transfer
2025/04/13 03:31:32 DEBUG : rclone-sync-test: Excluded
2025/04/13 03:31:32 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/04/13 03:31:32 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/04/13 03:31:32 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:31:32 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:31:32 DEBUG : Waiting for deletions to finish
2025/04/13 03:31:32 INFO  : rclone-sync-test-include: Removing directory
2025/04/13 03:31:32 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:32 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/04/13 03:31:32 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:32 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/04/13 03:31:33 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:33 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2025/04/13 03:31:33 DEBUG : pacer: low level retry 4/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:33 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2025/04/13 03:31:33 DEBUG : pacer: low level retry 5/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:33 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2025/04/13 03:31:33 DEBUG : pacer: low level retry 6/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:33 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2025/04/13 03:31:33 DEBUG : pacer: low level retry 7/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:33 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2025/04/13 03:31:34 DEBUG : pacer: low level retry 8/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:34 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/04/13 03:31:35 DEBUG : pacer: low level retry 9/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:37 DEBUG : pacer: low level retry 10/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:37 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/04/13 03:31:37 DEBUG : files root 'rclone-test-waseqex3zogu': failed to delete 1 directories
2025/04/13 03:31:37 INFO  : There was nothing to transfer
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:31:39 DEBUG : pacer: Reducing sleep to 1.5s
2025/04/13 03:31:41 DEBUG : pacer: Reducing sleep to 1.125s
2025/04/13 03:31:43 DEBUG : pacer: Reducing sleep to 843.75ms
2025/04/13 03:31:43 DEBUG : rclone-sync-test: Excluded
2025/04/13 03:31:44 DEBUG : pacer: Reducing sleep to 632.8125ms
2025/04/13 03:31:44 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/04/13 03:31:45 DEBUG : pacer: Reducing sleep to 474.609375ms
2025/04/13 03:31:45 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/04/13 03:31:45 DEBUG : pacer: Reducing sleep to 355.957031ms
2025/04/13 03:31:46 DEBUG : pacer: Reducing sleep to 266.967773ms
2025/04/13 03:31:46 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/04/13 03:31:46 DEBUG : files root 'rclone-test-waseqex3zogu/rclone-sync-test-include/layer2': Waiting for checks to finish
2025/04/13 03:31:46 DEBUG : files root 'rclone-test-waseqex3zogu/rclone-sync-test-include/layer2': Waiting for transfers to finish
2025/04/13 03:31:46 DEBUG : Waiting for deletions to finish
2025/04/13 03:31:46 INFO  : There was nothing to transfer
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:31:46 DEBUG : pacer: Reducing sleep to 200.225829ms
2025/04/13 03:31:46 DEBUG : pacer: Reducing sleep to 150.169371ms
2025/04/13 03:31:47 DEBUG : pacer: Reducing sleep to 112.627028ms
2025/04/13 03:31:47 DEBUG : rclone-sync-test: Excluded
2025/04/13 03:31:47 DEBUG : pacer: Reducing sleep to 84.470271ms
2025/04/13 03:31:47 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/04/13 03:31:47 DEBUG : pacer: Reducing sleep to 63.352703ms
2025/04/13 03:31:47 DEBUG : pacer: Reducing sleep to 47.514527ms
2025/04/13 03:31:47 DEBUG : pacer: Reducing sleep to 35.635895ms
2025/04/13 03:31:47 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/04/13 03:31:47 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:31:47 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:31:47 DEBUG : Waiting for deletions to finish
2025/04/13 03:31:47 INFO  : rclone-sync-test-include: Removing directory
2025/04/13 03:31:47 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:47 DEBUG : pacer: Rate limited, increasing sleep to 71.27179ms
2025/04/13 03:31:47 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:47 DEBUG : pacer: Rate limited, increasing sleep to 142.54358ms
2025/04/13 03:31:48 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:48 DEBUG : pacer: Rate limited, increasing sleep to 285.08716ms
2025/04/13 03:31:48 DEBUG : pacer: low level retry 4/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:48 DEBUG : pacer: Rate limited, increasing sleep to 570.17432ms
2025/04/13 03:31:48 DEBUG : pacer: low level retry 5/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:48 DEBUG : pacer: Rate limited, increasing sleep to 1.14034864s
2025/04/13 03:31:49 DEBUG : pacer: low level retry 6/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:49 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/04/13 03:31:50 DEBUG : pacer: low level retry 7/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:52 DEBUG : pacer: low level retry 8/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:54 DEBUG : pacer: low level retry 9/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:56 DEBUG : pacer: low level retry 10/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/rclone-sync-test-include not empty`)
2025/04/13 03:31:56 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/04/13 03:31:56 DEBUG : files root 'rclone-test-waseqex3zogu': failed to delete 1 directories
2025/04/13 03:31:56 INFO  : There was nothing to transfer
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:31:58 DEBUG : pacer: Reducing sleep to 1.5s
2025/04/13 03:31:58 DEBUG : : Excluded
2025/04/13 03:32:00 DEBUG : pacer: Reducing sleep to 1.125s
2025/04/13 03:32:01 DEBUG : pacer: Reducing sleep to 843.75ms
2025/04/13 03:32:01 DEBUG : rclone-sync-test: Excluded
2025/04/13 03:32:02 DEBUG : pacer: Reducing sleep to 632.8125ms
2025/04/13 03:32:02 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/04/13 03:32:03 DEBUG : pacer: Reducing sleep to 474.609375ms
2025/04/13 03:32:03 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/04/13 03:32:04 DEBUG : pacer: Reducing sleep to 355.957031ms
2025/04/13 03:32:04 DEBUG : pacer: Reducing sleep to 266.967773ms
2025/04/13 03:32:04 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/04/13 03:32:04 DEBUG : files root 'rclone-test-waseqex3zogu/rclone-sync-test-ignore-file': Waiting for checks to finish
2025/04/13 03:32:04 DEBUG : files root 'rclone-test-waseqex3zogu/rclone-sync-test-ignore-file': Waiting for transfers to finish
2025/04/13 03:32:04 DEBUG : Waiting for deletions to finish
2025/04/13 03:32:04 INFO  : There was nothing to transfer
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:32:05 DEBUG : pacer: Reducing sleep to 200.225829ms
2025/04/13 03:32:05 DEBUG : pacer: Reducing sleep to 150.169371ms
2025/04/13 03:32:05 DEBUG : pacer: Reducing sleep to 112.627028ms
2025/04/13 03:32:05 DEBUG : pacer: Reducing sleep to 84.470271ms
2025/04/13 03:32:05 DEBUG : pacer: Reducing sleep to 63.352703ms
2025/04/13 03:32:05 DEBUG : pacer: Reducing sleep to 47.514527ms
2025/04/13 03:32:06 DEBUG : pacer: Reducing sleep to 35.635895ms
2025/04/13 03:32:06 DEBUG : pacer: Reducing sleep to 26.726921ms
2025/04/13 03:32:06 DEBUG : pacer: Reducing sleep to 20.04519ms
2025/04/13 03:32:06 DEBUG : pacer: Reducing sleep to 15.033892ms
2025/04/13 03:32:06 DEBUG : pacer: Reducing sleep to 11.275419ms
2025/04/13 03:32:06 DEBUG : pacer: Reducing sleep to 10ms
--- PASS: TestSyncOverlapWithFilter (43.40s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:32:11 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/dst"
2025/04/13 03:32:11 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/CompareDest"
2025/04/13 03:32:13 DEBUG : one: Need to transfer - File not found at Destination
2025/04/13 03:32:13 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:32:13 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:32:14 DEBUG : one: Dst hash empty - aborting Src hash check
2025/04/13 03:32:14 INFO  : one: Copied (new)
2025/04/13 03:32:14 DEBUG : Waiting for deletions to finish
2025/04/13 03:32:15 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:32:15 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/13 03:32:15 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:32:16 DEBUG : one: Dst hash empty - aborting Src hash check
2025/04/13 03:32:16 INFO  : one: Copied (replaced existing)
2025/04/13 03:32:16 DEBUG : Waiting for deletions to finish
2025/04/13 03:32:19 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/13 03:32:19 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:32:19 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:32:19 DEBUG : one: Destination found in --compare-dest, skipping
2025/04/13 03:32:19 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:32:19 DEBUG : Waiting for deletions to finish
2025/04/13 03:32:19 INFO  : There was nothing to transfer
2025/04/13 03:32:20 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/13 03:32:21 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:32:21 DEBUG : two: Destination found in --compare-dest, skipping
2025/04/13 03:32:21 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:32:21 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:32:21 DEBUG : one: Destination found in --compare-dest, skipping
2025/04/13 03:32:21 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:32:21 DEBUG : Waiting for deletions to finish
2025/04/13 03:32:21 INFO  : There was nothing to transfer
2025/04/13 03:32:21 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/13 03:32:22 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:32:22 DEBUG : two: Destination found in --compare-dest, skipping
2025/04/13 03:32:22 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:32:22 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:32:22 DEBUG : one: Destination found in --compare-dest, skipping
2025/04/13 03:32:22 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:32:22 DEBUG : Waiting for deletions to finish
2025/04/13 03:32:22 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2025/04/13 03:32:23 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/13 03:32:23 DEBUG : two: Sizes differ (src 5 vs dst 3)
2025/04/13 03:32:23 DEBUG : two: Need to transfer - File not found at Destination
2025/04/13 03:32:23 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:32:23 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:32:23 DEBUG : one: Destination found in --compare-dest, skipping
2025/04/13 03:32:23 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:32:24 DEBUG : two: Dst hash empty - aborting Src hash check
2025/04/13 03:32:24 INFO  : two: Copied (new)
2025/04/13 03:32:24 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncCompareDest (14.88s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:32:28 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/dest"
2025/04/13 03:32:28 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/pre-dest1"
2025/04/13 03:32:29 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/pre-dest2"
2025/04/13 03:32:30 DEBUG : 1: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:32:30 DEBUG : 1: Destination found in --compare-dest, skipping
2025/04/13 03:32:30 DEBUG : 2: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:32:30 DEBUG : 2: Destination found in --compare-dest, skipping
2025/04/13 03:32:31 DEBUG : 3: Need to transfer - File not found at Destination
2025/04/13 03:32:31 DEBUG : files root 'rclone-test-waseqex3zogu/dest': Waiting for checks to finish
2025/04/13 03:32:31 DEBUG : files root 'rclone-test-waseqex3zogu/dest': Waiting for transfers to finish
2025/04/13 03:32:32 DEBUG : 3: Dst hash empty - aborting Src hash check
2025/04/13 03:32:32 INFO  : 3: Copied (new)
2025/04/13 03:32:32 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncMultipleCompareDest (8.84s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:32:34 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/dst"
2025/04/13 03:32:35 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/CopyDest"
2025/04/13 03:32:35 DEBUG : one: Need to transfer - File not found at Destination
2025/04/13 03:32:35 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:32:35 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:32:36 DEBUG : one: Dst hash empty - aborting Src hash check
2025/04/13 03:32:36 INFO  : one: Copied (new)
2025/04/13 03:32:36 DEBUG : Waiting for deletions to finish
2025/04/13 03:32:37 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/13 03:32:37 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:32:37 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:32:38 DEBUG : one: Dst hash empty - aborting Src hash check
2025/04/13 03:32:38 INFO  : one: Copied (replaced existing)
2025/04/13 03:32:38 DEBUG : Waiting for deletions to finish
2025/04/13 03:32:40 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/BackupDir"
2025/04/13 03:32:41 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/13 03:32:41 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:32:41 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:32:41 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/13 03:32:42 INFO  : one: Moved (server-side)
2025/04/13 03:32:47 DEBUG : one: Dst hash empty - aborting Src hash check
2025/04/13 03:32:47 DEBUG : one: Src hash empty - aborting Dst hash check
2025/04/13 03:32:47 INFO  : one: Copied (server-side copy)
2025/04/13 03:32:47 DEBUG : one: Destination found in --copy-dest, using server-side copy
2025/04/13 03:32:47 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:32:47 DEBUG : Waiting for deletions to finish
2025/04/13 03:32:49 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:32:49 DEBUG : one: Unchanged skipping
2025/04/13 03:32:49 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:32:51 DEBUG : two: Dst hash empty - aborting Src hash check
2025/04/13 03:32:51 DEBUG : two: Src hash empty - aborting Dst hash check
2025/04/13 03:32:51 INFO  : two: Copied (server-side copy)
2025/04/13 03:32:51 DEBUG : two: Destination found in --copy-dest, using server-side copy
2025/04/13 03:32:51 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:32:51 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:32:51 DEBUG : Waiting for deletions to finish
2025/04/13 03:32:52 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:32:52 DEBUG : one: Unchanged skipping
2025/04/13 03:32:52 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:32:52 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:32:52 DEBUG : two: Unchanged skipping
2025/04/13 03:32:52 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:32:52 DEBUG : Waiting for deletions to finish
2025/04/13 03:32:52 INFO  : There was nothing to transfer
2025/04/13 03:32:53 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:32:53 DEBUG : one: Unchanged skipping
2025/04/13 03:32:53 DEBUG : three: Sizes differ (src 7 vs dst 5)
2025/04/13 03:32:53 DEBUG : three: Destination not found in --copy-dest
2025/04/13 03:32:53 DEBUG : three: Need to transfer - File not found at Destination
2025/04/13 03:32:53 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2025/04/13 03:32:53 DEBUG : two: Unchanged skipping
2025/04/13 03:32:53 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:32:53 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:32:54 DEBUG : three: Dst hash empty - aborting Src hash check
2025/04/13 03:32:54 INFO  : three: Copied (new)
2025/04/13 03:32:54 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncCopyDest (22.09s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:32:59 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/dst"
2025/04/13 03:33:00 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/backup"
2025/04/13 03:33:01 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/04/13 03:33:01 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:33:01 DEBUG : two: Unchanged skipping
2025/04/13 03:33:01 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:33:02 INFO  : one: Moved (server-side)
2025/04/13 03:33:02 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:33:04 DEBUG : one: Dst hash empty - aborting Src hash check
2025/04/13 03:33:04 INFO  : one: Copied (new)
2025/04/13 03:33:04 DEBUG : Waiting for deletions to finish
2025/04/13 03:33:04 INFO  : three.txt: Moved (server-side)
2025/04/13 03:33:04 INFO  : three.txt: Moved into backup dir
2025/04/13 03:33:07 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/04/13 03:33:07 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:33:07 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:33:07 DEBUG : two: Unchanged skipping
2025/04/13 03:33:08 INFO  : one: Deleted
2025/04/13 03:33:08 INFO  : one: Moved (server-side)
2025/04/13 03:33:08 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:33:09 DEBUG : pacer: low level retry 1/10 (error Put "https://s3.amazonaws.com/objects.brickftp.com/metadata/126732/af57e026-ace6-4916-8400-2f063228bf1b?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=AKIAIEWLY3MN4YGZQOWA%2F20250413%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20250413T033309Z&X-Amz-Expires=900&X-Amz-SignedHeaders=host&partNumber=1&response-content-type=application%2Foctet-stream&uploadId=2BRmAEkmDulHxz6gPF5kyYGuZVpD.uyZ6yyXkjJ1.gT1TyJdGzzV45vLJb2WVCIJolyCBzy3yZwrARXPZZhkIT6xEDriz6PZgYGBlMk6L5hdHIa0qgefMlJ2ltttZOEW&X-Amz-Signature=2d3d0abf42c704b0a0022733b70e48277947eb39adb318b295198b418b0552c0": net/http: HTTP/1.x transport connection broken: http: ContentLength=5 with Body length 0)
2025/04/13 03:33:09 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/04/13 03:33:11 DEBUG : pacer: Reducing sleep to 15ms
2025/04/13 03:33:11 DEBUG : pacer: Reducing sleep to 11.25ms
2025/04/13 03:33:11 ERROR : one: corrupted on transfer: sizes differ src(Local file system at /tmp/rclone2741615887) 5 vs dst(files root 'rclone-test-waseqex3zogu/dst') 0
2025/04/13 03:33:11 INFO  : one: Removing failed copy
2025/04/13 03:33:11 DEBUG : pacer: Reducing sleep to 10ms
2025/04/13 03:33:11 ERROR : files root 'rclone-test-waseqex3zogu/dst': not deleting files as there were IO errors
2025/04/13 03:33:11 ERROR : files root 'rclone-test-waseqex3zogu/dst': not deleting directories as there were IO errors
    sync_test.go:2410: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2410
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2427
        	Error:      	Received unexpected error:
        	            	corrupted on transfer: sizes differ src(Local file system at /tmp/rclone2741615887) 5 vs dst(files root 'rclone-test-waseqex3zogu/dst') 0
        	Test:       	TestSyncBackupDir
--- FAIL: TestSyncBackupDir (17.20s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:33:16 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/dst"
2025/04/13 03:33:17 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/backup"
2025/04/13 03:33:18 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/04/13 03:33:18 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:33:18 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:33:18 DEBUG : two: Unchanged skipping
2025/04/13 03:33:19 INFO  : one: Moved (server-side) to: one.bak
2025/04/13 03:33:19 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:33:21 DEBUG : one: Dst hash empty - aborting Src hash check
2025/04/13 03:33:21 INFO  : one: Copied (new)
2025/04/13 03:33:21 DEBUG : Waiting for deletions to finish
2025/04/13 03:33:22 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/04/13 03:33:22 INFO  : three.txt: Moved into backup dir
2025/04/13 03:33:24 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/04/13 03:33:24 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:33:24 DEBUG : two: Unchanged skipping
2025/04/13 03:33:24 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:33:25 INFO  : one.bak: Deleted
2025/04/13 03:33:25 INFO  : one: Moved (server-side) to: one.bak
2025/04/13 03:33:25 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:33:27 DEBUG : one: Dst hash empty - aborting Src hash check
2025/04/13 03:33:27 INFO  : one: Copied (new)
2025/04/13 03:33:27 DEBUG : Waiting for deletions to finish
2025/04/13 03:33:27 INFO  : three.txt.bak: Deleted
2025/04/13 03:33:28 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/04/13 03:33:28 INFO  : three.txt: Moved into backup dir
--- PASS: TestSyncBackupDirWithSuffix (15.90s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3
    fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3
    fstest.go:299: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:299
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2377
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2435
        	Error:      	Should be true
        	Test:       	TestSyncBackupDirWithSuffixKeepExtension
        	Messages:   	listing wrong, want
        	            	  dst/one (3), dst/three.txt (5), dst/two (3) got
        	            	  
    fstest.go:197: Not found "dst/one"
    fstest.go:197: Not found "dst/two"
    fstest.go:197: Not found "dst/three.txt"
    fstest.go:200: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:200
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:304
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2377
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2435
        	Error:      	Not equal: 
        	            	expected: 0
        	            	actual  : 3
        	Test:       	TestSyncBackupDirWithSuffixKeepExtension
        	Messages:   	3 objects not found
2025/04/13 03:33:39 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/dst"
2025/04/13 03:33:40 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/backup"
2025/04/13 03:33:41 DEBUG : one: Need to transfer - File not found at Destination
2025/04/13 03:33:41 DEBUG : two: Need to transfer - File not found at Destination
2025/04/13 03:33:41 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:33:41 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:33:42 DEBUG : one: Dst hash empty - aborting Src hash check
2025/04/13 03:33:42 INFO  : one: Copied (new)
2025/04/13 03:33:45 DEBUG : two: Dst hash empty - aborting Src hash check
2025/04/13 03:33:45 INFO  : two: Copied (new)
2025/04/13 03:33:45 DEBUG : Waiting for deletions to finish
    fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3
    fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3
    fstest.go:299: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:299
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2398
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2435
        	Error:      	Should be true
        	Test:       	TestSyncBackupDirWithSuffixKeepExtension
        	Messages:   	listing wrong, want
        	            	  backup/one-2019-01-01 (3), backup/three-2019-01-01.txt (5), dst/one (4), dst/two (3) got
        	            	  dst/one (4), dst/two (3)
    fstest.go:197: Not found "backup/one-2019-01-01"
    fstest.go:197: Not found "backup/three-2019-01-01.txt"
    fstest.go:200: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:200
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:304
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2398
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2435
        	Error:      	Not equal: 
        	            	expected: 0
        	            	actual  : 2
        	Test:       	TestSyncBackupDirWithSuffixKeepExtension
        	Messages:   	2 objects not found
    fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3
    fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3
    fstest.go:299: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:299
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2404
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2435
        	Error:      	Should be true
        	Test:       	TestSyncBackupDirWithSuffixKeepExtension
        	Messages:   	listing wrong, want
        	            	  backup/one-2019-01-01 (3), backup/three-2019-01-01.txt (5), dst/one (4), dst/three.txt (6), dst/two (3) got
        	            	  dst/one (4), dst/three.txt (6), dst/two (3)
    fstest.go:197: Not found "backup/three-2019-01-01.txt"
    fstest.go:197: Not found "backup/one-2019-01-01"
    fstest.go:200: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:200
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:304
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2404
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2435
        	Error:      	Not equal: 
        	            	expected: 0
        	            	actual  : 2
        	Test:       	TestSyncBackupDirWithSuffixKeepExtension
        	Messages:   	2 objects not found
2025/04/13 03:34:04 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/04/13 03:34:04 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:34:04 DEBUG : two: Unchanged skipping
2025/04/13 03:34:04 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:34:06 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/04/13 03:34:06 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:34:07 DEBUG : one: Dst hash empty - aborting Src hash check
2025/04/13 03:34:07 INFO  : one: Copied (new)
2025/04/13 03:34:07 DEBUG : Waiting for deletions to finish
2025/04/13 03:34:08 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/04/13 03:34:08 INFO  : three.txt: Moved into backup dir
--- FAIL: TestSyncBackupDirWithSuffixKeepExtension (40.27s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:34:13 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/dst"
2025/04/13 03:34:14 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/04/13 03:34:14 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:34:14 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:34:14 DEBUG : two: Unchanged skipping
2025/04/13 03:34:15 INFO  : one: Moved (server-side) to: one.bak
2025/04/13 03:34:15 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:34:16 DEBUG : one: Dst hash empty - aborting Src hash check
2025/04/13 03:34:16 INFO  : one: Copied (new)
2025/04/13 03:34:16 DEBUG : Waiting for deletions to finish
2025/04/13 03:34:16 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/04/13 03:34:16 INFO  : three.txt: Moved into backup dir
2025/04/13 03:34:18 DEBUG : one.bak: Excluded (Path Filter)
2025/04/13 03:34:18 DEBUG : one.bak: Excluded
2025/04/13 03:34:18 DEBUG : three.txt.bak: Excluded (Path Filter)
2025/04/13 03:34:18 DEBUG : three.txt.bak: Excluded
2025/04/13 03:34:18 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/04/13 03:34:18 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for checks to finish
2025/04/13 03:34:18 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:34:18 DEBUG : two: Unchanged skipping
2025/04/13 03:34:18 INFO  : one.bak: Deleted
2025/04/13 03:34:19 INFO  : one: Moved (server-side) to: one.bak
2025/04/13 03:34:19 DEBUG : files root 'rclone-test-waseqex3zogu/dst': Waiting for transfers to finish
2025/04/13 03:34:19 DEBUG : one: Dst hash empty - aborting Src hash check
2025/04/13 03:34:19 INFO  : one: Copied (new)
2025/04/13 03:34:19 DEBUG : Waiting for deletions to finish
2025/04/13 03:34:20 INFO  : three.txt.bak: Deleted
2025/04/13 03:34:20 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/04/13 03:34:20 INFO  : three.txt: Moved into backup dir
--- PASS: TestSyncBackupDirSuffixOnly (11.89s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:34:24 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/dst"
2025/04/13 03:34:25 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/04/13 03:34:27 INFO  : one: Moved (server-side) to: one.bak
2025/04/13 03:34:27 DEBUG : one: Dst hash empty - aborting Src hash check
2025/04/13 03:34:27 INFO  : one: Copied (new)
2025/04/13 03:34:28 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:34:28 DEBUG : two: Unchanged skipping
2025/04/13 03:34:28 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/04/13 03:34:28 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/04/13 03:34:29 DEBUG : three.txt: Dst hash empty - aborting Src hash check
2025/04/13 03:34:29 INFO  : three.txt: Copied (new)
2025/04/13 03:34:30 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/04/13 03:34:31 INFO  : one.bak: Deleted
2025/04/13 03:34:31 INFO  : one: Moved (server-side) to: one.bak
2025/04/13 03:34:32 DEBUG : one: Dst hash empty - aborting Src hash check
2025/04/13 03:34:32 INFO  : one: Copied (new)
2025/04/13 03:34:32 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:34:32 DEBUG : two: Unchanged skipping
2025/04/13 03:34:32 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/04/13 03:34:32 INFO  : three.txt.bak: Deleted
2025/04/13 03:34:33 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/04/13 03:34:34 DEBUG : three.txt: Dst hash empty - aborting Src hash check
2025/04/13 03:34:34 INFO  : three.txt: Copied (new)
--- PASS: TestSyncSuffix (14.61s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:34:39 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-waseqex3zogu/dst"
2025/04/13 03:34:40 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/04/13 03:34:41 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/04/13 03:34:42 DEBUG : one: Dst hash empty - aborting Src hash check
2025/04/13 03:34:42 INFO  : one: Copied (new)
2025/04/13 03:34:42 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:34:42 DEBUG : two: Unchanged skipping
2025/04/13 03:34:43 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/04/13 03:34:43 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/04/13 03:34:44 DEBUG : three.txt: Dst hash empty - aborting Src hash check
2025/04/13 03:34:44 INFO  : three.txt: Copied (new)
2025/04/13 03:34:45 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/04/13 03:34:45 INFO  : one-2019-01-01: Deleted
2025/04/13 03:34:46 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/04/13 03:34:47 DEBUG : one: Dst hash empty - aborting Src hash check
2025/04/13 03:34:47 INFO  : one: Copied (new)
2025/04/13 03:34:47 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:34:47 DEBUG : two: Unchanged skipping
2025/04/13 03:34:47 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/04/13 03:34:47 INFO  : three-2019-01-01.txt: Deleted
2025/04/13 03:34:48 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/04/13 03:34:48 DEBUG : three.txt: Dst hash empty - aborting Src hash check
2025/04/13 03:34:48 INFO  : three.txt: Copied (new)
--- PASS: TestSyncSuffixKeepExtension (14.74s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:34:52 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2025/04/13 03:34:52 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:34:52 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:34:53 DEBUG : Testêé: Dst hash empty - aborting Src hash check
2025/04/13 03:34:53 INFO  : Testêé: Copied (replaced existing) to: Testêé
2025/04/13 03:34:53 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (2.52s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:34:54 DEBUG : existing: Need to transfer - File not found at Destination
2025/04/13 03:34:54 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:34:54 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:34:55 DEBUG : existing: Dst hash empty - aborting Src hash check
2025/04/13 03:34:55 INFO  : existing: Copied (new)
2025/04/13 03:34:55 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:34:55 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2025/04/13 03:34:55 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:34:55 ERROR : existing: Source and destination exist but do not match: immutable file modified
2025/04/13 03:34:55 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:34:55 ERROR : files root 'rclone-test-waseqex3zogu': not deleting files as there were IO errors
2025/04/13 03:34:55 ERROR : files root 'rclone-test-waseqex3zogu': not deleting directories as there were IO errors
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncImmutable (2.49s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    sync_test.go:2606: Skipping test as local or remote are case-insensitive
--- SKIP: TestSyncIgnoreCase (0.27s)
=== RUN   TestFixCase
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:35:00 DEBUG : existing: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:00 DEBUG : existing: Unchanged skipping
2025/04/13 03:35:00 DEBUG : existingbutdifferent: Sizes differ (src 5 vs dst 8)
2025/04/13 03:35:01 DEBUG : EXISTING: moving to existing-rclone-move-xetoyig3
2025/04/13 03:35:01 INFO  : SUBDIRA: Set directory modification time (using DirSetModTime)
2025/04/13 03:35:01 DEBUG : Added delayed dir = "SUBDIRA", newDst=SUBDIRA
2025/04/13 03:35:01 DEBUG : EXISTINGBUTDIFFERENT: moving to existingbutdifferent-rclone-move-kadanav4
2025/04/13 03:35:01 INFO  : EXISTING: Moved (server-side) to: existing-rclone-move-xetoyig3
2025/04/13 03:35:01 DEBUG : EXISTING: moving to existing
2025/04/13 03:35:01 INFO  : EXISTINGBUTDIFFERENT: Moved (server-side) to: existingbutdifferent-rclone-move-kadanav4
2025/04/13 03:35:01 DEBUG : EXISTINGBUTDIFFERENT: moving to existingbutdifferent
2025/04/13 03:35:02 INFO  : existing-rclone-move-xetoyig3: Moved (server-side) to: existing
2025/04/13 03:35:02 INFO  : EXISTING: Moved (server-side) to: existing
2025/04/13 03:35:02 INFO  : EXISTING: Fixed case by renaming to: existing
2025/04/13 03:35:02 INFO  : existingbutdifferent-rclone-move-kadanav4: Moved (server-side) to: existingbutdifferent
2025/04/13 03:35:02 INFO  : EXISTINGBUTDIFFERENT: Moved (server-side) to: existingbutdifferent
2025/04/13 03:35:02 INFO  : EXISTINGBUTDIFFERENT: Fixed case by renaming to: existingbutdifferent
2025/04/13 03:35:02 INFO  : SUBDIRA: Fixed case by renaming to: subdira
2025/04/13 03:35:02 INFO  : SUBDIRA/subdirb: Set directory modification time (using DirSetModTime)
2025/04/13 03:35:02 DEBUG : Added delayed dir = "SUBDIRA/subdirb", newDst=SUBDIRA/subdirb
2025/04/13 03:35:02 DEBUG : existingbutdifferent: Dst hash empty - aborting Src hash check
2025/04/13 03:35:02 INFO  : existingbutdifferent: Copied (replaced existing)
2025/04/13 03:35:03 INFO  : SUBDIRA/subdirb: Fixed case by renaming to: subdira/subdirb
2025/04/13 03:35:04 INFO  : SUBDIRA/subdirb/SUBDIRC: Set directory modification time (using DirSetModTime)
2025/04/13 03:35:04 DEBUG : Added delayed dir = "SUBDIRA/subdirb/SUBDIRC", newDst=SUBDIRA/subdirb/SUBDIRC
2025/04/13 03:35:05 INFO  : SUBDIRA/subdirb/SUBDIRC: Fixed case by renaming to: subdira/subdirb/subdirc
2025/04/13 03:35:05 DEBUG : subdira/subdirb/subdirc/hello: Sizes differ (src 5 vs dst 8)
2025/04/13 03:35:05 DEBUG : SUBDIRA/subdirb/SUBDIRC/HELLO: moving to subdira/subdirb/subdirc/hello-rclone-move-xininay7
2025/04/13 03:35:05 INFO  : SUBDIRA/subdirb/SUBDIRC/subdird: Set directory modification time (using DirSetModTime)
2025/04/13 03:35:05 DEBUG : Added delayed dir = "SUBDIRA/subdirb/SUBDIRC/subdird", newDst=SUBDIRA/subdirb/SUBDIRC/subdird
2025/04/13 03:35:06 INFO  : SUBDIRA/subdirb/SUBDIRC/HELLO: Moved (server-side) to: subdira/subdirb/subdirc/hello-rclone-move-xininay7
2025/04/13 03:35:06 DEBUG : SUBDIRA/subdirb/SUBDIRC/HELLO: moving to subdira/subdirb/subdirc/hello
2025/04/13 03:35:06 INFO  : subdira/subdirb/subdirc/hello-rclone-move-xininay7: Moved (server-side) to: subdira/subdirb/subdirc/hello
2025/04/13 03:35:06 INFO  : SUBDIRA/subdirb/SUBDIRC/HELLO: Moved (server-side) to: subdira/subdirb/subdirc/hello
2025/04/13 03:35:06 INFO  : SUBDIRA/subdirb/SUBDIRC/HELLO: Fixed case by renaming to: subdira/subdirb/subdirc/hello
2025/04/13 03:35:06 INFO  : SUBDIRA/subdirb/SUBDIRC/subdird: Fixed case by renaming to: subdira/subdirb/subdirc/subdird
2025/04/13 03:35:06 DEBUG : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: Sizes differ (src 5 vs dst 8)
2025/04/13 03:35:06 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:35:07 DEBUG : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: moving to subdira/subdirb/subdirc/subdird/filewithoutcasedifferences-rclone-move-mavalik3
2025/04/13 03:35:07 DEBUG : subdira/subdirb/subdirc/hello: Dst hash empty - aborting Src hash check
2025/04/13 03:35:07 INFO  : subdira/subdirb/subdirc/hello: Copied (replaced existing)
2025/04/13 03:35:07 INFO  : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: Moved (server-side) to: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences-rclone-move-mavalik3
2025/04/13 03:35:07 DEBUG : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: moving to subdira/subdirb/subdirc/subdird/filewithoutcasedifferences
2025/04/13 03:35:08 INFO  : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences-rclone-move-mavalik3: Moved (server-side) to: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences
2025/04/13 03:35:08 INFO  : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: Moved (server-side) to: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences
2025/04/13 03:35:08 INFO  : SUBDIRA/subdirb/SUBDIRC/subdird/filewithoutcasedifferences: Fixed case by renaming to: subdira/subdirb/subdirc/subdird/filewithoutcasedifferences
2025/04/13 03:35:08 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:35:08 DEBUG : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: Dst hash empty - aborting Src hash check
2025/04/13 03:35:08 INFO  : subdira/subdirb/subdirc/subdird/filewithoutcasedifferences: Copied (replaced existing)
2025/04/13 03:35:08 DEBUG : Waiting for deletions to finish
2025/04/13 03:35:11 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/subdira not empty`)
2025/04/13 03:35:11 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/04/13 03:35:11 DEBUG : pacer: Reducing sleep to 15ms
2025/04/13 03:35:11 DEBUG : pacer: Reducing sleep to 11.25ms
--- PASS: TestFixCase (14.94s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    sync_test.go:2674: This test only runs on local
2025/04/13 03:35:11 DEBUG : pacer: Reducing sleep to 10ms
=== RUN   TestMaxTransfer/Soft
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    sync_test.go:2674: This test only runs on local
=== RUN   TestMaxTransfer/Cautious
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (0.81s)
    --- SKIP: TestMaxTransfer/Hard (0.27s)
    --- SKIP: TestMaxTransfer/Soft (0.26s)
    --- SKIP: TestMaxTransfer/Cautious (0.27s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:35:42 DEBUG : both11: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both1: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both10: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both0: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:35:42 DEBUG : both11: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both12: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both1: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both13: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both13: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both14: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both10: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both15: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both15: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both16: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both16: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both17: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both0: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both18: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both12: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both19: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both14: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both2: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both17: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both3: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both3: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both4: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both18: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both5: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both19: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both6: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both6: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both7: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both7: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both8: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both8: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both9: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:35:42 DEBUG : both9: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both2: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both4: Unchanged skipping
2025/04/13 03:35:42 DEBUG : both5: Unchanged skipping
2025/04/13 03:35:42 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:35:42 DEBUG : Waiting for deletions to finish
2025/04/13 03:35:42 INFO  : only2: Deleted
2025/04/13 03:35:42 INFO  : only18: Deleted
2025/04/13 03:35:42 INFO  : only19: Deleted
2025/04/13 03:35:42 INFO  : only5: Deleted
2025/04/13 03:35:42 INFO  : only7: Deleted
2025/04/13 03:35:42 INFO  : only16: Deleted
2025/04/13 03:35:42 INFO  : only11: Deleted
2025/04/13 03:35:42 INFO  : only9: Deleted
2025/04/13 03:35:42 INFO  : only13: Deleted
2025/04/13 03:35:42 INFO  : only3: Deleted
2025/04/13 03:35:42 INFO  : only10: Deleted
2025/04/13 03:35:42 INFO  : only1: Deleted
2025/04/13 03:35:42 INFO  : only17: Deleted
2025/04/13 03:35:42 INFO  : only6: Deleted
2025/04/13 03:35:42 INFO  : only15: Deleted
2025/04/13 03:35:42 INFO  : only14: Deleted
2025/04/13 03:35:43 INFO  : only0: Deleted
2025/04/13 03:35:43 INFO  : only8: Deleted
2025/04/13 03:35:43 INFO  : only4: Deleted
2025/04/13 03:35:43 INFO  : only12: Deleted
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncConcurrentDelete (34.48s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:35:47 DEBUG : pacer: low level retry 1/10 (error Put "https://s3.amazonaws.com/objects.brickftp.com/metadata/126732/35687924-d7a3-4eb0-91a6-b4cb3e01d653?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=AKIAIEWLY3MN4YGZQOWA%2F20250413%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20250413T033547Z&X-Amz-Expires=900&X-Amz-SignedHeaders=host&partNumber=1&response-content-type=application%2Foctet-stream&uploadId=Js.Fw0l0paq5oRGojITBD7XpJJdWmknOq7nxx5slFsal05BQETAU2C6jnwZYoYwZy5aM1FkXb5wjCF5x4Y_r3hZ9kOcJ.wHZGNk9Bend5Nw_pwd1BQdj0UfMRGcBCmRG&X-Amz-Signature=6c46b9d32db456e9ae2f44b1bfd11c502af0631ef9c3838e244c7faeaa4a9636": net/http: HTTP/1.x transport connection broken: http: ContentLength=6 with Body length 0)
2025/04/13 03:35:47 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/04/13 03:35:49 DEBUG : pacer: Reducing sleep to 15ms
2025/04/13 03:35:49 DEBUG : pacer: Reducing sleep to 11.25ms
2025/04/13 03:35:50 DEBUG : pacer: Reducing sleep to 10ms
    fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3
    fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3
    fstest.go:299: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:299
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2744
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2762
        	Error:      	Should be true
        	Test:       	TestSyncConcurrentTruncate
        	Messages:   	listing wrong, want
        	            	  both0 (6), both1 (6), both10 (6), both11 (6), both12 (6), both13 (6), both14 (6), both15 (6), both16 (6), both17 (6), both18 (6), both19 (6), both2 (6), both3 (6), both4 (6), both5 (6), both6 (6), both7 (6), both8 (6), both9 (6), only0 (6), only1 (6), only10 (6), only11 (6), only12 (6), only13 (6), only14 (6), only15 (6), only16 (6), only17 (6), only18 (6), only19 (6), only2 (6), only3 (6), only4 (6), only5 (6), only6 (6), only7 (6), only8 (6), only9 (6) got
        	            	  both0 (0), both1 (6), both10 (6), both11 (6), both12 (6), both13 (6), both14 (6), both15 (6), both16 (6), both17 (6), both18 (6), both19 (6), both2 (6), both3 (6), both4 (6), both5 (6), both6 (6), both7 (6), both8 (6), both9 (6), only0 (6), only1 (6), only10 (6), only11 (6), only12 (6), only13 (6), only14 (6), only15 (6), only16 (6), only17 (6), only18 (6), only19 (6), only2 (6), only3 (6), only4 (6), only5 (6), only6 (6), only7 (6), only8 (6), only9 (6)
    fstest.go:144: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:144
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:189
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:344
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2744
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2762
        	Error:      	Not equal: 
        	            	expected: 6
        	            	actual  : 0
        	Test:       	TestSyncConcurrentTruncate
        	Messages:   	both0: size incorrect file=6 vs obj=0
2025/04/13 03:36:30 DEBUG : both0: Sizes differ (src 6 vs dst 0)
2025/04/13 03:36:30 DEBUG : both11: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : both10: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for checks to finish
2025/04/13 03:36:30 DEBUG : both1: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : both12: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : both11: Unchanged skipping
2025/04/13 03:36:30 DEBUG : both13: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : both13: Unchanged skipping
2025/04/13 03:36:30 DEBUG : both14: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : both14: Unchanged skipping
2025/04/13 03:36:30 DEBUG : both15: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : both15: Unchanged skipping
2025/04/13 03:36:30 DEBUG : both16: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : both10: Unchanged skipping
2025/04/13 03:36:30 DEBUG : both17: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : both17: Unchanged skipping
2025/04/13 03:36:30 DEBUG : both18: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : both18: Unchanged skipping
2025/04/13 03:36:30 DEBUG : both19: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : both1: Unchanged skipping
2025/04/13 03:36:30 DEBUG : both2: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : both16: Unchanged skipping
2025/04/13 03:36:30 DEBUG : both3: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : both3: Unchanged skipping
2025/04/13 03:36:30 DEBUG : both4: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : both4: Unchanged skipping
2025/04/13 03:36:30 DEBUG : both5: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : both5: Unchanged skipping
2025/04/13 03:36:30 DEBUG : both6: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : both6: Unchanged skipping
2025/04/13 03:36:30 DEBUG : both7: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : both7: Unchanged skipping
2025/04/13 03:36:30 DEBUG : both8: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : both8: Unchanged skipping
2025/04/13 03:36:30 DEBUG : both9: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/04/13 03:36:30 DEBUG : both9: Unchanged skipping
2025/04/13 03:36:30 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : both12: Unchanged skipping
2025/04/13 03:36:30 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : both19: Unchanged skipping
2025/04/13 03:36:30 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : both2: Unchanged skipping
2025/04/13 03:36:30 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2025/04/13 03:36:30 DEBUG : files root 'rclone-test-waseqex3zogu': Waiting for transfers to finish
2025/04/13 03:36:31 DEBUG : both0: Dst hash empty - aborting Src hash check
2025/04/13 03:36:31 INFO  : both0: Copied (replaced existing)
2025/04/13 03:36:31 DEBUG : only0: Dst hash empty - aborting Src hash check
2025/04/13 03:36:31 INFO  : only0: Copied (replaced existing)
2025/04/13 03:36:31 DEBUG : only1: Dst hash empty - aborting Src hash check
2025/04/13 03:36:31 INFO  : only1: Copied (replaced existing)
2025/04/13 03:36:31 DEBUG : only10: Dst hash empty - aborting Src hash check
2025/04/13 03:36:31 INFO  : only10: Copied (replaced existing)
2025/04/13 03:36:32 DEBUG : only11: Dst hash empty - aborting Src hash check
2025/04/13 03:36:32 INFO  : only11: Copied (replaced existing)
2025/04/13 03:36:32 DEBUG : only15: Dst hash empty - aborting Src hash check
2025/04/13 03:36:32 INFO  : only15: Copied (replaced existing)
2025/04/13 03:36:32 DEBUG : only16: Dst hash empty - aborting Src hash check
2025/04/13 03:36:32 INFO  : only16: Copied (replaced existing)
2025/04/13 03:36:32 DEBUG : only17: Dst hash empty - aborting Src hash check
2025/04/13 03:36:32 INFO  : only17: Copied (replaced existing)
2025/04/13 03:36:33 DEBUG : only19: Dst hash empty - aborting Src hash check
2025/04/13 03:36:33 INFO  : only19: Copied (replaced existing)
2025/04/13 03:36:33 DEBUG : only18: Dst hash empty - aborting Src hash check
2025/04/13 03:36:33 INFO  : only18: Copied (replaced existing)
2025/04/13 03:36:33 DEBUG : only2: Dst hash empty - aborting Src hash check
2025/04/13 03:36:33 INFO  : only2: Copied (replaced existing)
2025/04/13 03:36:33 DEBUG : only3: Dst hash empty - aborting Src hash check
2025/04/13 03:36:33 INFO  : only3: Copied (replaced existing)
2025/04/13 03:36:34 DEBUG : only5: Dst hash empty - aborting Src hash check
2025/04/13 03:36:34 INFO  : only5: Copied (replaced existing)
2025/04/13 03:36:34 DEBUG : only6: Dst hash empty - aborting Src hash check
2025/04/13 03:36:34 INFO  : only6: Copied (replaced existing)
2025/04/13 03:36:34 DEBUG : only12: Dst hash empty - aborting Src hash check
2025/04/13 03:36:34 INFO  : only12: Copied (replaced existing)
2025/04/13 03:36:34 DEBUG : only7: Dst hash empty - aborting Src hash check
2025/04/13 03:36:34 INFO  : only7: Copied (replaced existing)
2025/04/13 03:36:34 DEBUG : only4: Dst hash empty - aborting Src hash check
2025/04/13 03:36:34 INFO  : only4: Copied (replaced existing)
2025/04/13 03:36:35 DEBUG : only14: Dst hash empty - aborting Src hash check
2025/04/13 03:36:35 INFO  : only14: Copied (replaced existing)
2025/04/13 03:36:35 DEBUG : only13: Dst hash empty - aborting Src hash check
2025/04/13 03:36:35 INFO  : only13: Copied (replaced existing)
2025/04/13 03:36:35 DEBUG : only8: Dst hash empty - aborting Src hash check
2025/04/13 03:36:35 INFO  : only8: Copied (replaced existing)
2025/04/13 03:36:35 DEBUG : only9: Dst hash empty - aborting Src hash check
2025/04/13 03:36:35 INFO  : only9: Copied (replaced existing)
2025/04/13 03:36:35 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- FAIL: TestSyncConcurrentTruncate (55.97s)
=== RUN   TestSyncReplaceDirModTime
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:36:43 DEBUG : empty_dir: Making directory with metadata
2025/04/13 03:36:43 INFO  : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/13 03:36:43 DEBUG : empty_on_remote: Making directory with metadata
2025/04/13 03:36:43 INFO  : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/13 03:36:43 INFO  : empty_on_remote: Making directory
2025/04/13 03:36:43 INFO  : empty_on_remote: Made directory with modification time 2011-12-25 12:59:59.123456789 +0000 UTC
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:36:44 INFO  : test_dir1: Set directory modification time (using DirSetModTime)
2025/04/13 03:36:44 INFO  : test_dir2: Set directory modification time (using DirSetModTime)
2025/04/13 03:36:44 INFO  : test_dir2/sub_dir: Set directory modification time (using DirSetModTime)
2025/04/13 03:36:44 INFO  : empty_on_remote: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncReplaceDirModTime (5.92s)
=== RUN   TestSyncReplaceDirModTimeWithEmptyDirs
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:36:48 DEBUG : empty_dir: Making directory with metadata
2025/04/13 03:36:48 INFO  : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/13 03:36:48 DEBUG : empty_on_remote: Making directory with metadata
2025/04/13 03:36:48 INFO  : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/13 03:36:48 INFO  : empty_on_remote: Making directory
2025/04/13 03:36:49 INFO  : empty_on_remote: Made directory with modification time 2011-12-25 12:59:59.123456789 +0000 UTC
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:36:51 INFO  : test_dir1: Set directory modification time (using DirSetModTime)
2025/04/13 03:36:51 INFO  : test_dir2: Set directory modification time (using DirSetModTime)
2025/04/13 03:36:51 INFO  : test_dir2/sub_dir: Set directory modification time (using DirSetModTime)
2025/04/13 03:36:51 INFO  : empty_on_remote: Set directory modification time (using DirSetModTime)
2025/04/13 03:36:51 INFO  : empty_dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
--- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (7.36s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:36:56 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/13 03:36:56 INFO  : sub dir: Making directory
2025/04/13 03:36:56 INFO  : sub dir: Made directory with modification time 2011-12-30 12:59:59 +0000 UTC
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:37:06 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/04/13 03:37:06 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/04/13 03:37:06 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/13 03:37:06 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:37:13 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/sub dirEmpty not empty`)
2025/04/13 03:37:13 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/04/13 03:37:13 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/sub dirEmpty not empty`)
2025/04/13 03:37:13 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/04/13 03:37:13 DEBUG : pacer: Reducing sleep to 30ms
2025/04/13 03:37:13 DEBUG : pacer: Reducing sleep to 22.5ms
2025/04/13 03:37:13 DEBUG : pacer: Reducing sleep to 16.875ms
2025/04/13 03:37:13 DEBUG : pacer: Reducing sleep to 12.65625ms
2025/04/13 03:37:14 DEBUG : pacer: Reducing sleep to 10ms
2025/04/13 03:37:14 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/sub dir2 not empty`)
2025/04/13 03:37:14 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/04/13 03:37:14 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/sub dir2 not empty`)
2025/04/13 03:37:14 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/04/13 03:37:15 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/sub dir2 not empty`)
2025/04/13 03:37:15 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2025/04/13 03:37:15 DEBUG : pacer: low level retry 4/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/sub dir2 not empty`)
2025/04/13 03:37:15 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2025/04/13 03:37:15 DEBUG : pacer: low level retry 5/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/sub dir2 not empty`)
2025/04/13 03:37:15 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2025/04/13 03:37:15 DEBUG : pacer: low level retry 6/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/sub dir2 not empty`)
2025/04/13 03:37:15 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2025/04/13 03:37:15 DEBUG : pacer: low level retry 7/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/sub dir2 not empty`)
2025/04/13 03:37:15 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2025/04/13 03:37:16 DEBUG : pacer: low level retry 8/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/sub dir2 not empty`)
2025/04/13 03:37:16 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/04/13 03:37:17 DEBUG : pacer: low level retry 9/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/sub dir2 not empty`)
2025/04/13 03:37:19 DEBUG : pacer: Reducing sleep to 1.5s
2025/04/13 03:37:21 DEBUG : pacer: Reducing sleep to 1.125s
2025/04/13 03:37:23 DEBUG : pacer: Reducing sleep to 843.75ms
2025/04/13 03:37:24 DEBUG : pacer: Reducing sleep to 632.8125ms
2025/04/13 03:37:25 DEBUG : pacer: Reducing sleep to 474.609375ms
2025/04/13 03:37:25 DEBUG : pacer: Reducing sleep to 355.957031ms
2025/04/13 03:37:26 DEBUG : pacer: Reducing sleep to 266.967773ms
2025/04/13 03:37:26 DEBUG : pacer: Reducing sleep to 200.225829ms
2025/04/13 03:37:26 DEBUG : pacer: Reducing sleep to 150.169371ms
--- PASS: TestNothingToTransferWithEmptyDirs (30.75s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:37:27 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/13 03:37:27 INFO  : sub dir: Making directory
2025/04/13 03:37:27 DEBUG : pacer: Reducing sleep to 112.627028ms
2025/04/13 03:37:27 DEBUG : pacer: Reducing sleep to 84.470271ms
2025/04/13 03:37:27 INFO  : sub dir: Made directory with modification time 2011-12-30 12:59:59 +0000 UTC
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:37:35 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/04/13 03:37:35 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/04/13 03:37:35 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/13 03:37:35 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "files root 'rclone-test-waseqex3zogu'", Local "Local file system at /tmp/rclone2741615887", Modify Window "1s"
2025/04/13 03:37:40 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/sub dir2/very/very/very/very not empty`)
2025/04/13 03:37:40 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/04/13 03:37:41 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/sub dir2/very/very/very/very not empty`)
2025/04/13 03:37:41 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/04/13 03:37:41 DEBUG : pacer: Reducing sleep to 30ms
2025/04/13 03:37:41 DEBUG : pacer: Reducing sleep to 22.5ms
2025/04/13 03:37:41 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/sub dir2/very/very not empty`)
2025/04/13 03:37:41 DEBUG : pacer: Rate limited, increasing sleep to 45ms
2025/04/13 03:37:41 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/sub dir2/very/very not empty`)
2025/04/13 03:37:41 DEBUG : pacer: Rate limited, increasing sleep to 90ms
2025/04/13 03:37:41 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-waseqex3zogu/sub dir2/very/very not empty`)
2025/04/13 03:37:41 DEBUG : pacer: Rate limited, increasing sleep to 180ms
2025/04/13 03:37:41 DEBUG : pacer: Reducing sleep to 135ms
2025/04/13 03:37:42 DEBUG : pacer: Reducing sleep to 101.25ms
2025/04/13 03:37:42 DEBUG : pacer: Reducing sleep to 75.9375ms
2025/04/13 03:37:42 DEBUG : pacer: Reducing sleep to 56.953125ms
2025/04/13 03:37:42 DEBUG : pacer: Reducing sleep to 42.714843ms
2025/04/13 03:37:42 DEBUG : pacer: Reducing sleep to 32.036132ms
2025/04/13 03:37:42 DEBUG : pacer: Reducing sleep to 24.027099ms
2025/04/13 03:37:42 DEBUG : pacer: Reducing sleep to 18.020324ms
2025/04/13 03:37:42 DEBUG : pacer: Reducing sleep to 13.515243ms
2025/04/13 03:37:43 DEBUG : pacer: Reducing sleep to 10.136432ms
2025/04/13 03:37:43 DEBUG : pacer: Reducing sleep to 10ms
--- PASS: TestNothingToTransferWithoutEmptyDirs (16.35s)
FAIL
2025/04/13 03:37:43 DEBUG : files root 'rclone-test-waseqex3zogu': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose" - Finished ERROR in 10m13.525321611s (try 1/5): exit status 1: Failed [TestCopyAfterDelete TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime TestSyncWithTrackRenames TestSyncBackupDir TestSyncBackupDirWithSuffixKeepExtension TestSyncConcurrentTruncate]