"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5)
2024/12/25 01:51:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu"
2024/12/25 01:51:46 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/12/25 01:51:46 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0"
2024/12/25 01:51:47 DEBUG : Creating backend with remote "/tmp/rclone2674766322"
=== RUN   TestPipe
--- PASS: TestPipe (0.00s)
=== RUN   TestPipeConcurrent
--- PASS: TestPipeConcurrent (0.01s)
=== 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 "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:51:48 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/25 01:51:48 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/25 01:51:48 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2024/12/25 01:51:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:51:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:51:48 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.26s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:51:49 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/25 01:51:50 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/25 01:51:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/25 01:51:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:51:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:51:52 DEBUG : sub dir/hello world: md5 = 7151401cf5f10eb9681f7c450c78871e OK
2024/12/25 01:51:52 INFO  : sub dir/hello world: Copied (new)
2024/12/25 01:51:53 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:51:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (6.88s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:51:56 DEBUG : metadata sub dir: Making directory with metadata
2024/12/25 01:51:56 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/25 01:51:56 DEBUG : empty metadata sub dir: Making directory with metadata
2024/12/25 01:51:56 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/25 01:51:56 DEBUG : Local file system at /tmp/rclone2674766322: File to upload is small (21 bytes), uploading instead of streaming
2024/12/25 01:51:56 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/12/25 01:51:56 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/12/25 01:51:56 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/12/25 01:51:57 DEBUG : Google drive root 'crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0': Skipping btime metadata as can't update it on an existing file: 2024-12-25T01:51:56.780396257Z
2024/12/25 01:51:57 INFO  : empty metadata sub dir: Updated directory metadata
2024/12/25 01:51:58 DEBUG : Google drive root 'crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0': Skipping btime metadata as can't update it on an existing file: 2024-12-25T01:51:56.780396257Z
2024/12/25 01:51:58 INFO  : metadata sub dir: Updated directory metadata
2024/12/25 01:51:58 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/12/25 01:51:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:51:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:52:00 DEBUG : metadata sub dir/hello metadata world: md5 = fa9d0ec8025636aa69545e4e29176efb OK
2024/12/25 01:52:00 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:52:03 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (8.56s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:52:05 DEBUG : metadata sub dir: Making directory with metadata
2024/12/25 01:52:05 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/25 01:52:05 DEBUG : empty metadata sub dir: Making directory with metadata
2024/12/25 01:52:05 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/25 01:52:05 DEBUG : Local file system at /tmp/rclone2674766322: File to upload is small (21 bytes), uploading instead of streaming
2024/12/25 01:52:05 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/12/25 01:52:05 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/12/25 01:52:05 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/12/25 01:52:05 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2024/12/25 01:52:05 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2024/12/25 01:52:05 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/12/25 01:52:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:52:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:52:08 DEBUG : metadata sub dir/hello metadata world: md5 = 7a87286e903dbcf8e760511a77b3842b OK
2024/12/25 01:52:08 INFO  : metadata sub dir/hello metadata world: Copied (new)
2024/12/25 01:52:08 DEBUG : Google drive root 'crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0': Skipping btime metadata as can't update it on an existing file: 2024-12-25T01:52:05.34032186Z
2024/12/25 01:52:08 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:52:11 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (7.50s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:52:12 DEBUG : Creating backend with remote "/non-existing"
2024/12/25 01:52:13 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2024/12/25 01:52:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:52:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.13s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:52:13 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/25 01:52:14 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/25 01:52:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:52:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:52:16 DEBUG : sub dir/hello world: md5 = 030bbb7520989c9b1816109a13330cb6 OK
2024/12/25 01:52:16 INFO  : sub dir/hello world: Copied (new)
2024/12/25 01:52:17 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:52:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (6.30s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:52:20 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Running all checks before starting transfers
2024/12/25 01:52:20 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/25 01:52:20 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/25 01:52:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:52:20 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Checks finished, now starting transfers
2024/12/25 01:52:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:52:23 DEBUG : sub dir/hello world: md5 = 6a543f609685154f110efa93ddab1890 OK
2024/12/25 01:52:23 INFO  : sub dir/hello world: Copied (new)
2024/12/25 01:52:23 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:52:25 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (6.51s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:52:26 ERROR : Ignoring --no-traverse with sync
2024/12/25 01:52:27 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/25 01:52:27 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/25 01:52:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:52:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:52:29 DEBUG : sub dir/hello world: md5 = 1392b9c8d352df132861c1141811005c OK
2024/12/25 01:52:29 INFO  : sub dir/hello world: Copied (new)
2024/12/25 01:52:29 DEBUG : Waiting for deletions to finish
2024/12/25 01:52:30 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:52:32 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (6.64s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:52:33 DEBUG : hello world2: Need to transfer - File not found at Destination
2024/12/25 01:52:33 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/25 01:52:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:52:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:52:35 DEBUG : hello world2: md5 = 31fc435317bd8dc6140de28960355447 OK
2024/12/25 01:52:35 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestCopyWithDepth (3.41s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:52:37 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/25 01:52:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:52:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:52:38 DEBUG : potato2: md5 = ddfc34930d08c25de7c3aed56d1c9c53 OK
2024/12/25 01:52:38 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.49s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:52:40 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/25 01:52:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:52:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:52:42 DEBUG : potato2: md5 = 679154ea56d9573d3d87e607387b9de1 OK
2024/12/25 01:52:42 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.38s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:52:43 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/12/25 01:52:43 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/25 01:52:43 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/12/25 01:52:43 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/25 01:52:43 DEBUG : sub dir: Making directory with metadata
2024/12/25 01:52:44 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/12/25 01:52:44 DEBUG : sub dir2: Making directory with metadata
2024/12/25 01:52:45 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/25 01:52:45 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/12/25 01:52:45 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/25 01:52:46 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/25 01:52:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:52:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:52:47 DEBUG : sub dir/hello world: md5 = a7b09ea3fccfcd4a1f56d1f1fd4f98b7 OK
2024/12/25 01:52:47 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:52:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2024/12/25 01:52:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (9.89s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:52:53 DEBUG : sub dir2: Making directory
2024/12/25 01:52:53 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/12/25 01:52:53 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/25 01:52:53 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/25 01:52:53 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/12/25 01:52:53 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2024/12/25 01:52:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/25 01:52:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:52:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:52:56 DEBUG : sub dir/hello world: md5 = b5ac9957f7505b968251aaacecd1b133 OK
2024/12/25 01:52:56 INFO  : sub dir/hello world: Copied (new)
2024/12/25 01:52:56 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/25 01:52:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (5.81s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:52:59 DEBUG : sub dir2: Making directory with metadata
2024/12/25 01:52:59 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/25 01:52:59 DEBUG : sub dir: Making directory with metadata
2024/12/25 01:53:00 INFO  : sub dir: Made directory with metadata (mtime=2024-12-25T01:52:59.395852061Z)
2024/12/25 01:53:00 DEBUG : sub dir2: Making directory with metadata
2024/12/25 01:53:01 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/25 01:53:01 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/25 01:53:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:53:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:53:03 DEBUG : sub dir/hello world: md5 = d932f457aec153a2dd1939c9e92f7a64 OK
2024/12/25 01:53:03 INFO  : sub dir/hello world: Copied (new)
2024/12/25 01:53:03 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:53:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (8.40s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:53:07 DEBUG : sub dir no update dir modtime: Making directory with metadata
2024/12/25 01:53:07 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/12/25 01:53:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:53:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:53:09 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (4.28s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:53:12 DEBUG : sub dir2: Making directory
2024/12/25 01:53:12 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/25 01:53:12 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/12/25 01:53:12 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/25 01:53:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:53:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:53:14 DEBUG : sub dir/hello world: md5 = c64f9f1006a997d74cd2542199949930 OK
2024/12/25 01:53:14 INFO  : sub dir/hello world: Copied (new)
2024/12/25 01:53:14 INFO  : sub dir/hello world: Deleted
2024/12/25 01:53:15 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/25 01:53:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (5.87s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:53:17 DEBUG : sub dir2: Making directory with metadata
2024/12/25 01:53:17 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/25 01:53:17 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/25 01:53:18 DEBUG : sub dir: Making directory with metadata
2024/12/25 01:53:19 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/12/25 01:53:19 DEBUG : sub dir2: Making directory with metadata
2024/12/25 01:53:20 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/25 01:53:20 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/25 01:53:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:53:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:53:21 DEBUG : sub dir/hello world: md5 = c9105d52fdf9f17e9c7a5023c116bd65 OK
2024/12/25 01:53:21 INFO  : sub dir/hello world: Copied (new)
2024/12/25 01:53:21 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:53:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (7.81s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.44s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:53:26 DEBUG : sub dir2: Making directory
2024/12/25 01:53:26 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/25 01:53:26 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/12/25 01:53:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/25 01:53:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:53:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:53:28 DEBUG : sub dir/hello world: md5 = 13c0390ce68edcac1db106993c926539 OK
2024/12/25 01:53:28 INFO  : sub dir/hello world: Copied (new)
2024/12/25 01:53:28 DEBUG : Waiting for deletions to finish
2024/12/25 01:53:29 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/25 01:53:31 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (5.83s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:53:34 DEBUG : sub dir/hello world: md5 = 92288c611d5ef02c25ee70eec3c6cb48 OK
2024/12/25 01:53:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yolopox8peqe"
2024/12/25 01:53:35 DEBUG : Creating backend with remote "TestDrive:crypt/vrf4guujc4kg4b7f5e5sj0u2en5ok1k0pd61oce0pojsfbjktg30"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu' -> Encrypted drive 'TestCryptDrive:rclone-test-yolopox8peqe'
2024/12/25 01:53:36 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/25 01:53:36 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/25 01:53:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yolopox8peqe': Waiting for checks to finish
2024/12/25 01:53:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yolopox8peqe': Waiting for transfers to finish
2024/12/25 01:53:39 INFO  : sub dir/hello world: Copied (server-side copy)
2024/12/25 01:53:40 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:53:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yolopox8peqe': Purge remote
2024/12/25 01:53:42 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (11.89s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:53:46 DEBUG : sub dir/hello world: md5 = 2373d874e3897efe5ba657f40739e379 OK
2024/12/25 01:53:47 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/12/25 01:53:47 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/12/25 01:53:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:53:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:53:48 DEBUG : sub dir/hello world: md5 = 32c180a3092a990ea40de29034a64b9f OK
2024/12/25 01:53:48 INFO  : sub dir/hello world: Copied (replaced existing)
2024/12/25 01:53:49 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:53:51 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (8.46s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:53:54 DEBUG : sub dir/hello world: md5 = 903af8d15d8bc4c1bd02a58dac9390ce OK
2024/12/25 01:53:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-befofuj2laqu"
2024/12/25 01:53:55 DEBUG : Creating backend with remote "TestDrive:crypt/5tusfekuo0tcd2g6t4r33rao90taurcpg6rdsmbec6rtn8kljuh0"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu' -> Encrypted drive 'TestCryptDrive:rclone-test-befofuj2laqu'
2024/12/25 01:53:56 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/25 01:53:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/25 01:53:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-befofuj2laqu': Waiting for checks to finish
2024/12/25 01:53:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-befofuj2laqu': Waiting for transfers to finish
2024/12/25 01:54:00 INFO  : sub dir/hello world: Copied (server-side copy)
2024/12/25 01:54:01 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:54:03 DEBUG : sub dir/hello world: md5 = e59be3c0f72350f86947b8a085a5a26e OK
2024/12/25 01:54:04 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/12/25 01:54:04 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/12/25 01:54:04 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/12/25 01:54:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-befofuj2laqu': Waiting for checks to finish
2024/12/25 01:54:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-befofuj2laqu': Waiting for transfers to finish
2024/12/25 01:54:06 INFO  : sub dir/hello world: Copied (server-side copy)
2024/12/25 01:54:06 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:54:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-befofuj2laqu': Purge remote
2024/12/25 01:54:09 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (18.35s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:54:13 DEBUG : sub dir/hello world: md5 = d7da41878fa7b4d8357e1757ff20b12f OK
2024/12/25 01:54:14 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/12/25 01:54:14 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/12/25 01:54:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:54:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:54:15 DEBUG : sub dir/hello world: md5 = 27bfef8dfce93b21a2f9ebe43693c5c0 OK
2024/12/25 01:54:15 INFO  : sub dir/hello world: Copied (replaced existing)
2024/12/25 01:54:15 INFO  : sub dir/hello world: Deleted
2024/12/25 01:54:16 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:54:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (8.49s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:54:21 DEBUG : sub dir/hello world: md5 = 40bff7cea378759adfadc3c2e0deaaaf OK
2024/12/25 01:54:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-ruyolil8mefa"
2024/12/25 01:54:22 DEBUG : Creating backend with remote "TestDrive:crypt/468hfi2c2974k01n92hetlgjh1u4gm4hoghbfava7165u04qff40"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu' -> Encrypted drive 'TestCryptDrive:rclone-test-ruyolil8mefa'
2024/12/25 01:54:23 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/25 01:54:23 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/25 01:54:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ruyolil8mefa': Waiting for checks to finish
2024/12/25 01:54:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ruyolil8mefa': Waiting for transfers to finish
2024/12/25 01:54:26 INFO  : sub dir/hello world: Copied (server-side copy)
2024/12/25 01:54:27 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:54:29 DEBUG : sub dir/hello world: md5 = d5a7146834a4118a06cce99371f3eaa3 OK
2024/12/25 01:54:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ruyolil8mefa': Using server-side directory move
2024/12/25 01:54:29 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-ruyolil8mefa': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/12/25 01:54:30 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/12/25 01:54:30 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/12/25 01:54:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ruyolil8mefa': Waiting for checks to finish
2024/12/25 01:54:30 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/12/25 01:54:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ruyolil8mefa': Waiting for transfers to finish
2024/12/25 01:54:30 INFO  : sub dir/hello world: Deleted
2024/12/25 01:54:31 INFO  : sub dir/hello world: Moved (server-side)
2024/12/25 01:54:32 INFO  : sub dir: Set directory modification time (using SetModTime)
2024/12/25 01:54:34 DEBUG : sub dir/hello world: md5 = 421568ca1290c0cd0da80ec138b296e8 OK
2024/12/25 01:54:35 DEBUG : testing file moves
2024/12/25 01:54:35 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/12/25 01:54:35 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/12/25 01:54:35 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2024/12/25 01:54:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ruyolil8mefa': Waiting for checks to finish
2024/12/25 01:54:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ruyolil8mefa': Waiting for transfers to finish
2024/12/25 01:54:36 INFO  : sub dir/hello world: Deleted
2024/12/25 01:54:37 INFO  : sub dir/hello world: Moved (server-side)
2024/12/25 01:54:37 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:54:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ruyolil8mefa': Purge remote
--- PASS: TestServerSideMoveOverSelf (22.14s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:54:43 DEBUG : sub dir/hello world: md5 = d73c94ab222780a7e60b9f8c2ee4d11e OK
2024/12/25 01:54:43 ERROR : : error listing: directory not found
2024/12/25 01:54:44 DEBUG : Local file system at /tmp/rclone2674766322: Making directory
2024/12/25 01:54:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:54:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:54:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (6.34s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:54:50 DEBUG : sub dir/hello world: md5 = 48d53851a14562894d2da6b0aeb61b8a OK
2024/12/25 01:54:51 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/25 01:54:51 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/25 01:54:51 DEBUG : Local file system at /tmp/rclone2674766322: Waiting for checks to finish
2024/12/25 01:54:51 DEBUG : Local file system at /tmp/rclone2674766322: Waiting for transfers to finish
2024/12/25 01:54:52 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2024/12/25 01:54:52 INFO  : sub dir/hello world: Copied (new)
2024/12/25 01:54:52 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:54:53 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (7.14s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:54:55 DEBUG : check sum: Need to transfer - File not found at Destination
2024/12/25 01:54:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:54:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:54:56 DEBUG : check sum: md5 = b025d6418233eae4981eb26f91f9be74 OK
2024/12/25 01:54:56 INFO  : check sum: Copied (new)
2024/12/25 01:54:56 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:54:57 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2024/12/25 01:54:57 DEBUG : check sum: Size of src and dst objects identical
2024/12/25 01:54:57 DEBUG : check sum: Unchanged skipping
2024/12/25 01:54:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:54:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:54:57 DEBUG : Waiting for deletions to finish
2024/12/25 01:54:57 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (4.31s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:54:59 DEBUG : sizeonly: Need to transfer - File not found at Destination
2024/12/25 01:54:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:54:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:55:00 DEBUG : sizeonly: md5 = de2f5409b39e9a993670f7f5687818a6 OK
2024/12/25 01:55:00 INFO  : sizeonly: Copied (new)
2024/12/25 01:55:00 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:55:01 DEBUG : sizeonly: Sizes identical
2024/12/25 01:55:01 DEBUG : sizeonly: Unchanged skipping
2024/12/25 01:55:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:55:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:55:01 DEBUG : Waiting for deletions to finish
2024/12/25 01:55:01 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (4.43s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:55:03 DEBUG : ignore-size: Need to transfer - File not found at Destination
2024/12/25 01:55:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:55:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:55:05 DEBUG : ignore-size: md5 = c8b08bd0fcbcd90b24ccc044d556276a OK
2024/12/25 01:55:05 INFO  : ignore-size: Copied (new)
2024/12/25 01:55:05 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:55:05 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 01:55:05 DEBUG : ignore-size: Unchanged skipping
2024/12/25 01:55:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:55:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:55:05 DEBUG : Waiting for deletions to finish
2024/12/25 01:55:05 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (4.42s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:55:09 DEBUG : existing: md5 = 65d9ced19f4a5da7f40f8a92fcf0a03e OK
2024/12/25 01:55:10 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 01:55:10 DEBUG : existing: Unchanged skipping
2024/12/25 01:55:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:55:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:55:10 DEBUG : Waiting for deletions to finish
2024/12/25 01:55:10 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:55:10 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2024/12/25 01:55:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:55:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:55:11 DEBUG : existing: md5 = 3b4c5fbe5a2c97a322a7c32f9c178b64 OK
2024/12/25 01:55:11 INFO  : existing: Copied (replaced existing)
2024/12/25 01:55:11 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (5.74s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:55:13 DEBUG : existing: Need to transfer - File not found at Destination
2024/12/25 01:55:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:55:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:55:15 DEBUG : existing: md5 = 19addcdfa32c4769227de480f56085dc OK
2024/12/25 01:55:15 INFO  : existing: Copied (new)
2024/12/25 01:55:15 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:55:15 DEBUG : existing: Destination exists, skipping
2024/12/25 01:55:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:55:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:55:15 DEBUG : Waiting for deletions to finish
2024/12/25 01:55:15 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (4.26s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:55:20 DEBUG : b/potato: md5 = deb2633fdcdeebfee4c53ea688ecf31e OK
2024/12/25 01:55:23 DEBUG : c/non empty space: md5 = 519168dca12313b41851f4747592fb61 OK
2024/12/25 01:55:23 DEBUG : d: Making directory
2024/12/25 01:55:24 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/12/25 01:55:24 DEBUG : Added delayed dir = "c", newDst=c
2024/12/25 01:55:24 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 01:55:24 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/12/25 01:55:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:55:24 DEBUG : c/non empty space: Unchanged skipping
2024/12/25 01:55:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:55:27 DEBUG : a/potato2: md5 = ffae05b696d99d2b8edc7e00a41996c3 OK
2024/12/25 01:55:27 INFO  : a/potato2: Copied (new)
2024/12/25 01:55:27 DEBUG : Waiting for deletions to finish
2024/12/25 01:55:27 INFO  : b/potato: Deleted
2024/12/25 01:55:28 INFO  : a: Set directory modification time (using DirSetModTime)
2024/12/25 01:55:28 INFO  : d: Removing directory
2024/12/25 01:55:29 INFO  : b: Removing directory
2024/12/25 01:55:29 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/12/25 01:55:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:55:32 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/12/25 01:55:33 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (16.35s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:55:35 DEBUG : empty space: md5 = 66c178c27e485df7320be511367aa39f OK
2024/12/25 01:55:36 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2024/12/25 01:55:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:55:36 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2024/12/25 01:55:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:55:36 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:55:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:55:36 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2024/12/25 01:55:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:55:38 DEBUG : empty space: md5 = 56f7cea1c6577afffc3a89a36c34d3d8 OK
2024/12/25 01:55:38 INFO  : empty space: Copied (replaced existing)
2024/12/25 01:55:38 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (6.60s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.44s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:55:43 DEBUG : foo: md5 = 4d6b25d541fa2dd0ea7f5758010333f3 OK
2024/12/25 01:55:43 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2024/12/25 01:55:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:55:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:55:44 DEBUG : foo: md5 = ccac79c83cd1921a27ef2e478fe9b588 OK
2024/12/25 01:55:44 INFO  : foo: Copied (replaced existing)
2024/12/25 01:55:44 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (6.03s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:55:49 DEBUG : empty space: md5 = 21623a07edc8eff0458be26c8f73deb4 OK
2024/12/25 01:55:49 DEBUG : potato: Need to transfer - File not found at Destination
2024/12/25 01:55:49 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 01:55:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:55:49 DEBUG : empty space: Unchanged skipping
2024/12/25 01:55:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:55:51 DEBUG : potato: md5 = 0e1eed3c425f05b44d7df7f664c521fe OK
2024/12/25 01:55:51 INFO  : potato: Copied (new)
2024/12/25 01:55:51 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (6.19s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:55:55 DEBUG : potato: md5 = 5d4bcb6a1eb640738a136a293f5bfd53 OK
2024/12/25 01:55:55 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2024/12/25 01:55:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:55:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:55:57 DEBUG : potato: md5 = 7a4c1d1d2b05908811f2e037999437cf OK
2024/12/25 01:55:57 INFO  : potato: Copied (replaced existing)
2024/12/25 01:55:57 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (5.12s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:56:00 DEBUG : potato: md5 = d09577e71e3ea6928bfb9bfa5bb65560 OK
2024/12/25 01:56:00 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
2024/12/25 01:56:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:56:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:56:02 DEBUG : potato: md5 = 0e881af23b1f7b21507766c04848307b OK
2024/12/25 01:56:02 INFO  : potato: Copied (replaced existing)
2024/12/25 01:56:02 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (5.01s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:56:05 DEBUG : potato: md5 = a2a5771cb538ba8d33818223c44884c9 OK
2024/12/25 01:56:06 DEBUG : empty space: md5 = d29480cee21691890bb98987b8d42d34 OK
2024/12/25 01:56:07 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/25 01:56:07 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2024/12/25 01:56:07 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 01:56:07 DEBUG : empty space: Unchanged skipping
2024/12/25 01:56:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:56:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:56:07 DEBUG : Waiting for deletions to finish
2024/12/25 01:56:07 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.58s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:56:10 DEBUG : potato: md5 = 604fa0104aac875f0cecd8a36a84f351 OK
2024/12/25 01:56:12 DEBUG : empty space: md5 = 80e8112235d2c3a2c8870a084fa21e30 OK
2024/12/25 01:56:13 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/25 01:56:13 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 01:56:13 DEBUG : empty space: Unchanged skipping
2024/12/25 01:56:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:56:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:56:15 DEBUG : potato2: md5 = e5d62474b01080a4b856fb18485aeb62 OK
2024/12/25 01:56:15 INFO  : potato2: Copied (new)
2024/12/25 01:56:15 DEBUG : Waiting for deletions to finish
2024/12/25 01:56:15 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.52s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:56:20 DEBUG : b/potato: md5 = 47ccc8b6ad13e0675996bbc709e19dc3 OK
2024/12/25 01:56:23 DEBUG : c/non empty space: md5 = 7e8ec02840359574fa8c9ce6836eb72d OK
2024/12/25 01:56:23 DEBUG : d: Making directory
2024/12/25 01:56:24 DEBUG : d/e: Making directory
2024/12/25 01:56:26 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/12/25 01:56:26 DEBUG : Added delayed dir = "c", newDst=c
2024/12/25 01:56:26 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/12/25 01:56:26 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 01:56:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:56:26 DEBUG : c/non empty space: Unchanged skipping
2024/12/25 01:56:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:56:29 DEBUG : a/potato2: md5 = 79d3a00799686ff017b212a449242cb2 OK
2024/12/25 01:56:29 INFO  : a/potato2: Copied (new)
2024/12/25 01:56:29 DEBUG : Waiting for deletions to finish
2024/12/25 01:56:29 INFO  : b/potato: Deleted
2024/12/25 01:56:30 INFO  : a: Set directory modification time (using DirSetModTime)
2024/12/25 01:56:30 INFO  : d/e: Removing directory
2024/12/25 01:56:31 INFO  : d: Removing directory
2024/12/25 01:56:31 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2024/12/25 01:56:32 INFO  : b: Removing directory
2024/12/25 01:56:32 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/12/25 01:56:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:56:35 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/12/25 01:56:36 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (19.56s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:56:39 DEBUG : b/potato: md5 = 4545753fe5fe893d194bd8a65a80b5a9 OK
2024/12/25 01:56:42 DEBUG : c/non empty space: md5 = 5d7a53518faedb73b2c6ccd971b8214b OK
2024/12/25 01:56:42 DEBUG : d: Making directory
2024/12/25 01:56:44 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/12/25 01:56:44 DEBUG : Added delayed dir = "c", newDst=c
2024/12/25 01:56:44 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 01:56:44 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/12/25 01:56:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:56:44 DEBUG : c/non empty space: Unchanged skipping
2024/12/25 01:56:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:56:47 DEBUG : a/potato2: md5 = 475dae628e85af9deb25aef670ddee9b OK
2024/12/25 01:56:47 INFO  : a/potato2: Copied (new)
2024/12/25 01:56:47 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': not deleting files as there were IO errors
2024/12/25 01:56:47 INFO  : a: Set directory modification time (using DirSetModTime)
2024/12/25 01:56:47 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:56:51 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/12/25 01:56:52 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/12/25 01:56:52 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (16.75s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:56:55 DEBUG : potato: md5 = ecee01e5724d8ad157dd5cffc17b5dab OK
2024/12/25 01:56:57 DEBUG : empty space: md5 = 96b372838619a01a21e960de443af34b OK
2024/12/25 01:56:57 DEBUG : Waiting for deletions to finish
2024/12/25 01:56:58 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/25 01:56:58 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 01:56:58 DEBUG : empty space: Unchanged skipping
2024/12/25 01:56:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:56:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:56:58 INFO  : potato: Deleted
2024/12/25 01:56:59 DEBUG : potato2: md5 = a029785504ba8eea0d6080d7ba89ed8e OK
2024/12/25 01:56:59 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (7.66s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:57:03 DEBUG : potato: md5 = a322148adf11794898126ca5f7555818 OK
2024/12/25 01:57:05 DEBUG : empty space: md5 = 63eef39a170d6e386eaabca481523887 OK
2024/12/25 01:57:05 DEBUG : Waiting for deletions to finish
2024/12/25 01:57:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:57:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:57:06 INFO  : potato: Deleted
2024/12/25 01:57:06 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/25 01:57:06 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 01:57:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:57:06 DEBUG : empty space: Unchanged skipping
2024/12/25 01:57:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:57:08 DEBUG : potato2: md5 = d2947cf4d11464724ccc20c07c8d0f3c OK
2024/12/25 01:57:08 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (8.72s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:57:12 DEBUG : potato: md5 = 8cabc17c80ef487ec8dfe3fab6eebc94 OK
2024/12/25 01:57:12 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/25 01:57:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:57:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:57:14 DEBUG : potato2: md5 = 05fa4c8fed904c990400429c25d36095 OK
2024/12/25 01:57:14 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (5.98s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:57:19 DEBUG : potato2: md5 = 1d271c2d3162c9fb1599042ec9bbe9da OK
2024/12/25 01:57:20 DEBUG : empty space: md5 = eea6303e6affbea4ae3d6c46ce9c78e9 OK
2024/12/25 01:57:21 DEBUG : enormous: Excluded (Size Filter)
2024/12/25 01:57:21 DEBUG : enormous: Excluded
2024/12/25 01:57:21 DEBUG : potato2: Excluded (Size Filter)
2024/12/25 01:57:21 DEBUG : potato2: Excluded
2024/12/25 01:57:21 DEBUG : potato2: Excluded (Size Filter)
2024/12/25 01:57:21 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 01:57:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:57:21 DEBUG : empty space: Unchanged skipping
2024/12/25 01:57:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:57:21 DEBUG : Waiting for deletions to finish
2024/12/25 01:57:21 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:57:21 DEBUG : enormous: Excluded (Size Filter)
2024/12/25 01:57:21 DEBUG : enormous: Excluded
2024/12/25 01:57:21 DEBUG : potato2: Excluded (Size Filter)
2024/12/25 01:57:21 DEBUG : potato2: Excluded
2024/12/25 01:57:21 DEBUG : potato2: Excluded (Size Filter)
2024/12/25 01:57:21 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/12/25 01:57:21 DEBUG : empty space: Unchanged skipping
2024/12/25 01:57:21 DEBUG : Local file system at /tmp/rclone2674766322: Waiting for checks to finish
2024/12/25 01:57:21 DEBUG : Local file system at /tmp/rclone2674766322: Waiting for transfers to finish
2024/12/25 01:57:21 DEBUG : Waiting for deletions to finish
2024/12/25 01:57:21 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncWithExclude (7.72s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:57:25 DEBUG : potato2: md5 = 69715aa8b70cb665d758768e46fee326 OK
2024/12/25 01:57:27 DEBUG : empty space: md5 = 086a5a383182aa61bfa198679c16e5d3 OK
2024/12/25 01:57:28 DEBUG : enormous: md5 = 51e9e3edc07563a64e0059a9fb4be031 OK
2024/12/25 01:57:29 DEBUG : enormous: Excluded (Size Filter)
2024/12/25 01:57:29 DEBUG : enormous: Excluded
2024/12/25 01:57:29 DEBUG : potato2: Excluded (Size Filter)
2024/12/25 01:57:29 DEBUG : potato2: Excluded
2024/12/25 01:57:29 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 01:57:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:57:29 DEBUG : empty space: Unchanged skipping
2024/12/25 01:57:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:57:29 DEBUG : Waiting for deletions to finish
2024/12/25 01:57:29 INFO  : potato2: Deleted
2024/12/25 01:57:29 INFO  : enormous: Deleted
2024/12/25 01:57:29 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:57:30 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/12/25 01:57:30 DEBUG : empty space: Unchanged skipping
2024/12/25 01:57:30 DEBUG : Local file system at /tmp/rclone2674766322: Waiting for checks to finish
2024/12/25 01:57:30 DEBUG : Local file system at /tmp/rclone2674766322: Waiting for transfers to finish
2024/12/25 01:57:30 DEBUG : Waiting for deletions to finish
2024/12/25 01:57:30 INFO  : enormous: Deleted
2024/12/25 01:57:30 INFO  : potato2: Deleted
2024/12/25 01:57:30 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (8.07s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:57:33 DEBUG : one: md5 = f6a30bb510d752814f4b6f40ff7fb2f1 OK
2024/12/25 01:57:35 DEBUG : two: md5 = 4bdc32d18ba980162a25ca4c194f8103 OK
2024/12/25 01:57:37 DEBUG : three: md5 = cead4fff568d24e0db9a05d448b81742 OK
2024/12/25 01:57:38 DEBUG : four: md5 = af95d19986937e30e9c53ee029931ebf OK
2024/12/25 01:57:39 DEBUG : five: Need to transfer - File not found at Destination
2024/12/25 01:57:39 DEBUG : four: Sizes differ (src 4 vs dst 8)
2024/12/25 01:57:39 DEBUG : one: Destination is newer than source, skipping
2024/12/25 01:57:39 DEBUG : three: Sizes identical
2024/12/25 01:57:39 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2024/12/25 01:57:39 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2024/12/25 01:57:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:57:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:57:40 DEBUG : four: md5 = 32913bd257d551611ab2c30547d13654 OK
2024/12/25 01:57:40 INFO  : four: Copied (replaced existing)
2024/12/25 01:57:40 DEBUG : two: md5 = 551639b0f9252e1593d3ef35f0f99dd8 OK
2024/12/25 01:57:40 INFO  : two: Copied (replaced existing)
2024/12/25 01:57:40 DEBUG : five: md5 = 5a5ea69ee69ca92144860e4f9fc58702 OK
2024/12/25 01:57:40 INFO  : five: Copied (new)
2024/12/25 01:57:40 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (11.85s)
=== 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.01s)
    --- SKIP: TestSyncWithMaxDuration/Hard (0.00s)
    --- SKIP: TestSyncWithMaxDuration/Soft (0.00s)
=== RUN   TestSyncWithTrackRenames
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2024/12/25 01:57:44 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Ignoring --track-renames as the source and destination do not have a common hash
2024/12/25 01:57:44 DEBUG : potato: Need to transfer - File not found at Destination
2024/12/25 01:57:44 DEBUG : yam: Need to transfer - File not found at Destination
2024/12/25 01:57:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:57:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:57:45 DEBUG : yam: md5 = 977c3e8a73767f40a9183cde6650826d OK
2024/12/25 01:57:45 INFO  : yam: Copied (new)
2024/12/25 01:57:45 DEBUG : potato: md5 = f9f6af3c7a27f253e86d42b9f67bede0 OK
2024/12/25 01:57:45 INFO  : potato: Copied (new)
2024/12/25 01:57:45 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:57:46 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Ignoring --track-renames as the source and destination do not have a common hash
2024/12/25 01:57:46 DEBUG : yaml: Need to transfer - File not found at Destination
2024/12/25 01:57:46 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 01:57:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:57:46 DEBUG : potato: Unchanged skipping
2024/12/25 01:57:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:57:48 DEBUG : yaml: md5 = 08db38b54c2aeac709afe2875f59f6b5 OK
2024/12/25 01:57:48 INFO  : yaml: Copied (new)
2024/12/25 01:57:48 DEBUG : Waiting for deletions to finish
2024/12/25 01:57:48 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (7.49s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2024/12/25 01:57:51 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Making map for --track-renames
2024/12/25 01:57:51 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Finished making map for --track-renames
2024/12/25 01:57:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:57:51 DEBUG : yam: Need to transfer - No matching file found at Destination
2024/12/25 01:57:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for renames to finish
2024/12/25 01:57:51 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/12/25 01:57:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:57:53 DEBUG : yam: md5 = 11a7129d9037bad5f264a3834a645629 OK
2024/12/25 01:57:53 INFO  : yam: Copied (new)
2024/12/25 01:57:53 DEBUG : potato: md5 = 739c14066c60738dc0e51b2044c711af OK
2024/12/25 01:57:53 INFO  : potato: Copied (new)
2024/12/25 01:57:53 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:57:54 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 01:57:54 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Making map for --track-renames
2024/12/25 01:57:54 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Finished making map for --track-renames
2024/12/25 01:57:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:57:54 DEBUG : potato: Unchanged skipping
2024/12/25 01:57:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for renames to finish
2024/12/25 01:57:54 INFO  : yam: Moved (server-side) to: yaml
2024/12/25 01:57:54 INFO  : yaml: Renamed from "yam"
2024/12/25 01:57:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:57:54 DEBUG : Waiting for deletions to finish
2024/12/25 01:57:54 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (5.86s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2024/12/25 01:57:57 DEBUG : Added delayed dir = "sub", newDst=<nil>
2024/12/25 01:57:57 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Making map for --track-renames
2024/12/25 01:57:57 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Finished making map for --track-renames
2024/12/25 01:57:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:57:57 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2024/12/25 01:57:57 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/12/25 01:57:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for renames to finish
2024/12/25 01:57:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:58:00 DEBUG : sub/yam: md5 = 867110ca0e1608dc5d4cb8cdb207c0ba OK
2024/12/25 01:58:00 INFO  : sub/yam: Copied (new)
2024/12/25 01:58:00 DEBUG : potato: md5 = 2606f0da7e3fd5e9c56e04c414260ebf OK
2024/12/25 01:58:00 INFO  : potato: Copied (new)
2024/12/25 01:58:00 DEBUG : Waiting for deletions to finish
2024/12/25 01:58:01 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:58:01 DEBUG : Added delayed dir = "sub", newDst=sub
2024/12/25 01:58:01 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 01:58:01 DEBUG : potato: Unchanged skipping
2024/12/25 01:58:01 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Making map for --track-renames
2024/12/25 01:58:01 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Finished making map for --track-renames
2024/12/25 01:58:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:58:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for renames to finish
2024/12/25 01:58:03 INFO  : sub/yam: Moved (server-side) to: yam
2024/12/25 01:58:03 INFO  : yam: Renamed from "sub/yam"
2024/12/25 01:58:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:58:03 DEBUG : Waiting for deletions to finish
2024/12/25 01:58:03 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.39s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:58:06 DEBUG : Creating backend with remote "/tmp/rclone2674766322/dir1"
2024/12/25 01:58:06 DEBUG : Creating backend with remote "/tmp/rclone2674766322/dir2"
2024/12/25 01:58:06 DEBUG : Local file system at /tmp/rclone2674766322/dir2: Using server-side directory move
2024/12/25 01:58:06 INFO  : Local file system at /tmp/rclone2674766322/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/12/25 01:58:06 DEBUG : file1.txt: Need to transfer - File not found at Destination
2024/12/25 01:58:06 INFO  : file1.txt: Moved (server-side)
2024/12/25 01:58:06 DEBUG : Local file system at /tmp/rclone2674766322/dir2: Waiting for checks to finish
2024/12/25 01:58:06 DEBUG : Local file system at /tmp/rclone2674766322/dir2: Waiting for transfers to finish
--- PASS: TestServerSideMoveLocal (0.44s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:58:07 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/12/25 01:58:07 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/25 01:58:07 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/25 01:58:07 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/12/25 01:58:07 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/12/25 01:58:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:58:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:58:09 DEBUG : sub dir/hello world: md5 = c86f8edd22d7f4049e3df47c3c64fb0e OK
2024/12/25 01:58:09 INFO  : sub dir/hello world: Copied (new)
2024/12/25 01:58:09 INFO  : sub dir/hello world: Deleted
2024/12/25 01:58:12 DEBUG : nested/sub dir/file: md5 = d5a07bc5fb3ab2f9a9891a8dffeefa37 OK
2024/12/25 01:58:12 INFO  : nested/sub dir/file: Copied (new)
2024/12/25 01:58:12 INFO  : nested/sub dir/file: Deleted
2024/12/25 01:58:12 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/12/25 01:58:13 INFO  : nested: Set directory modification time (using DirSetModTime)
2024/12/25 01:58:13 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/25 01:58:13 INFO  : sub dir: Removing directory
2024/12/25 01:58:13 INFO  : nested/sub dir: Removing directory
2024/12/25 01:58:13 INFO  : nested: Removing directory
2024/12/25 01:58:13 DEBUG : Local file system at /tmp/rclone2674766322: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:58:16 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/12/25 01:58:16 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/12/25 01:58:17 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (11.58s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:58:19 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/12/25 01:58:19 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/25 01:58:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/25 01:58:19 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/12/25 01:58:19 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/12/25 01:58:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:58:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:58:21 DEBUG : sub dir/hello world: md5 = 69ff985006a00682d15d23b469eda346 OK
2024/12/25 01:58:21 INFO  : sub dir/hello world: Copied (new)
2024/12/25 01:58:21 INFO  : sub dir/hello world: Deleted
2024/12/25 01:58:23 DEBUG : nested/sub dir/file: md5 = ae91e6d432f4c8a6cd1d37af04315684 OK
2024/12/25 01:58:23 INFO  : nested/sub dir/file: Copied (new)
2024/12/25 01:58:23 INFO  : nested/sub dir/file: Deleted
2024/12/25 01:58:24 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/12/25 01:58:25 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/25 01:58:25 INFO  : nested: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:58:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/12/25 01:58:28 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/12/25 01:58:29 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (12.16s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:58:31 DEBUG : existing: Need to transfer - File not found at Destination
2024/12/25 01:58:31 DEBUG : existing-b: Need to transfer - File not found at Destination
2024/12/25 01:58:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:58:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:58:32 DEBUG : existing: md5 = 3cd8f6294d19e9029b08a797d79c9142 OK
2024/12/25 01:58:32 INFO  : existing: Copied (new)
2024/12/25 01:58:32 INFO  : existing: Deleted
2024/12/25 01:58:33 DEBUG : existing-b: md5 = 2ab64163bc1b613db214d909a27308cd OK
2024/12/25 01:58:33 INFO  : existing-b: Copied (new)
2024/12/25 01:58:33 INFO  : existing-b: Deleted
2024/12/25 01:58:33 DEBUG : existing: Destination exists, skipping
2024/12/25 01:58:33 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2024/12/25 01:58:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:58:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:58:33 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (4.72s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:58:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nubeqaw4mazu"
2024/12/25 01:58:35 DEBUG : Creating backend with remote "TestDrive:crypt/car27dm5ahcbm6lq5fss71f277l1kno48inj6jjacqld3mvv89sg"
2024/12/25 01:58:38 DEBUG : potato2: md5 = 8215f2130fd26da7cf6023a4afb2df4d OK
2024/12/25 01:58:40 DEBUG : empty space: md5 = 6ad52d344eff2c94d49a05098285f7ff OK
2024/12/25 01:58:41 DEBUG : potato3: md5 = 90e03dad31a944129ae0d3a0f7af1c9a OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu' -> Encrypted drive 'TestCryptDrive:rclone-test-nubeqaw4mazu'
2024/12/25 01:58:44 DEBUG : empty space: md5 = a9013fd86ccaa0f0292046bbac7d1d87 OK
2024/12/25 01:58:46 DEBUG : potato3: md5 = c538575aa160b4bd95b4f434736ddb3e OK
2024/12/25 01:58:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nubeqaw4mazu': Using server-side directory move
2024/12/25 01:58:46 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-nubeqaw4mazu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/12/25 01:58:46 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/25 01:58:46 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/12/25 01:58:46 DEBUG : empty space: Unchanged skipping
2024/12/25 01:58:46 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/12/25 01:58:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nubeqaw4mazu': Waiting for checks to finish
2024/12/25 01:58:47 INFO  : empty space: Deleted
2024/12/25 01:58:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nubeqaw4mazu': Waiting for transfers to finish
2024/12/25 01:58:47 INFO  : potato3: Deleted
2024/12/25 01:58:47 INFO  : potato2: Moved (server-side)
2024/12/25 01:58:47 INFO  : potato3: Moved (server-side)
2024/12/25 01:58:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-juluviy5qedo"
2024/12/25 01:58:48 DEBUG : Creating backend with remote "TestDrive:crypt/5j63ua0fu4q1edhips0rrjubk8aie97kdgi4tjuj015u8hmvtrqg"
2024/12/25 01:58:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-juluviy5qedo': Using server-side directory move
2024/12/25 01:58:50 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-juluviy5qedo': Server side directory move succeeded
2024/12/25 01:58:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-juluviy5qedo': Purge remote
2024/12/25 01:58:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nubeqaw4mazu': Purge remote
2024/12/25 01:58:52 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (16.64s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:58:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-debiwow0fine"
2024/12/25 01:58:52 DEBUG : Creating backend with remote "TestDrive:crypt/pcjp6fl7nv7umnk7lrbtgp28je9bgv55tavabl7jdov1d6umdc30"
2024/12/25 01:58:55 DEBUG : potato2: md5 = fc7231f2a252ffedc3a0bbe6385833ec OK
2024/12/25 01:58:56 DEBUG : empty space: md5 = a4fea8448f8992451f92793a84dd1228 OK
2024/12/25 01:58:58 DEBUG : potato3: md5 = 104cc5e0ec735afc329c52e1e65af42c OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu' -> Encrypted drive 'TestCryptDrive:rclone-test-debiwow0fine'
2024/12/25 01:59:01 DEBUG : empty space: md5 = 14f0801c798dd297e3bb9305af9d59b4 OK
2024/12/25 01:59:03 DEBUG : potato3: md5 = 00079588ab5f5f6b9d4f07b4397a4164 OK
2024/12/25 01:59:03 DEBUG : empty space: Excluded (Size Filter)
2024/12/25 01:59:03 DEBUG : empty space: Excluded (Size Filter)
2024/12/25 01:59:03 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/25 01:59:03 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/12/25 01:59:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-debiwow0fine': Waiting for checks to finish
2024/12/25 01:59:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-debiwow0fine': Waiting for transfers to finish
2024/12/25 01:59:04 INFO  : potato2: Moved (server-side)
2024/12/25 01:59:05 INFO  : potato3: Deleted
2024/12/25 01:59:05 INFO  : potato3: Moved (server-side)
2024/12/25 01:59:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-leyipit9mife"
2024/12/25 01:59:06 DEBUG : Config file has changed externally - reloading
2024/12/25 01:59:06 DEBUG : Creating backend with remote "TestDrive:crypt/m3vn272uvlq0tr1u5hdjqne6s44ituqkgfi2qv26j06506429epg"
2024/12/25 01:59:07 DEBUG : empty space: Excluded (Size Filter)
2024/12/25 01:59:07 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/25 01:59:07 DEBUG : potato3: Need to transfer - File not found at Destination
2024/12/25 01:59:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-leyipit9mife': Waiting for checks to finish
2024/12/25 01:59:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-leyipit9mife': Waiting for transfers to finish
2024/12/25 01:59:09 INFO  : potato2: Moved (server-side)
2024/12/25 01:59:10 INFO  : potato3: Moved (server-side)
2024/12/25 01:59:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-leyipit9mife': Purge remote
2024/12/25 01:59:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-debiwow0fine': Purge remote
--- PASS: TestServerSideMoveWithFilter (20.23s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:59:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qepefot8nuhe"
2024/12/25 01:59:12 DEBUG : Creating backend with remote "TestDrive:crypt/0tiep0iu7nrtq7u7a31c55m9frpuvttsejoava59tledagdk00e0"
2024/12/25 01:59:15 DEBUG : potato2: md5 = a72a9199fd2b918bbcb2dbdb55b5ea42 OK
2024/12/25 01:59:16 DEBUG : empty space: md5 = 0941cdfbddface6716e33678e499281b OK
2024/12/25 01:59:18 DEBUG : potato3: md5 = 6601961b2128d840963776b451212894 OK
2024/12/25 01:59:18 DEBUG : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu' -> Encrypted drive 'TestCryptDrive:rclone-test-qepefot8nuhe'
2024/12/25 01:59:22 DEBUG : empty space: md5 = 61c06a7fbeafea900c0fa150dd266010 OK
2024/12/25 01:59:24 DEBUG : potato3: md5 = d134089ef4de498376b5ad88410a8210 OK
2024/12/25 01:59:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qepefot8nuhe': Using server-side directory move
2024/12/25 01:59:24 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-qepefot8nuhe': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/12/25 01:59:25 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/25 01:59:25 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2024/12/25 01:59:25 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/12/25 01:59:25 DEBUG : empty space: Unchanged skipping
2024/12/25 01:59:25 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/12/25 01:59:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qepefot8nuhe': Waiting for checks to finish
2024/12/25 01:59:25 INFO  : empty space: Deleted
2024/12/25 01:59:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qepefot8nuhe': Waiting for transfers to finish
2024/12/25 01:59:25 INFO  : potato3: Deleted
2024/12/25 01:59:26 INFO  : potato2: Moved (server-side)
2024/12/25 01:59:26 INFO  : potato3: Moved (server-side)
2024/12/25 01:59:26 INFO  : tomatoDir: Removing directory
2024/12/25 01:59:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': deleted 1 directories
2024/12/25 01:59:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-seledon5haqi"
2024/12/25 01:59:28 DEBUG : Creating backend with remote "TestDrive:crypt/qdi00cq866hosjg1n5lha4dpld23u3pr28iuv52gcn3bm9peqmqg"
2024/12/25 01:59:29 DEBUG : tomatoDir: Making directory
2024/12/25 01:59:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-seledon5haqi': Using server-side directory move
2024/12/25 01:59:31 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-seledon5haqi': Server side directory move succeeded
2024/12/25 01:59:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-seledon5haqi': Purge remote
2024/12/25 01:59:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qepefot8nuhe': Purge remote
2024/12/25 01:59:33 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (21.03s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.46s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:59:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/rclone-sync-test"
2024/12/25 01:59:34 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncOverlap (3.77s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:59:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/rclone-sync-test"
2024/12/25 01:59:37 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2024/12/25 01:59:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/rclone-sync-test-include/layer2"
2024/12/25 01:59:40 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2024/12/25 01:59:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/rclone-sync-test-ignore-file"
2024/12/25 01:59:43 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2024/12/25 01:59:48 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 86a25f2396a25303472862916965eb34 OK
2024/12/25 01:59:50 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/12/25 01:59:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/rclone-sync-test': Waiting for checks to finish
2024/12/25 01:59:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/rclone-sync-test': Waiting for transfers to finish
2024/12/25 01:59:50 DEBUG : Waiting for deletions to finish
2024/12/25 01:59:50 INFO  : There was nothing to transfer
2024/12/25 01:59:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:59:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:59:52 DEBUG : Waiting for deletions to finish
2024/12/25 01:59:52 INFO  : rclone-sync-test-include: Removing directory
2024/12/25 01:59:52 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/12/25 01:59:52 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/12/25 01:59:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': failed to delete 1 directories
2024/12/25 01:59:52 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:59:54 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/12/25 01:59:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/rclone-sync-test-include/layer2': Waiting for checks to finish
2024/12/25 01:59:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/rclone-sync-test-include/layer2': Waiting for transfers to finish
2024/12/25 01:59:54 DEBUG : Waiting for deletions to finish
2024/12/25 01:59:54 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:59:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 01:59:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 01:59:56 DEBUG : Waiting for deletions to finish
2024/12/25 01:59:56 INFO  : rclone-sync-test-include: Removing directory
2024/12/25 01:59:56 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/12/25 01:59:56 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/12/25 01:59:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': failed to delete 1 directories
2024/12/25 01:59:56 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 01:59:58 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/12/25 01:59:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/rclone-sync-test-ignore-file': Waiting for checks to finish
2024/12/25 01:59:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/rclone-sync-test-ignore-file': Waiting for transfers to finish
2024/12/25 01:59:58 DEBUG : Waiting for deletions to finish
2024/12/25 01:59:58 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:00:00 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/12/25 02:00:01 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (33.03s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:00:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/dst"
2024/12/25 02:00:11 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/25 02:00:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/CompareDest"
2024/12/25 02:00:12 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/gveqi14airsml4bgu7krj116o8"
2024/12/25 02:00:14 DEBUG : one: Need to transfer - File not found at Destination
2024/12/25 02:00:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:00:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:00:17 DEBUG : one: md5 = 6b2984ea22d2066c51132f907eeb9029 OK
2024/12/25 02:00:17 INFO  : one: Copied (new)
2024/12/25 02:00:17 DEBUG : Waiting for deletions to finish
2024/12/25 02:00:18 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/25 02:00:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:00:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:00:19 DEBUG : one: md5 = 8c68a9096d4484ac956d34c1f67d9e86 OK
2024/12/25 02:00:19 INFO  : one: Copied (replaced existing)
2024/12/25 02:00:19 DEBUG : Waiting for deletions to finish
2024/12/25 02:00:22 DEBUG : dst/one: md5 = b50cce3cd6bfcb782264b4a665771281 OK
2024/12/25 02:00:24 DEBUG : CompareDest/one: md5 = 07219b94e2c28a52663f43c1d736a5c5 OK
2024/12/25 02:00:25 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/25 02:00:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:00:25 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 02:00:25 DEBUG : one: Destination found in --compare-dest, skipping
2024/12/25 02:00:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:00:25 DEBUG : Waiting for deletions to finish
2024/12/25 02:00:25 INFO  : There was nothing to transfer
2024/12/25 02:00:27 DEBUG : CompareDest/two: md5 = 6ece86013573ed3dc051c349e540be7d OK
2024/12/25 02:00:28 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 02:00:28 DEBUG : two: Destination found in --compare-dest, skipping
2024/12/25 02:00:28 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/25 02:00:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:00:29 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 02:00:29 DEBUG : one: Destination found in --compare-dest, skipping
2024/12/25 02:00:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:00:29 DEBUG : Waiting for deletions to finish
2024/12/25 02:00:29 INFO  : There was nothing to transfer
2024/12/25 02:00:30 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 02:00:30 DEBUG : two: Destination found in --compare-dest, skipping
2024/12/25 02:00:30 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/25 02:00:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:00:30 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 02:00:30 DEBUG : one: Destination found in --compare-dest, skipping
2024/12/25 02:00:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:00:30 DEBUG : Waiting for deletions to finish
2024/12/25 02:00:30 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2024/12/25 02:00:31 DEBUG : two: Sizes differ (src 5 vs dst 3)
2024/12/25 02:00:31 DEBUG : two: Need to transfer - File not found at Destination
2024/12/25 02:00:31 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/25 02:00:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:00:32 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 02:00:32 DEBUG : one: Destination found in --compare-dest, skipping
2024/12/25 02:00:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:00:33 DEBUG : two: md5 = 71941ea3fd68a255fe01935df515a09e OK
2024/12/25 02:00:33 INFO  : two: Copied (new)
2024/12/25 02:00:33 DEBUG : Waiting for deletions to finish
2024/12/25 02:00:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/25 02:00:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/25 02:00:37 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/25 02:00:37 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncCompareDest (27.59s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:00:41 DEBUG : pre-dest1/1: md5 = 43882b8643de246bbfa56cbbe4b7fcbc OK
2024/12/25 02:00:43 DEBUG : pre-dest2/2: md5 = 57e7a43e7c3732058fae82e7e19bd05c OK
2024/12/25 02:00:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/dest"
2024/12/25 02:00:44 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/rg03c1jvnehrrc617i0lnqjddc"
2024/12/25 02:00:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/pre-dest1"
2024/12/25 02:00:45 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/bbnblvh6k061ssopqrp18kd7gc"
2024/12/25 02:00:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/pre-dest2"
2024/12/25 02:00:46 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/dgicm1h6b5ejvlltm8eeif0bnk"
2024/12/25 02:00:47 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:00:47 DEBUG : 1: Destination found in --compare-dest, skipping
2024/12/25 02:00:48 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:00:48 DEBUG : 2: Destination found in --compare-dest, skipping
2024/12/25 02:00:48 DEBUG : 3: Need to transfer - File not found at Destination
2024/12/25 02:00:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dest': Waiting for checks to finish
2024/12/25 02:00:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dest': Waiting for transfers to finish
2024/12/25 02:00:51 DEBUG : 3: md5 = feb739369779d0f6f9e08d8e00f926af OK
2024/12/25 02:00:51 INFO  : 3: Copied (new)
2024/12/25 02:00:51 DEBUG : Waiting for deletions to finish
2024/12/25 02:00:54 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2024/12/25 02:00:55 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2024/12/25 02:00:56 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (18.25s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:00:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/dst"
2024/12/25 02:00:56 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/25 02:00:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/CopyDest"
2024/12/25 02:00:58 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/d09o6po3f7bm6ce32vdgs8h9ls"
2024/12/25 02:01:00 DEBUG : one: Need to transfer - File not found at Destination
2024/12/25 02:01:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:01:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:01:02 DEBUG : one: md5 = 4c289509e395527cabea712ca428935a OK
2024/12/25 02:01:02 INFO  : one: Copied (new)
2024/12/25 02:01:02 DEBUG : Waiting for deletions to finish
2024/12/25 02:01:04 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/25 02:01:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:01:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:01:05 DEBUG : one: md5 = 624e25c6922a9d369b4e6ba4a9a6b365 OK
2024/12/25 02:01:05 INFO  : one: Copied (replaced existing)
2024/12/25 02:01:05 DEBUG : Waiting for deletions to finish
2024/12/25 02:01:07 DEBUG : dst/one: md5 = fe5a6ff249a8e50c210006b26ba0e7a2 OK
2024/12/25 02:01:10 DEBUG : CopyDest/one: md5 = 263cfdb5c2a1f5b935f941ec754f7d1b OK
2024/12/25 02:01:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/BackupDir"
2024/12/25 02:01:10 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/s6dbk3lfi7c9kfvo6j7bla9m0g"
2024/12/25 02:01:12 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/25 02:01:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:01:13 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 02:01:13 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/25 02:01:15 INFO  : one: Moved (server-side)
2024/12/25 02:01:16 INFO  : one: Copied (server-side copy)
2024/12/25 02:01:16 DEBUG : one: Destination found in --copy-dest, using server-side copy
2024/12/25 02:01:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:01:16 DEBUG : Waiting for deletions to finish
2024/12/25 02:01:18 DEBUG : CopyDest/two: md5 = fe4213ed3101faad3ea16f80e577efc2 OK
2024/12/25 02:01:19 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 02:01:21 INFO  : two: Copied (server-side copy)
2024/12/25 02:01:21 DEBUG : two: Destination found in --copy-dest, using server-side copy
2024/12/25 02:01:21 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 02:01:21 DEBUG : one: Unchanged skipping
2024/12/25 02:01:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:01:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:01:21 DEBUG : Waiting for deletions to finish
2024/12/25 02:01:21 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 02:01:21 DEBUG : one: Unchanged skipping
2024/12/25 02:01:21 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 02:01:21 DEBUG : two: Unchanged skipping
2024/12/25 02:01:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:01:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:01:21 DEBUG : Waiting for deletions to finish
2024/12/25 02:01:21 INFO  : There was nothing to transfer
2024/12/25 02:01:23 DEBUG : CopyDest/three: md5 = 2181977633a5fc642922a25e6cc53f59 OK
2024/12/25 02:01:24 DEBUG : three: Sizes differ (src 7 vs dst 5)
2024/12/25 02:01:24 DEBUG : three: Destination not found in --copy-dest
2024/12/25 02:01:24 DEBUG : three: Need to transfer - File not found at Destination
2024/12/25 02:01:24 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 02:01:24 DEBUG : one: Unchanged skipping
2024/12/25 02:01:24 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/25 02:01:24 DEBUG : two: Unchanged skipping
2024/12/25 02:01:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:01:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:01:26 DEBUG : three: md5 = 9cedea6726caa38ec3683d16912523c3 OK
2024/12/25 02:01:26 INFO  : three: Copied (new)
2024/12/25 02:01:26 DEBUG : Waiting for deletions to finish
2024/12/25 02:01:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/12/25 02:01:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/25 02:01:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/25 02:01:32 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/12/25 02:01:32 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/25 02:01:32 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/25 02:01:33 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (37.06s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:01:36 DEBUG : dst/one: md5 = efad9f07ff40782b20339c1379fa1122 OK
2024/12/25 02:01:38 DEBUG : dst/two: md5 = 2aea71bd83f46fe034869dffe1b308c2 OK
2024/12/25 02:01:39 DEBUG : dst/three.txt: md5 = ca9255510c9110a887a1c631bc88e215 OK
2024/12/25 02:01:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/dst"
2024/12/25 02:01:40 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/25 02:01:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/backup"
2024/12/25 02:01:40 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/1nrff024r7pq65ecp72fc28jb0"
2024/12/25 02:01:42 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/25 02:01:42 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:01:42 DEBUG : two: Unchanged skipping
2024/12/25 02:01:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:01:44 INFO  : one: Moved (server-side)
2024/12/25 02:01:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:01:46 DEBUG : one: md5 = 878b79e2302d9456174d5508b9721f79 OK
2024/12/25 02:01:46 INFO  : one: Copied (new)
2024/12/25 02:01:46 DEBUG : Waiting for deletions to finish
2024/12/25 02:01:47 INFO  : three.txt: Moved (server-side)
2024/12/25 02:01:47 INFO  : three.txt: Moved into backup dir
2024/12/25 02:01:49 DEBUG : dst/three.txt: md5 = dbbc3f0dc02b982bdf60888f7a1b1855 OK
2024/12/25 02:01:50 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/25 02:01:50 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:01:50 DEBUG : two: Unchanged skipping
2024/12/25 02:01:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:01:50 INFO  : one: Deleted
2024/12/25 02:01:51 INFO  : one: Moved (server-side)
2024/12/25 02:01:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:01:53 DEBUG : one: md5 = ffc9f8e0bbacf78b6a70e0c203499fa4 OK
2024/12/25 02:01:53 INFO  : one: Copied (new)
2024/12/25 02:01:53 DEBUG : Waiting for deletions to finish
2024/12/25 02:01:54 INFO  : three.txt: Deleted
2024/12/25 02:01:55 INFO  : three.txt: Moved (server-side)
2024/12/25 02:01:55 INFO  : three.txt: Moved into backup dir
2024/12/25 02:01:58 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/25 02:01:58 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/25 02:01:59 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/12/25 02:01:59 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/25 02:01:59 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/25 02:01:59 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
--- PASS: TestSyncBackupDir (26.16s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:02:02 DEBUG : dst/one: md5 = 4a8423174fee316d9617b473253796d1 OK
2024/12/25 02:02:04 DEBUG : dst/two: md5 = d6f70fa4b266768726cd0618f183b1db OK
2024/12/25 02:02:05 DEBUG : dst/three.txt: md5 = ee3eaf85885c690e6a358bbc7ae8c9bf OK
2024/12/25 02:02:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/dst"
2024/12/25 02:02:06 DEBUG : Config file has changed externally - reloading
2024/12/25 02:02:06 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/25 02:02:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/backup"
2024/12/25 02:02:07 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/1nrff024r7pq65ecp72fc28jb0"
2024/12/25 02:02:09 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/25 02:02:09 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:02:09 DEBUG : two: Unchanged skipping
2024/12/25 02:02:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:02:11 INFO  : one: Moved (server-side) to: one.bak
2024/12/25 02:02:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:02:12 DEBUG : one: md5 = 5012b1126f01b83e156427ed3c8ab353 OK
2024/12/25 02:02:12 INFO  : one: Copied (new)
2024/12/25 02:02:12 DEBUG : Waiting for deletions to finish
2024/12/25 02:02:13 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/25 02:02:13 INFO  : three.txt: Moved into backup dir
2024/12/25 02:02:15 DEBUG : dst/three.txt: md5 = 05241a7d308647f24763fb97cf69196a OK
2024/12/25 02:02:16 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/25 02:02:16 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:02:16 DEBUG : two: Unchanged skipping
2024/12/25 02:02:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:02:17 INFO  : one.bak: Deleted
2024/12/25 02:02:18 INFO  : one: Moved (server-side) to: one.bak
2024/12/25 02:02:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:02:19 DEBUG : one: md5 = 4e2a4db9ac9717bafe1fe0f03868e51b OK
2024/12/25 02:02:19 INFO  : one: Copied (new)
2024/12/25 02:02:19 DEBUG : Waiting for deletions to finish
2024/12/25 02:02:20 INFO  : three.txt.bak: Deleted
2024/12/25 02:02:21 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/25 02:02:21 INFO  : three.txt: Moved into backup dir
2024/12/25 02:02:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/25 02:02:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/25 02:02:25 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/12/25 02:02:25 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/12/25 02:02:25 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/12/25 02:02:25 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirWithSuffix (26.52s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:02:29 DEBUG : dst/one: md5 = 95bcedddaf71294e4bce647aa17b5b3d OK
2024/12/25 02:02:30 DEBUG : dst/two: md5 = ac91966de15ed32ee95574963c1bf56e OK
2024/12/25 02:02:32 DEBUG : dst/three.txt: md5 = 8ba2386d8ca6cea9573220eac6e0cd90 OK
2024/12/25 02:02:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/dst"
2024/12/25 02:02:32 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/25 02:02:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/backup"
2024/12/25 02:02:33 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/1nrff024r7pq65ecp72fc28jb0"
2024/12/25 02:02:35 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/25 02:02:35 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:02:35 DEBUG : two: Unchanged skipping
2024/12/25 02:02:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:02:37 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/12/25 02:02:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:02:38 DEBUG : one: md5 = e176888669b91deda6a0dbf1f140f5da OK
2024/12/25 02:02:38 INFO  : one: Copied (new)
2024/12/25 02:02:38 DEBUG : Waiting for deletions to finish
2024/12/25 02:02:39 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/12/25 02:02:39 INFO  : three.txt: Moved into backup dir
2024/12/25 02:02:41 DEBUG : dst/three.txt: md5 = 0070bd9a28f4c2eb0bac8fcd83f4071f OK
2024/12/25 02:02:42 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/25 02:02:42 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:02:42 DEBUG : two: Unchanged skipping
2024/12/25 02:02:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:02:43 INFO  : one-2019-01-01: Deleted
2024/12/25 02:02:44 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/12/25 02:02:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:02:45 DEBUG : one: md5 = 70e6efc04c537133fb6b4c6d177c384a OK
2024/12/25 02:02:45 INFO  : one: Copied (new)
2024/12/25 02:02:45 DEBUG : Waiting for deletions to finish
2024/12/25 02:02:46 INFO  : three-2019-01-01.txt: Deleted
2024/12/25 02:02:47 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/12/25 02:02:47 INFO  : three.txt: Moved into backup dir
2024/12/25 02:02:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/25 02:02:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/25 02:02:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/12/25 02:02:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/12/25 02:02:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/12/25 02:02:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (26.08s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:02:55 DEBUG : dst/one: md5 = fd4f4288c9b829403eef09593205b8ab OK
2024/12/25 02:02:56 DEBUG : dst/two: md5 = 7d3a7301347ed255d1119bec32dea048 OK
2024/12/25 02:02:58 DEBUG : dst/three.txt: md5 = be3f9f421679d308cc90203d428534de OK
2024/12/25 02:02:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/dst"
2024/12/25 02:02:59 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/25 02:03:00 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/25 02:03:00 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:03:00 DEBUG : two: Unchanged skipping
2024/12/25 02:03:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:03:00 INFO  : one: Moved (server-side) to: one.bak
2024/12/25 02:03:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:03:02 DEBUG : one: md5 = 4c85f08ed13527f943c3f564307b3a9b OK
2024/12/25 02:03:02 INFO  : one: Copied (new)
2024/12/25 02:03:02 DEBUG : Waiting for deletions to finish
2024/12/25 02:03:03 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/25 02:03:03 INFO  : three.txt: Moved into backup dir
2024/12/25 02:03:05 DEBUG : dst/three.txt: md5 = b8044a54a24bdafcaadca2fcfa8c2785 OK
2024/12/25 02:03:06 DEBUG : one.bak: Excluded (Path Filter)
2024/12/25 02:03:06 DEBUG : three.txt.bak: Excluded (Path Filter)
2024/12/25 02:03:06 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/25 02:03:06 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:03:06 DEBUG : two: Unchanged skipping
2024/12/25 02:03:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for checks to finish
2024/12/25 02:03:06 INFO  : one.bak: Deleted
2024/12/25 02:03:07 INFO  : one: Moved (server-side) to: one.bak
2024/12/25 02:03:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu/dst': Waiting for transfers to finish
2024/12/25 02:03:09 DEBUG : one: md5 = 1e773824ba2808196c512cb63151e070 OK
2024/12/25 02:03:09 INFO  : one: Copied (new)
2024/12/25 02:03:09 DEBUG : Waiting for deletions to finish
2024/12/25 02:03:09 INFO  : three.txt.bak: Deleted
2024/12/25 02:03:10 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/25 02:03:10 INFO  : three.txt: Moved into backup dir
2024/12/25 02:03:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/25 02:03:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/12/25 02:03:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/12/25 02:03:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/12/25 02:03:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/12/25 02:03:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncBackupDirSuffixOnly (21.85s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:03:17 DEBUG : dst/one: md5 = 837eb908a531f52d3df027b8cb1446ef OK
2024/12/25 02:03:18 DEBUG : dst/two: md5 = 921341f38c1130641821824219959e4b OK
2024/12/25 02:03:20 DEBUG : dst/three.txt: md5 = cdb3f9eb2b4969c121d04f309e6f42b1 OK
2024/12/25 02:03:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/dst"
2024/12/25 02:03:20 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/25 02:03:21 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/25 02:03:22 INFO  : one: Moved (server-side) to: one.bak
2024/12/25 02:03:23 DEBUG : one: md5 = 3aa36bbf49e1557b39b2e61945c8f130 OK
2024/12/25 02:03:23 INFO  : one: Copied (new)
2024/12/25 02:03:24 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:03:24 DEBUG : two: Unchanged skipping
2024/12/25 02:03:24 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/12/25 02:03:25 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/25 02:03:26 DEBUG : three.txt: md5 = a33786a4165229380f3e7dae036e5356 OK
2024/12/25 02:03:26 INFO  : three.txt: Copied (new)
2024/12/25 02:03:28 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/25 02:03:28 INFO  : one.bak: Deleted
2024/12/25 02:03:29 INFO  : one: Moved (server-side) to: one.bak
2024/12/25 02:04:06 DEBUG : one: md5 = 0de1abfec1cc1c22d4c61131420d3943 OK
2024/12/25 02:04:06 INFO  : one: Copied (new)
2024/12/25 02:04:07 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:04:07 DEBUG : two: Unchanged skipping
2024/12/25 02:04:07 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/12/25 02:04:08 INFO  : three.txt.bak: Deleted
2024/12/25 02:04:08 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/25 02:04:10 DEBUG : three.txt: md5 = f37be7c4f076f8626fc0bd190bb0a54b OK
2024/12/25 02:04:10 INFO  : three.txt: Copied (new)
2024/12/25 02:04:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/12/25 02:04:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/25 02:04:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/12/25 02:04:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/12/25 02:04:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/25 02:04:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/12/25 02:04:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncSuffix (61.03s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:04:18 DEBUG : dst/one: md5 = aaa9c87e50765da435e33d69167f3ab9 OK
2024/12/25 02:04:19 DEBUG : dst/two: md5 = 98b54731dc3d53a7afea4f6b8529291b OK
2024/12/25 02:04:21 DEBUG : dst/three.txt: md5 = f258c714f24573508b7dd47b0da2c173 OK
2024/12/25 02:04:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mutewan0nusu/dst"
2024/12/25 02:04:22 DEBUG : Creating backend with remote "TestDrive:crypt/l9a8dgjn3rn8j571epfupo4qvumd9jcv61e69sdoh5rasmr6b9s0/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/25 02:04:23 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/25 02:04:23 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/12/25 02:04:25 DEBUG : one: md5 = 0dcd784cb45b0f0dac18c3d7c997347f OK
2024/12/25 02:04:25 INFO  : one: Copied (new)
2024/12/25 02:04:25 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:04:25 DEBUG : two: Unchanged skipping
2024/12/25 02:04:26 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/12/25 02:04:26 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/12/25 02:04:28 DEBUG : three.txt: md5 = 27d2245fffbdc065ec25f6eebced5461 OK
2024/12/25 02:04:28 INFO  : three.txt: Copied (new)
2024/12/25 02:04:29 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/25 02:04:30 INFO  : one-2019-01-01: Deleted
2024/12/25 02:04:31 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/12/25 02:04:32 DEBUG : one: md5 = bf52edd74d5061ab1854a7361d646ca3 OK
2024/12/25 02:04:32 INFO  : one: Copied (new)
2024/12/25 02:04:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:04:33 DEBUG : two: Unchanged skipping
2024/12/25 02:04:33 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/12/25 02:04:34 INFO  : three-2019-01-01.txt: Deleted
2024/12/25 02:04:34 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/12/25 02:04:36 DEBUG : three.txt: md5 = 06110f01a58736332c7d68e3da3098c1 OK
2024/12/25 02:04:36 INFO  : three.txt: Copied (new)
2024/12/25 02:04:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/12/25 02:04:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/25 02:04:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/12/25 02:04:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/25 02:04:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/12/25 02:04:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/12/25 02:04:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncSuffixKeepExtension (25.76s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:04:42 DEBUG : Testêé: md5 = 7bb60d655a7b4999af7a7637500ceb50 OK
2024/12/25 02:04:43 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2024/12/25 02:04:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 02:04:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 02:04:44 DEBUG : Testêé: md5 = 5ed4ee65e60adeb9a3f87bec7a2d669a OK
2024/12/25 02:04:44 INFO  : Testêé: Copied (replaced existing) to: Testêé
2024/12/25 02:04:44 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (4.42s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:04:46 DEBUG : existing: Need to transfer - File not found at Destination
2024/12/25 02:04:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 02:04:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 02:04:47 DEBUG : existing: md5 = d7008091deadd0fbe3c37c1c150a8d9f OK
2024/12/25 02:04:47 INFO  : existing: Copied (new)
2024/12/25 02:04:47 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:04:48 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2024/12/25 02:04:48 ERROR : existing: Source and destination exist but do not match: immutable file modified
2024/12/25 02:04:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 02:04:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 02:04:48 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': not deleting files as there were IO errors
2024/12/25 02:04:48 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncImmutable (5.04s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:04:52 DEBUG : EXISTING: md5 = 5ac7702449f2528e8488e581717f8b74 OK
2024/12/25 02:04:52 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:04:52 DEBUG : existing: Unchanged skipping
2024/12/25 02:04:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 02:04:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 02:04:52 DEBUG : Waiting for deletions to finish
2024/12/25 02:04:52 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (3.51s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.45s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
=== RUN   TestMaxTransfer/Soft
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
=== RUN   TestMaxTransfer/Cautious
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.36s)
    --- SKIP: TestMaxTransfer/Hard (0.44s)
    --- SKIP: TestMaxTransfer/Soft (0.46s)
    --- SKIP: TestMaxTransfer/Cautious (0.46s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:04:57 DEBUG : both0: md5 = e91889a8d368cf16abae29d475fdedc7 OK
2024/12/25 02:04:59 DEBUG : only0: md5 = 97e377b59d153ae6914e1f6e562fe291 OK
2024/12/25 02:05:00 DEBUG : both1: md5 = 7c07d42a618a9fd89613d427dbf8908a OK
2024/12/25 02:05:02 DEBUG : only1: md5 = 58d5d88667aad3169f71e196cc58fec5 OK
2024/12/25 02:05:04 DEBUG : both2: md5 = 87bf908aa45ad7a346d597744ff0182c OK
2024/12/25 02:05:05 DEBUG : only2: md5 = 7b1b6d28738b6cdb82a1715e86164000 OK
2024/12/25 02:05:07 DEBUG : both3: md5 = b18cead7ea5a26f419fa342e14ac166f OK
2024/12/25 02:05:08 DEBUG : only3: md5 = 84d9d985c991f613049feb45354e80c8 OK
2024/12/25 02:05:10 DEBUG : both4: md5 = d1cbe610650658afed3552b9f47c271b OK
2024/12/25 02:05:12 DEBUG : only4: md5 = 9a817ce2ebe6f09a6a00f5c57b41e72f OK
2024/12/25 02:05:13 DEBUG : both5: md5 = 8c814f2093fbcf5c00f17398857b897e OK
2024/12/25 02:05:15 DEBUG : only5: md5 = a5a7fa255c71c707e28b7901038e694d OK
2024/12/25 02:05:17 DEBUG : both6: md5 = 6fb472bfc66b9b8959bd353b624c07b8 OK
2024/12/25 02:05:18 DEBUG : only6: md5 = b8058e49f59ff73a7dc198d086791d78 OK
2024/12/25 02:05:20 DEBUG : both7: md5 = 01a609d4873522bd8918f5882305f4ab OK
2024/12/25 02:05:22 DEBUG : only7: md5 = cd8ab30e2ffa0c84bdbe62bc4c49af4b OK
2024/12/25 02:05:23 DEBUG : both8: md5 = 11f89b222ec2845dec024a5d05b651de OK
2024/12/25 02:05:25 DEBUG : only8: md5 = 4bbdc4fb8485ed1ceb10865492d8894e OK
2024/12/25 02:05:27 DEBUG : both9: md5 = c039494461676c6db67afcf090e57ca6 OK
2024/12/25 02:05:29 DEBUG : only9: md5 = feee4bb4bc92c8b5a4776149003d9140 OK
2024/12/25 02:05:30 DEBUG : both10: md5 = 110e25cf19cfc762aabbb25d7f248cba OK
2024/12/25 02:05:32 DEBUG : only10: md5 = f87a5f5d8c0c0904135164d00a6fad44 OK
2024/12/25 02:05:34 DEBUG : both11: md5 = 357039c88e4b760fe58e5df10bc18699 OK
2024/12/25 02:05:35 DEBUG : only11: md5 = bf927891df80e68d046afed7f2a65bc0 OK
2024/12/25 02:05:37 DEBUG : both12: md5 = 2e18fb593d3609c97949089fb6c7bd59 OK
2024/12/25 02:05:39 DEBUG : only12: md5 = 10c7821d8314560def2a686bbcd4cad6 OK
2024/12/25 02:05:40 DEBUG : both13: md5 = 21845cd96f7a167fc2c7163a76298e24 OK
2024/12/25 02:05:42 DEBUG : only13: md5 = 567bf48f49dad35a0f3caf900c71b56b OK
2024/12/25 02:05:44 DEBUG : both14: md5 = 8bf06fd66d017149ba1079f5b643c86b OK
2024/12/25 02:05:45 DEBUG : only14: md5 = 318274832f19d3831d6cf604bb3b1d33 OK
2024/12/25 02:05:47 DEBUG : both15: md5 = c795650fce5589016fcae192d9197002 OK
2024/12/25 02:05:49 DEBUG : only15: md5 = 84dd409b06e12db330c1e0032a24b9f1 OK
2024/12/25 02:05:50 DEBUG : both16: md5 = 59cbf6d9a379cf95e88da8bcf6db779a OK
2024/12/25 02:05:52 DEBUG : only16: md5 = 3c14bd141c889ab3d7e73a79e25d8a5f OK
2024/12/25 02:05:53 DEBUG : both17: md5 = 737639d9bc1c95532d5e5827c3f13416 OK
2024/12/25 02:05:55 DEBUG : only17: md5 = 9f89f293f19acd2c269b2a18cfe3f05d OK
2024/12/25 02:05:57 DEBUG : both18: md5 = 59d5797799796d806a744a315bc782fe OK
2024/12/25 02:05:58 DEBUG : only18: md5 = 97c1cc1acb3df47747e1653aec5ea769 OK
2024/12/25 02:06:00 DEBUG : both19: md5 = 2ebbd28ed5353e81eb9bfcf941e24f6c OK
2024/12/25 02:06:01 DEBUG : only19: md5 = 43389ae2e01cd0c7cf4cc35c414a6fc1 OK
2024/12/25 02:06:02 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 02:06:02 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both1: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both0: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both13: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both14: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both15: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both16: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both17: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both18: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both19: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both10: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both3: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both4: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both5: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both6: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both7: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both8: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:06:02 DEBUG : both9: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both11: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both12: Unchanged skipping
2024/12/25 02:06:02 DEBUG : both2: Unchanged skipping
2024/12/25 02:06:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 02:06:02 DEBUG : Waiting for deletions to finish
2024/12/25 02:06:02 INFO  : only4: Deleted
2024/12/25 02:06:02 INFO  : only2: Deleted
2024/12/25 02:06:02 INFO  : only1: Deleted
2024/12/25 02:06:02 INFO  : only0: Deleted
2024/12/25 02:06:03 INFO  : only11: Deleted
2024/12/25 02:06:03 INFO  : only13: Deleted
2024/12/25 02:06:03 INFO  : only12: Deleted
2024/12/25 02:06:03 INFO  : only5: Deleted
2024/12/25 02:06:03 INFO  : only15: Deleted
2024/12/25 02:06:03 INFO  : only19: Deleted
2024/12/25 02:06:04 INFO  : only18: Deleted
2024/12/25 02:06:04 INFO  : only3: Deleted
2024/12/25 02:06:04 INFO  : only7: Deleted
2024/12/25 02:06:04 INFO  : only9: Deleted
2024/12/25 02:06:04 INFO  : only14: Deleted
2024/12/25 02:06:04 INFO  : only16: Deleted
2024/12/25 02:06:05 INFO  : only17: Deleted
2024/12/25 02:06:05 INFO  : only10: Deleted
2024/12/25 02:06:05 INFO  : only6: Deleted
2024/12/25 02:06:05 INFO  : only8: Deleted
2024/12/25 02:06:05 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (81.15s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:06:18 DEBUG : both0: md5 = 808b04998da5f5ea7361fd22aa4bc8be OK
2024/12/25 02:06:20 DEBUG : only0: md5 = 4371ad3d959edf4df3a6b0c3cf8455f7 OK
2024/12/25 02:06:21 DEBUG : both1: md5 = baa655d6aebc9ac342053151a7a49081 OK
2024/12/25 02:06:23 DEBUG : only1: md5 = cba78c678f9a91d5a4fc9eccbe3c3721 OK
2024/12/25 02:06:24 DEBUG : both2: md5 = c9d3e2af5955562c3781690dcb711e08 OK
2024/12/25 02:06:26 DEBUG : only2: md5 = afff76612fca1c4ac203f21dee5a7109 OK
2024/12/25 02:06:27 DEBUG : both3: md5 = cced3aa89fdd6ee4c76f198c064bb475 OK
2024/12/25 02:06:29 DEBUG : only3: md5 = 7c853dc4ac3304965f7336b673de07fb OK
2024/12/25 02:06:31 DEBUG : both4: md5 = d5970cac8122a65bed3e029c2cd936dc OK
2024/12/25 02:06:32 DEBUG : only4: md5 = 7d8e44b435ae91b88ff25bb44a4be667 OK
2024/12/25 02:06:34 DEBUG : both5: md5 = 82ed4f12f34661055c735be8d271e80c OK
2024/12/25 02:06:36 DEBUG : only5: md5 = 695696ff3efdef25e1b8c66a19309836 OK
2024/12/25 02:06:37 DEBUG : both6: md5 = ac030d03389dcb5de1fc1cab35fe4000 OK
2024/12/25 02:06:39 DEBUG : only6: md5 = b6b2705e55b1bc733bfe9388f62f1963 OK
2024/12/25 02:06:40 DEBUG : both7: md5 = 8dff60f30dc973a4cc7a2dfca9514f99 OK
2024/12/25 02:06:42 DEBUG : only7: md5 = 11fbed8640fb1f678f31d54ed8c8d21b OK
2024/12/25 02:06:44 DEBUG : both8: md5 = 27efe3c1ea376f6738b388b0946c2d8a OK
2024/12/25 02:06:45 DEBUG : only8: md5 = 80f0e7f53a1caec86de085a948c8f089 OK
2024/12/25 02:06:47 DEBUG : both9: md5 = 28f5344ec7de6f8649294c780b4705cd OK
2024/12/25 02:06:49 DEBUG : only9: md5 = 8243e87dc0a4e7ab5785d14812b0e2fe OK
2024/12/25 02:06:50 DEBUG : both10: md5 = b4533f767ca5d156a40c3c0405ca287c OK
2024/12/25 02:06:52 DEBUG : only10: md5 = 99e525988b944dab428c22d6ca364d4a OK
2024/12/25 02:06:54 DEBUG : both11: md5 = 393725a5abb8b94435c3402d1bab6322 OK
2024/12/25 02:06:56 DEBUG : only11: md5 = 96b57a46ef6eca66c60f52c89ea78202 OK
2024/12/25 02:06:57 DEBUG : both12: md5 = 25cbb7a83ac338da874eb4e9c85ad044 OK
2024/12/25 02:06:59 DEBUG : only12: md5 = ab31cbfdec195e4e7f836de056b71a3f OK
2024/12/25 02:07:00 DEBUG : both13: md5 = b39cf07fdb333c7d30b752029703d414 OK
2024/12/25 02:07:02 DEBUG : only13: md5 = 9e82d8e35f41870e709c995a17057c2a OK
2024/12/25 02:07:04 DEBUG : both14: md5 = 4ac6ce7bb36e82d576c9b3f8a5882430 OK
2024/12/25 02:07:05 DEBUG : only14: md5 = 2dfbcfb4355193a7649d5ec675be546d OK
2024/12/25 02:07:07 DEBUG : both15: md5 = 2bc1a897aebc406cc2bb6f299a018214 OK
2024/12/25 02:07:08 DEBUG : only15: md5 = 00b33586fe891a04b52b58b75d864e70 OK
2024/12/25 02:07:10 DEBUG : both16: md5 = 163cbf6e17d381109312e2bb9bc32395 OK
2024/12/25 02:07:11 DEBUG : only16: md5 = e0a72b691dbf377dcc8d508cfa77db0d OK
2024/12/25 02:07:13 DEBUG : both17: md5 = 00662e2d41fa75df02a40242dac69957 OK
2024/12/25 02:07:14 DEBUG : only17: md5 = dbc3d4a2c057542d6bcff4a2e85d340a OK
2024/12/25 02:07:16 DEBUG : both18: md5 = 8c482b28667b6d9b9d88105cd71b4bc1 OK
2024/12/25 02:07:18 DEBUG : only18: md5 = 16ea455fcfa1b2252ec0af94448dbc92 OK
2024/12/25 02:07:19 DEBUG : both19: md5 = 24789e3a6c9304f13543c4eef362b570 OK
2024/12/25 02:07:21 DEBUG : only19: md5 = 08a7ba5a5698e229da799d7cf6eb5156 OK
2024/12/25 02:07:22 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for checks to finish
2024/12/25 02:07:22 DEBUG : both0: Unchanged skipping
2024/12/25 02:07:22 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both12: Unchanged skipping
2024/12/25 02:07:22 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both13: Unchanged skipping
2024/12/25 02:07:22 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both14: Unchanged skipping
2024/12/25 02:07:22 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both15: Unchanged skipping
2024/12/25 02:07:22 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both16: Unchanged skipping
2024/12/25 02:07:22 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both17: Unchanged skipping
2024/12/25 02:07:22 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both18: Unchanged skipping
2024/12/25 02:07:22 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both19: Unchanged skipping
2024/12/25 02:07:22 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both2: Unchanged skipping
2024/12/25 02:07:22 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both3: Unchanged skipping
2024/12/25 02:07:22 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both4: Unchanged skipping
2024/12/25 02:07:22 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both5: Unchanged skipping
2024/12/25 02:07:22 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both6: Unchanged skipping
2024/12/25 02:07:22 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both7: Unchanged skipping
2024/12/25 02:07:22 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both8: Unchanged skipping
2024/12/25 02:07:22 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/25 02:07:22 DEBUG : both9: Unchanged skipping
2024/12/25 02:07:22 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2024/12/25 02:07:22 DEBUG : both10: Unchanged skipping
2024/12/25 02:07:22 DEBUG : both1: Unchanged skipping
2024/12/25 02:07:22 DEBUG : both11: Unchanged skipping
2024/12/25 02:07:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Waiting for transfers to finish
2024/12/25 02:07:23 DEBUG : only1: md5 = 5e5f7bb0a61e1a14900f719e39208ca6 OK
2024/12/25 02:07:23 INFO  : only1: Copied (replaced existing)
2024/12/25 02:07:23 DEBUG : only10: md5 = edd5a5652e08f6d677c2e3780bdaae8b OK
2024/12/25 02:07:23 INFO  : only10: Copied (replaced existing)
2024/12/25 02:07:23 DEBUG : only11: md5 = 86a6804212e1e161d70b247b0b340def OK
2024/12/25 02:07:23 INFO  : only11: Copied (replaced existing)
2024/12/25 02:07:23 DEBUG : only0: md5 = ce4ec6b5149aefaad24c96d0ab0fd59d OK
2024/12/25 02:07:23 INFO  : only0: Copied (replaced existing)
2024/12/25 02:07:24 DEBUG : only12: md5 = 891783767801a308341cde2f1e6468d3 OK
2024/12/25 02:07:24 INFO  : only12: Copied (replaced existing)
2024/12/25 02:07:24 DEBUG : only14: md5 = 185d4dce1fc6dee0dae4f1aa5fcd721b OK
2024/12/25 02:07:24 INFO  : only14: Copied (replaced existing)
2024/12/25 02:07:24 DEBUG : only13: md5 = 535eea254244efc4254b5fe73c2fefcc OK
2024/12/25 02:07:24 INFO  : only13: Copied (replaced existing)
2024/12/25 02:07:24 DEBUG : only15: md5 = 4e18cccd1acb32c47dd743796ca15675 OK
2024/12/25 02:07:24 INFO  : only15: Copied (replaced existing)
2024/12/25 02:07:26 DEBUG : only19: md5 = a41a7b05ab378ad099aeb7bf66ff4f0a OK
2024/12/25 02:07:26 INFO  : only19: Copied (replaced existing)
2024/12/25 02:07:26 DEBUG : only17: md5 = 6c8e87cf71f520832438e2277955aa97 OK
2024/12/25 02:07:26 INFO  : only17: Copied (replaced existing)
2024/12/25 02:07:26 DEBUG : only18: md5 = 5f113b756082ada1da15bb67ac12c365 OK
2024/12/25 02:07:26 INFO  : only18: Copied (replaced existing)
2024/12/25 02:07:26 DEBUG : only16: md5 = 86c4145bf4b517de3c421aaa9708b2a1 OK
2024/12/25 02:07:26 INFO  : only16: Copied (replaced existing)
2024/12/25 02:07:27 DEBUG : only2: md5 = 9606c94e5f1e1230296ab233542da692 OK
2024/12/25 02:07:27 INFO  : only2: Copied (replaced existing)
2024/12/25 02:07:27 DEBUG : only4: md5 = 4171f8e10b57df753a0f414ab04eb4c6 OK
2024/12/25 02:07:27 INFO  : only4: Copied (replaced existing)
2024/12/25 02:07:27 DEBUG : only5: md5 = 5fd9eb0d39e0592e9e46bfebe1f95514 OK
2024/12/25 02:07:27 INFO  : only5: Copied (replaced existing)
2024/12/25 02:07:27 DEBUG : only3: md5 = 4c304d751fb68b272b7fc459b584b0c1 OK
2024/12/25 02:07:27 INFO  : only3: Copied (replaced existing)
2024/12/25 02:07:28 DEBUG : only6: md5 = b1d51fea9d22cfd243f997ac3da8919a OK
2024/12/25 02:07:28 INFO  : only6: Copied (replaced existing)
2024/12/25 02:07:28 DEBUG : only9: md5 = fce0ba5161b6ded39868cc47af52e9d4 OK
2024/12/25 02:07:28 INFO  : only9: Copied (replaced existing)
2024/12/25 02:07:28 DEBUG : only8: md5 = 5533e0deb9fe0489368f6ec3cd9c0700 OK
2024/12/25 02:07:28 INFO  : only8: Copied (replaced existing)
2024/12/25 02:07:28 DEBUG : only7: md5 = 90cfe467d48287465fa92b01426d8407 OK
2024/12/25 02:07:28 INFO  : only7: Copied (replaced existing)
2024/12/25 02:07:28 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (94.10s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:07:51 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/25 02:07:51 DEBUG : sub dir: Making directory with metadata
2024/12/25 02:07:52 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:08:11 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/12/25 02:08:12 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/12/25 02:08:12 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/25 02:08:12 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:08:27 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2024/12/25 02:08:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/12/25 02:08:29 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/12/25 02:08:30 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/12/25 02:08:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/25 02:08:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/25 02:08:32 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/25 02:08:33 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/25 02:08:34 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/12/25 02:08:35 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/12/25 02:08:35 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/25 02:08:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (46.95s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:08:38 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/25 02:08:38 DEBUG : sub dir: Making directory with metadata
2024/12/25 02:08:39 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:09:04 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/12/25 02:09:04 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/12/25 02:09:04 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/25 02:09:04 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu'", Local "Local file system at /tmp/rclone2674766322", Modify Window "1ms"
2024/12/25 02:09:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/12/25 02:09:19 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/12/25 02:09:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/12/25 02:09:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/25 02:09:21 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/25 02:09:22 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/25 02:09:23 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/25 02:09:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/12/25 02:09:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/12/25 02:09:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/25 02:09:25 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (49.81s)
PASS
2024/12/25 02:09:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mutewan0nusu': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 17m42.030801754s (try 1/5)