"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5)
2024/11/26 03:23:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya"
2024/11/26 03:23:25 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/11/26 03:23:25 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80"
2024/11/26 03:23:26 DEBUG : Creating backend with remote "/tmp/rclone2855278465"
=== RUN   TestPipe
--- PASS: TestPipe (0.00s)
=== RUN   TestPipeConcurrent
--- PASS: TestPipeConcurrent (0.03s)
=== 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-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:23:27 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/26 03:23:27 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/26 03:23:27 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2024/11/26 03:23:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:23:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:23:27 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (3.14s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:23:29 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/26 03:23:29 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/26 03:23:29 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/26 03:23:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:23:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:23:32 DEBUG : sub dir/hello world: md5 = 4fa2ee2b395816827e9321ad2c41d547 OK
2024/11/26 03:23:32 INFO  : sub dir/hello world: Copied (new)
2024/11/26 03:23:33 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:23:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (7.31s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:23:36 DEBUG : metadata sub dir: Making directory with metadata
2024/11/26 03:23:36 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/26 03:23:36 DEBUG : empty metadata sub dir: Making directory with metadata
2024/11/26 03:23:36 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/26 03:23:36 DEBUG : Local file system at /tmp/rclone2855278465: File to upload is small (21 bytes), uploading instead of streaming
2024/11/26 03:23:36 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/11/26 03:23:36 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/11/26 03:23:36 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/11/26 03:23:37 DEBUG : Google drive root 'crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80': Skipping btime metadata as can't update it on an existing file: 2024-11-26T03:23:36.606440914Z
2024/11/26 03:23:37 INFO  : empty metadata sub dir: Updated directory metadata
2024/11/26 03:23:38 DEBUG : Google drive root 'crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80': Skipping btime metadata as can't update it on an existing file: 2024-11-26T03:23:36.606440914Z
2024/11/26 03:23:38 INFO  : metadata sub dir: Updated directory metadata
2024/11/26 03:23:38 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/11/26 03:23:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:23:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:23:40 DEBUG : metadata sub dir/hello metadata world: md5 = 00b339ddb71a1f6f470429f44767d3ec OK
2024/11/26 03:23:40 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:23:43 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (9.34s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:23:45 DEBUG : metadata sub dir: Making directory with metadata
2024/11/26 03:23:45 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/26 03:23:45 DEBUG : empty metadata sub dir: Making directory with metadata
2024/11/26 03:23:45 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/26 03:23:45 DEBUG : Local file system at /tmp/rclone2855278465: File to upload is small (21 bytes), uploading instead of streaming
2024/11/26 03:23:45 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/11/26 03:23:45 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/11/26 03:23:45 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/11/26 03:23:46 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2024/11/26 03:23:46 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2024/11/26 03:23:46 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/11/26 03:23:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:23:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:23:49 DEBUG : metadata sub dir/hello metadata world: md5 = 402e25c296d6e2f3fb91510797e50cb2 OK
2024/11/26 03:23:49 INFO  : metadata sub dir/hello metadata world: Copied (new)
2024/11/26 03:23:49 DEBUG : Google drive root 'crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80': Skipping btime metadata as can't update it on an existing file: 2024-11-26T03:23:45.94637475Z
2024/11/26 03:23:50 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:23:53 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (8.78s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:23:54 DEBUG : Creating backend with remote "/non-existing"
2024/11/26 03:23:54 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2024/11/26 03:23:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:23:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.11s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:23:55 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/26 03:23:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/26 03:23:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:23:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:23:59 DEBUG : sub dir/hello world: md5 = e9a9a1014e3848b4230346b051e534a1 OK
2024/11/26 03:23:59 INFO  : sub dir/hello world: Copied (new)
2024/11/26 03:23:59 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:24:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (7.15s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:24:02 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Running all checks before starting transfers
2024/11/26 03:24:03 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/26 03:24:03 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/26 03:24:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:24:03 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Checks finished, now starting transfers
2024/11/26 03:24:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:24:05 DEBUG : sub dir/hello world: md5 = c31d27b846759f3724df44c384f28445 OK
2024/11/26 03:24:05 INFO  : sub dir/hello world: Copied (new)
2024/11/26 03:24:06 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:24:08 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (6.86s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:24:09 ERROR : Ignoring --no-traverse with sync
2024/11/26 03:24:10 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/26 03:24:10 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/26 03:24:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:24:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:24:12 DEBUG : sub dir/hello world: md5 = 0f2206d1f9d992474beddca6b824ada7 OK
2024/11/26 03:24:12 INFO  : sub dir/hello world: Copied (new)
2024/11/26 03:24:12 DEBUG : Waiting for deletions to finish
2024/11/26 03:24:13 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:24:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (8.15s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:24:18 DEBUG : hello world2: Need to transfer - File not found at Destination
2024/11/26 03:24:18 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/26 03:24:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:24:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:24:19 DEBUG : hello world2: md5 = 14ba1d3993d6b786876e6de8d73c9a2a OK
2024/11/26 03:24:19 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestCopyWithDepth (5.42s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:24:23 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/26 03:24:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:24:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:24:25 DEBUG : potato2: md5 = a80fd4dc1b6a0287dfe9fb7e9c9f32cb OK
2024/11/26 03:24:25 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.77s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:24:27 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/26 03:24:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:24:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:24:29 DEBUG : potato2: md5 = c4e3fe9b5f06971a3cc18abf55a9a2b5 OK
2024/11/26 03:24:29 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.80s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:24:30 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/26 03:24:30 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/26 03:24:30 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/26 03:24:30 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/26 03:24:31 DEBUG : sub dir: Making directory with metadata
2024/11/26 03:24:32 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/26 03:24:32 DEBUG : sub dir2: Making directory with metadata
2024/11/26 03:24:33 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/26 03:24:33 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/26 03:24:33 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/26 03:24:34 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/26 03:24:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:24:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:24:35 DEBUG : sub dir/hello world: md5 = 8269bd22c85ebe3cb0c04c76905d913e OK
2024/11/26 03:24:35 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:24:39 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2024/11/26 03:24:40 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (10.50s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:24:41 DEBUG : sub dir2: Making directory
2024/11/26 03:24:41 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/26 03:24:41 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/26 03:24:41 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/26 03:24:41 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/26 03:24:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/26 03:24:41 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2024/11/26 03:24:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:24:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:24:44 DEBUG : sub dir/hello world: md5 = 27e7b2c034b4043a98a23f748093e480 OK
2024/11/26 03:24:44 INFO  : sub dir/hello world: Copied (new)
2024/11/26 03:24:45 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/26 03:24:47 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (7.20s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:24:48 DEBUG : sub dir2: Making directory with metadata
2024/11/26 03:24:48 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/26 03:24:48 DEBUG : sub dir: Making directory with metadata
2024/11/26 03:24:49 INFO  : sub dir: Made directory with metadata (mtime=2024-11-26T03:24:48.673930415Z)
2024/11/26 03:24:49 DEBUG : sub dir2: Making directory with metadata
2024/11/26 03:24:50 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/26 03:24:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/26 03:24:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:24:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:24:52 DEBUG : sub dir/hello world: md5 = 42f4acc3fc604a9221ab0454ddd850ea OK
2024/11/26 03:24:52 INFO  : sub dir/hello world: Copied (new)
2024/11/26 03:24:52 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:24:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (8.41s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:24:57 DEBUG : sub dir no update dir modtime: Making directory with metadata
2024/11/26 03:24:57 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/26 03:24:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:24:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:24:58 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (4.75s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:25:01 DEBUG : sub dir2: Making directory
2024/11/26 03:25:02 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/26 03:25:02 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/26 03:25:02 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/26 03:25:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:25:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:25:04 DEBUG : sub dir/hello world: md5 = 9433d5ddf849746039703d7118ab925d OK
2024/11/26 03:25:04 INFO  : sub dir/hello world: Copied (new)
2024/11/26 03:25:04 INFO  : sub dir/hello world: Deleted
2024/11/26 03:25:05 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/26 03:25:07 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (6.71s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:25:08 DEBUG : sub dir2: Making directory with metadata
2024/11/26 03:25:08 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/26 03:25:08 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/26 03:25:08 DEBUG : sub dir: Making directory with metadata
2024/11/26 03:25:09 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/26 03:25:09 DEBUG : sub dir2: Making directory with metadata
2024/11/26 03:25:11 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/26 03:25:11 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/26 03:25:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:25:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:25:12 DEBUG : sub dir/hello world: md5 = 147f95322597fef696be97ddf05b53ff OK
2024/11/26 03:25:12 INFO  : sub dir/hello world: Copied (new)
2024/11/26 03:25:12 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:25:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (8.87s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.48s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:25:17 DEBUG : sub dir2: Making directory
2024/11/26 03:25:18 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/26 03:25:18 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/26 03:25:18 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/26 03:25:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:25:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:25:20 DEBUG : sub dir/hello world: md5 = e85d9e26678afbadb06f4ea596006827 OK
2024/11/26 03:25:20 INFO  : sub dir/hello world: Copied (new)
2024/11/26 03:25:20 DEBUG : Waiting for deletions to finish
2024/11/26 03:25:21 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/26 03:25:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (6.85s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:25:27 DEBUG : sub dir/hello world: md5 = deae77c2074a5a5d3dba2def64f1b4bd OK
2024/11/26 03:25:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bahonef6civu"
2024/11/26 03:25:28 DEBUG : Creating backend with remote "TestDrive:crypt/ro69414pi2vq2tvm2qmeqv33n9ihpg31gpkf6acv3a4e7cr0kk40"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya' -> Encrypted drive 'TestCryptDrive:rclone-test-bahonef6civu'
2024/11/26 03:25:29 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/26 03:25:29 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/26 03:25:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bahonef6civu': Waiting for checks to finish
2024/11/26 03:25:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bahonef6civu': Waiting for transfers to finish
2024/11/26 03:25:32 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/26 03:25:33 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:25:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bahonef6civu': Purge remote
2024/11/26 03:25:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (12.41s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:25:40 DEBUG : sub dir/hello world: md5 = 0430edd3e3b32a00ca3149ee4c8acedf OK
2024/11/26 03:25:40 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/26 03:25:41 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/26 03:25:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:25:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:25:42 DEBUG : sub dir/hello world: md5 = 0104c2ac3f04dbc458908c42b59930fa OK
2024/11/26 03:25:42 INFO  : sub dir/hello world: Copied (replaced existing)
2024/11/26 03:25:43 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:25:45 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (9.24s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:25:49 DEBUG : sub dir/hello world: md5 = 3d674669cfb598137057c99f2cd4301f OK
2024/11/26 03:25:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-takijex0gusu"
2024/11/26 03:25:49 DEBUG : Creating backend with remote "TestDrive:crypt/f2kom8mcghg419b6ve644lo1ljfo79faso2jdmdec4qsimtroeb0"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya' -> Encrypted drive 'TestCryptDrive:rclone-test-takijex0gusu'
2024/11/26 03:25:51 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/26 03:25:51 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/26 03:25:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-takijex0gusu': Waiting for checks to finish
2024/11/26 03:25:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-takijex0gusu': Waiting for transfers to finish
2024/11/26 03:25:54 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/26 03:25:55 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:25:57 DEBUG : sub dir/hello world: md5 = 7a442765756ff9e6855b5df740406cf3 OK
2024/11/26 03:25:58 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/26 03:25:58 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/26 03:25:58 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/26 03:25:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-takijex0gusu': Waiting for checks to finish
2024/11/26 03:25:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-takijex0gusu': Waiting for transfers to finish
2024/11/26 03:26:00 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/26 03:26:01 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:26:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-takijex0gusu': Purge remote
2024/11/26 03:26:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (19.07s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:26:08 DEBUG : sub dir/hello world: md5 = 37df843866d26837f60a89061d7bb085 OK
2024/11/26 03:26:08 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/26 03:26:09 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/26 03:26:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:26:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:26:10 DEBUG : sub dir/hello world: md5 = 899e584057eda6dcc7689f0982a109b4 OK
2024/11/26 03:26:10 INFO  : sub dir/hello world: Copied (replaced existing)
2024/11/26 03:26:10 INFO  : sub dir/hello world: Deleted
2024/11/26 03:26:11 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:26:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (8.89s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:26:17 DEBUG : sub dir/hello world: md5 = 68c8e44d3eecf22b69935c5fd9c51fe8 OK
2024/11/26 03:26:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cedejif9xoba"
2024/11/26 03:26:17 DEBUG : Creating backend with remote "TestDrive:crypt/uqvgbak42tddi9sqdgvsdc011g6pvsnelt7g7futl4764nqphakg"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya' -> Encrypted drive 'TestCryptDrive:rclone-test-cedejif9xoba'
2024/11/26 03:26:18 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/26 03:26:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/26 03:26:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cedejif9xoba': Waiting for checks to finish
2024/11/26 03:26:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cedejif9xoba': Waiting for transfers to finish
2024/11/26 03:26:22 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/26 03:26:23 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:26:25 DEBUG : sub dir/hello world: md5 = 3e6f827925ad0bfc3d22077e6bfccc5b OK
2024/11/26 03:26:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cedejif9xoba': Using server-side directory move
2024/11/26 03:26:25 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-cedejif9xoba': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/26 03:26:26 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/26 03:26:26 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/26 03:26:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cedejif9xoba': Waiting for checks to finish
2024/11/26 03:26:26 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/26 03:26:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cedejif9xoba': Waiting for transfers to finish
2024/11/26 03:26:26 INFO  : sub dir/hello world: Deleted
2024/11/26 03:26:27 INFO  : sub dir/hello world: Moved (server-side)
2024/11/26 03:26:28 INFO  : sub dir: Set directory modification time (using SetModTime)
2024/11/26 03:26:31 DEBUG : sub dir/hello world: md5 = 97f3b84e2f4e838672167aa8a1a23612 OK
2024/11/26 03:26:31 DEBUG : testing file moves
2024/11/26 03:26:31 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/26 03:26:31 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/26 03:26:32 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2024/11/26 03:26:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cedejif9xoba': Waiting for checks to finish
2024/11/26 03:26:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cedejif9xoba': Waiting for transfers to finish
2024/11/26 03:26:32 INFO  : sub dir/hello world: Deleted
2024/11/26 03:26:33 INFO  : sub dir/hello world: Moved (server-side)
2024/11/26 03:26:34 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:26:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cedejif9xoba': Purge remote
--- PASS: TestServerSideMoveOverSelf (24.35s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:26:41 DEBUG : sub dir/hello world: md5 = b18ff0245b7e69b27801126cf337504d OK
2024/11/26 03:26:41 ERROR : : error listing: directory not found
2024/11/26 03:26:41 DEBUG : Local file system at /tmp/rclone2855278465: Making directory
2024/11/26 03:26:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:26:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:26:44 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (6.82s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:26:48 DEBUG : sub dir/hello world: md5 = 341ef8664c49d6ca5f9b1e9043659b8f OK
2024/11/26 03:26:48 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/26 03:26:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/26 03:26:49 DEBUG : Local file system at /tmp/rclone2855278465: Waiting for checks to finish
2024/11/26 03:26:49 DEBUG : Local file system at /tmp/rclone2855278465: Waiting for transfers to finish
2024/11/26 03:26:50 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2024/11/26 03:26:50 INFO  : sub dir/hello world: Copied (new)
2024/11/26 03:26:50 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:26:51 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (7.31s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:26:53 DEBUG : check sum: Need to transfer - File not found at Destination
2024/11/26 03:26:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:26:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:26:54 DEBUG : check sum: md5 = 6f7815db66bcd5a6cf0e37a4f09584ac OK
2024/11/26 03:26:54 INFO  : check sum: Copied (new)
2024/11/26 03:26:54 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:26:55 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2024/11/26 03:26:55 DEBUG : check sum: Size of src and dst objects identical
2024/11/26 03:26:55 DEBUG : check sum: Unchanged skipping
2024/11/26 03:26:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:26:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:26:55 DEBUG : Waiting for deletions to finish
2024/11/26 03:26:55 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (4.56s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:26:57 DEBUG : sizeonly: Need to transfer - File not found at Destination
2024/11/26 03:26:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:26:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:26:59 DEBUG : sizeonly: md5 = 34c63da308553cb0b5080a69c087ec68 OK
2024/11/26 03:26:59 INFO  : sizeonly: Copied (new)
2024/11/26 03:26:59 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:26:59 DEBUG : sizeonly: Sizes identical
2024/11/26 03:26:59 DEBUG : sizeonly: Unchanged skipping
2024/11/26 03:26:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:26:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:26:59 DEBUG : Waiting for deletions to finish
2024/11/26 03:26:59 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (5.64s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:27:03 DEBUG : ignore-size: Need to transfer - File not found at Destination
2024/11/26 03:27:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:27:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:27:05 DEBUG : ignore-size: md5 = c58a01128e1ce9ddbecfab0842d154a2 OK
2024/11/26 03:27:05 INFO  : ignore-size: Copied (new)
2024/11/26 03:27:05 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:27:05 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:27:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:27:05 DEBUG : ignore-size: Unchanged skipping
2024/11/26 03:27:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:27:05 DEBUG : Waiting for deletions to finish
2024/11/26 03:27:05 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (5.14s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:27:09 DEBUG : existing: md5 = 2fc05a3dd8b284832ae758d0efef1cc0 OK
2024/11/26 03:27:10 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:27:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:27:10 DEBUG : existing: Unchanged skipping
2024/11/26 03:27:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:27:10 DEBUG : Waiting for deletions to finish
2024/11/26 03:27:10 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:27:10 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2024/11/26 03:27:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:27:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:27:11 DEBUG : existing: md5 = 8c4d42b4226f3f06fc7a1be6227ae374 OK
2024/11/26 03:27:11 INFO  : existing: Copied (replaced existing)
2024/11/26 03:27:11 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (5.99s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:27:14 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/26 03:27:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:27:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:27:16 DEBUG : existing: md5 = 1d5c24d2a253090610c8d711ba03144f OK
2024/11/26 03:27:16 INFO  : existing: Copied (new)
2024/11/26 03:27:16 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:27:16 DEBUG : existing: Destination exists, skipping
2024/11/26 03:27:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:27:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:27:16 DEBUG : Waiting for deletions to finish
2024/11/26 03:27:16 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (4.55s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:27:21 DEBUG : b/potato: md5 = d410ce147cdd9ca8d3c3b6b0c52fcd30 OK
2024/11/26 03:27:24 DEBUG : c/non empty space: md5 = 46664a94f9c540fb50c80309d8ad46ce OK
2024/11/26 03:27:24 DEBUG : d: Making directory
2024/11/26 03:27:26 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/26 03:27:26 DEBUG : Added delayed dir = "c", newDst=c
2024/11/26 03:27:26 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/26 03:27:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:27:26 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:27:26 DEBUG : c/non empty space: Unchanged skipping
2024/11/26 03:27:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:27:28 DEBUG : a/potato2: md5 = b12cfc0148e2ed9d5de0ef0e1825f99d OK
2024/11/26 03:27:28 INFO  : a/potato2: Copied (new)
2024/11/26 03:27:28 DEBUG : Waiting for deletions to finish
2024/11/26 03:27:29 INFO  : b/potato: Deleted
2024/11/26 03:27:30 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/26 03:27:30 INFO  : d: Removing directory
2024/11/26 03:27:30 INFO  : b: Removing directory
2024/11/26 03:27:31 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/26 03:27:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:27:34 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/26 03:27:35 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (17.80s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:27:38 DEBUG : empty space: md5 = 2dc33f37086c4f9f23dc9a5ac56660e5 OK
2024/11/26 03:27:38 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/11/26 03:27:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:27:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:27:38 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2024/11/26 03:27:38 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:27:39 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/11/26 03:27:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:27:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:27:40 DEBUG : empty space: md5 = cea50a4d1843b6eb3a88b829b1961719 OK
2024/11/26 03:27:40 INFO  : empty space: Copied (replaced existing)
2024/11/26 03:27:40 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (6.30s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.45s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:27:45 DEBUG : foo: md5 = a2856489f466190a6adc17e5d6fa238e OK
2024/11/26 03:27:45 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/11/26 03:27:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:27:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:27:47 DEBUG : foo: md5 = fdcc613a50cd19f66708cadb65e894e7 OK
2024/11/26 03:27:47 INFO  : foo: Copied (replaced existing)
2024/11/26 03:27:47 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (5.72s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:27:50 DEBUG : empty space: md5 = 3daedf15e446c9efe617717b80453de2 OK
2024/11/26 03:27:51 DEBUG : potato: Need to transfer - File not found at Destination
2024/11/26 03:27:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:27:51 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:27:51 DEBUG : empty space: Unchanged skipping
2024/11/26 03:27:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:27:52 DEBUG : potato: md5 = 6ab3356b4f6f51cf991041cf80dfb1e3 OK
2024/11/26 03:27:52 INFO  : potato: Copied (new)
2024/11/26 03:27:52 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (6.55s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:27:57 DEBUG : potato: md5 = f90043754ed67d72e068c4ca22e120e7 OK
2024/11/26 03:27:57 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2024/11/26 03:27:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:27:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:27:58 DEBUG : potato: md5 = 76c8f3443ecfdb8081f0b3bd93577f8f OK
2024/11/26 03:27:58 INFO  : potato: Copied (replaced existing)
2024/11/26 03:27:58 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (5.03s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:28:02 DEBUG : potato: md5 = b7cc028efafaf73364586608b72f6e63 OK
2024/11/26 03:28:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:28:02 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/11/26 03:28:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:28:04 DEBUG : potato: md5 = c4abb91e9a34e55694c4bc363c7c1269 OK
2024/11/26 03:28:04 INFO  : potato: Copied (replaced existing)
2024/11/26 03:28:04 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (5.52s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:28:07 DEBUG : potato: md5 = 6361186f750992d80aa6d2f1c9fad124 OK
2024/11/26 03:28:09 DEBUG : empty space: md5 = 949ede52f6f1176dab407d31f80c692b OK
2024/11/26 03:28:09 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/26 03:28:09 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2024/11/26 03:28:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:28:09 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:28:09 DEBUG : empty space: Unchanged skipping
2024/11/26 03:28:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:28:09 DEBUG : Waiting for deletions to finish
2024/11/26 03:28:09 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.88s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:28:13 DEBUG : potato: md5 = 9663a8edf3dd1f425d8b0a434124e57d OK
2024/11/26 03:28:15 DEBUG : empty space: md5 = 519ecf91ecf32689ec3fb9d13e650fc7 OK
2024/11/26 03:28:16 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/26 03:28:16 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:28:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:28:16 DEBUG : empty space: Unchanged skipping
2024/11/26 03:28:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:28:17 DEBUG : potato2: md5 = 9c2659330c932c1a61a11b671e058487 OK
2024/11/26 03:28:17 INFO  : potato2: Copied (new)
2024/11/26 03:28:17 DEBUG : Waiting for deletions to finish
2024/11/26 03:28:18 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.75s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:28:23 DEBUG : b/potato: md5 = 3a05f7a910983f7afb38d230818f8dd2 OK
2024/11/26 03:28:26 DEBUG : c/non empty space: md5 = e345b91faebf20b47a336e44de7f8dd6 OK
2024/11/26 03:28:26 DEBUG : d: Making directory
2024/11/26 03:28:27 DEBUG : d/e: Making directory
2024/11/26 03:28:29 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/26 03:28:29 DEBUG : Added delayed dir = "c", newDst=c
2024/11/26 03:28:29 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/26 03:28:29 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:28:29 DEBUG : c/non empty space: Unchanged skipping
2024/11/26 03:28:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:28:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:28:32 DEBUG : a/potato2: md5 = a2110367bc2a2f570ae4fdb13f632892 OK
2024/11/26 03:28:32 INFO  : a/potato2: Copied (new)
2024/11/26 03:28:32 DEBUG : Waiting for deletions to finish
2024/11/26 03:28:32 INFO  : b/potato: Deleted
2024/11/26 03:28:33 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/26 03:28:33 INFO  : d/e: Removing directory
2024/11/26 03:28:34 INFO  : d: Removing directory
2024/11/26 03:28:34 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2024/11/26 03:28:35 INFO  : b: Removing directory
2024/11/26 03:28:35 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/26 03:28:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:28:38 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/26 03:28:39 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (20.27s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:28:43 DEBUG : b/potato: md5 = fbc962a7c0da25202ced4a0bad9ffbd7 OK
2024/11/26 03:28:46 DEBUG : c/non empty space: md5 = f14a36368431b21f1934bf11638ff7e3 OK
2024/11/26 03:28:46 DEBUG : d: Making directory
2024/11/26 03:28:47 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/26 03:28:47 DEBUG : Added delayed dir = "c", newDst=c
2024/11/26 03:28:47 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/26 03:28:48 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:28:48 DEBUG : c/non empty space: Unchanged skipping
2024/11/26 03:28:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:28:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:28:50 DEBUG : a/potato2: md5 = 2f9adc2944a381f5429e4e0ebcf3f57b OK
2024/11/26 03:28:50 INFO  : a/potato2: Copied (new)
2024/11/26 03:28:50 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': not deleting files as there were IO errors
2024/11/26 03:28:50 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/26 03:28:50 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:28:54 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/26 03:28:55 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/26 03:28:56 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (16.79s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:28:59 DEBUG : potato: md5 = 796616037227596c579786d2176c2a69 OK
2024/11/26 03:29:01 DEBUG : empty space: md5 = 80fe9bd91e78aa49059e3fdd4bdb55b7 OK
2024/11/26 03:29:01 DEBUG : Waiting for deletions to finish
2024/11/26 03:29:01 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/26 03:29:01 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:29:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:29:01 DEBUG : empty space: Unchanged skipping
2024/11/26 03:29:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:29:02 INFO  : potato: Deleted
2024/11/26 03:29:03 DEBUG : potato2: md5 = 27dc5aec00bcac71ccefbf5189a192aa OK
2024/11/26 03:29:03 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (7.68s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:29:07 DEBUG : potato: md5 = ef807562471bde28436ee651dd49db6c OK
2024/11/26 03:29:08 DEBUG : empty space: md5 = 94383963e87501b3bbd97270fb52a428 OK
2024/11/26 03:29:08 DEBUG : Waiting for deletions to finish
2024/11/26 03:29:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:29:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:29:09 INFO  : potato: Deleted
2024/11/26 03:29:10 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/26 03:29:10 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:29:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:29:10 DEBUG : empty space: Unchanged skipping
2024/11/26 03:29:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:29:11 DEBUG : potato2: md5 = e041b050c2c1c30700ee7ab8679a1b6f OK
2024/11/26 03:29:11 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (8.90s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:29:16 DEBUG : potato: md5 = 2b0b056e676a30b79c79d7529f152d7d OK
2024/11/26 03:29:16 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/26 03:29:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:29:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:29:18 DEBUG : potato2: md5 = 6e1b3e760290738adea18e2f8d225022 OK
2024/11/26 03:29:18 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (6.91s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:29:22 DEBUG : potato2: md5 = 5cf63ff448591672ea4891241ab15616 OK
2024/11/26 03:29:24 DEBUG : empty space: md5 = b5fff38ede7c8b77593026cc5d265305 OK
2024/11/26 03:29:24 DEBUG : enormous: Excluded (Size Filter)
2024/11/26 03:29:24 DEBUG : enormous: Excluded
2024/11/26 03:29:24 DEBUG : potato2: Excluded (Size Filter)
2024/11/26 03:29:24 DEBUG : potato2: Excluded
2024/11/26 03:29:25 DEBUG : potato2: Excluded (Size Filter)
2024/11/26 03:29:25 DEBUG : potato2: Excluded
2024/11/26 03:29:25 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:29:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:29:25 DEBUG : empty space: Unchanged skipping
2024/11/26 03:29:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:29:25 DEBUG : Waiting for deletions to finish
2024/11/26 03:29:25 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:29:25 DEBUG : enormous: Excluded (Size Filter)
2024/11/26 03:29:25 DEBUG : enormous: Excluded
2024/11/26 03:29:25 DEBUG : potato2: Excluded (Size Filter)
2024/11/26 03:29:25 DEBUG : potato2: Excluded
2024/11/26 03:29:25 DEBUG : potato2: Excluded (Size Filter)
2024/11/26 03:29:25 DEBUG : potato2: Excluded
2024/11/26 03:29:25 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/11/26 03:29:25 DEBUG : empty space: Unchanged skipping
2024/11/26 03:29:25 DEBUG : Local file system at /tmp/rclone2855278465: Waiting for checks to finish
2024/11/26 03:29:25 DEBUG : Local file system at /tmp/rclone2855278465: Waiting for transfers to finish
2024/11/26 03:29:25 DEBUG : Waiting for deletions to finish
2024/11/26 03:29:25 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncWithExclude (6.81s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:29:29 DEBUG : potato2: md5 = 74c7755123bb34d7c813d829abb4917d OK
2024/11/26 03:29:31 DEBUG : empty space: md5 = 5d2184a2516ffbf11fa40c8644545796 OK
2024/11/26 03:29:33 DEBUG : enormous: md5 = ac259da3909d13b523cea3ae4f25dd84 OK
2024/11/26 03:29:33 DEBUG : enormous: Excluded (Size Filter)
2024/11/26 03:29:33 DEBUG : enormous: Excluded
2024/11/26 03:29:33 DEBUG : potato2: Excluded (Size Filter)
2024/11/26 03:29:33 DEBUG : potato2: Excluded
2024/11/26 03:29:33 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:29:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:29:33 DEBUG : empty space: Unchanged skipping
2024/11/26 03:29:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:29:33 DEBUG : Waiting for deletions to finish
2024/11/26 03:29:34 INFO  : potato2: Deleted
2024/11/26 03:29:34 INFO  : enormous: Deleted
2024/11/26 03:29:34 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:29:34 DEBUG : Local file system at /tmp/rclone2855278465: Waiting for checks to finish
2024/11/26 03:29:34 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/11/26 03:29:34 DEBUG : empty space: Unchanged skipping
2024/11/26 03:29:34 DEBUG : Local file system at /tmp/rclone2855278465: Waiting for transfers to finish
2024/11/26 03:29:34 DEBUG : Waiting for deletions to finish
2024/11/26 03:29:34 INFO  : enormous: Deleted
2024/11/26 03:29:34 INFO  : potato2: Deleted
2024/11/26 03:29:34 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (8.78s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:29:38 DEBUG : one: md5 = 57c7c735ad1419e78d03fefdf5b9ea8e OK
2024/11/26 03:29:40 DEBUG : two: md5 = fe372723558f6ec4c79302bfdf98de51 OK
2024/11/26 03:29:42 DEBUG : three: md5 = a667c90a8b0a192c0dc89245f655a6f1 OK
2024/11/26 03:29:44 DEBUG : four: md5 = 28754ddab248262904922af9b5abcc48 OK
2024/11/26 03:29:44 DEBUG : five: Need to transfer - File not found at Destination
2024/11/26 03:29:44 DEBUG : one: Destination is newer than source, skipping
2024/11/26 03:29:44 DEBUG : three: Sizes identical
2024/11/26 03:29:44 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2024/11/26 03:29:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:29:44 DEBUG : four: Sizes differ (src 4 vs dst 8)
2024/11/26 03:29:44 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2024/11/26 03:29:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:29:45 DEBUG : two: md5 = cf696008bf59bb1dd53a826fc6b8109c OK
2024/11/26 03:29:45 INFO  : two: Copied (replaced existing)
2024/11/26 03:29:45 DEBUG : four: md5 = 353eda8dd684593ea35a4706442c9cc5 OK
2024/11/26 03:29:45 INFO  : four: Copied (replaced existing)
2024/11/26 03:29:46 DEBUG : five: md5 = 1c49184cfe022530fb7575464ff018f8 OK
2024/11/26 03:29:46 INFO  : five: Copied (new)
2024/11/26 03:29:46 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (13.17s)
=== RUN   TestSyncWithMaxDuration
=== RUN   TestSyncWithMaxDuration/Hard
    sync_test.go:1466: Skipping test on non local remote
=== RUN   TestSyncWithMaxDuration/Soft
    sync_test.go:1466: Skipping test on non local remote
--- PASS: TestSyncWithMaxDuration (0.00s)
    --- SKIP: TestSyncWithMaxDuration/Hard (0.00s)
    --- SKIP: TestSyncWithMaxDuration/Soft (0.00s)
=== RUN   TestSyncWithTrackRenames
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2024/11/26 03:29:49 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Ignoring --track-renames as the source and destination do not have a common hash
2024/11/26 03:29:50 DEBUG : potato: Need to transfer - File not found at Destination
2024/11/26 03:29:50 DEBUG : yam: Need to transfer - File not found at Destination
2024/11/26 03:29:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:29:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:29:51 DEBUG : yam: md5 = 0cc674cb2480246fc91001f7dc9bcc40 OK
2024/11/26 03:29:51 INFO  : yam: Copied (new)
2024/11/26 03:29:51 DEBUG : potato: md5 = 56ac3b31ac12ffdcf062d83592b6dd8c OK
2024/11/26 03:29:51 INFO  : potato: Copied (new)
2024/11/26 03:29:51 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:29:52 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Ignoring --track-renames as the source and destination do not have a common hash
2024/11/26 03:29:52 DEBUG : yaml: Need to transfer - File not found at Destination
2024/11/26 03:29:52 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:29:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:29:52 DEBUG : potato: Unchanged skipping
2024/11/26 03:29:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:29:54 DEBUG : yaml: md5 = fe8a92161a6e1f944744b6c619457c03 OK
2024/11/26 03:29:54 INFO  : yaml: Copied (new)
2024/11/26 03:29:54 DEBUG : Waiting for deletions to finish
2024/11/26 03:29:54 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (7.83s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2024/11/26 03:29:58 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Making map for --track-renames
2024/11/26 03:29:58 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Finished making map for --track-renames
2024/11/26 03:29:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:29:58 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/11/26 03:29:58 DEBUG : yam: Need to transfer - No matching file found at Destination
2024/11/26 03:29:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for renames to finish
2024/11/26 03:29:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:29:59 DEBUG : yam: md5 = 1b3c0ac187a7e0a7badc6b36def170ed OK
2024/11/26 03:29:59 INFO  : yam: Copied (new)
2024/11/26 03:29:59 DEBUG : potato: md5 = afaf3f8050a348d9a99953050db3a116 OK
2024/11/26 03:29:59 INFO  : potato: Copied (new)
2024/11/26 03:29:59 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:30:00 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:30:00 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Making map for --track-renames
2024/11/26 03:30:00 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Finished making map for --track-renames
2024/11/26 03:30:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:30:00 DEBUG : potato: Unchanged skipping
2024/11/26 03:30:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for renames to finish
2024/11/26 03:30:01 INFO  : yam: Moved (server-side) to: yaml
2024/11/26 03:30:01 INFO  : yaml: Renamed from "yam"
2024/11/26 03:30:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:30:01 DEBUG : Waiting for deletions to finish
2024/11/26 03:30:01 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (6.25s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2024/11/26 03:30:04 DEBUG : Added delayed dir = "sub", newDst=<nil>
2024/11/26 03:30:04 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Making map for --track-renames
2024/11/26 03:30:04 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Finished making map for --track-renames
2024/11/26 03:30:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:30:04 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/11/26 03:30:04 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2024/11/26 03:30:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for renames to finish
2024/11/26 03:30:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:30:06 DEBUG : potato: md5 = 79852ca42324cfe62a002d5c6e7f5ee9 OK
2024/11/26 03:30:06 INFO  : potato: Copied (new)
2024/11/26 03:30:07 DEBUG : sub/yam: md5 = b97d9f596e124beb20184bc0a95ffbe9 OK
2024/11/26 03:30:07 INFO  : sub/yam: Copied (new)
2024/11/26 03:30:07 DEBUG : Waiting for deletions to finish
2024/11/26 03:30:07 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:30:08 DEBUG : Added delayed dir = "sub", newDst=sub
2024/11/26 03:30:08 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:30:08 DEBUG : potato: Unchanged skipping
2024/11/26 03:30:08 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Making map for --track-renames
2024/11/26 03:30:08 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Finished making map for --track-renames
2024/11/26 03:30:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:30:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for renames to finish
2024/11/26 03:30:10 INFO  : sub/yam: Moved (server-side) to: yam
2024/11/26 03:30:10 INFO  : yam: Renamed from "sub/yam"
2024/11/26 03:30:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:30:10 DEBUG : Waiting for deletions to finish
2024/11/26 03:30:10 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (10.17s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:30:14 DEBUG : Creating backend with remote "/tmp/rclone2855278465/dir1"
2024/11/26 03:30:14 DEBUG : Config file has changed externally - reloading
2024/11/26 03:30:14 DEBUG : Creating backend with remote "/tmp/rclone2855278465/dir2"
2024/11/26 03:30:14 DEBUG : Local file system at /tmp/rclone2855278465/dir2: Using server-side directory move
2024/11/26 03:30:14 INFO  : Local file system at /tmp/rclone2855278465/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/26 03:30:14 DEBUG : file1.txt: Need to transfer - File not found at Destination
2024/11/26 03:30:14 INFO  : file1.txt: Moved (server-side)
2024/11/26 03:30:14 DEBUG : Local file system at /tmp/rclone2855278465/dir2: Waiting for checks to finish
2024/11/26 03:30:14 DEBUG : Local file system at /tmp/rclone2855278465/dir2: Waiting for transfers to finish
--- PASS: TestServerSideMoveLocal (0.43s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:30:14 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/11/26 03:30:14 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/26 03:30:14 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/26 03:30:14 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/11/26 03:30:14 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/11/26 03:30:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:30:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:30:17 DEBUG : sub dir/hello world: md5 = e11876c90fc5510422289d850304e909 OK
2024/11/26 03:30:17 INFO  : sub dir/hello world: Copied (new)
2024/11/26 03:30:17 INFO  : sub dir/hello world: Deleted
2024/11/26 03:30:20 DEBUG : nested/sub dir/file: md5 = a2bb56074bd53b01f25123964747bfb2 OK
2024/11/26 03:30:20 INFO  : nested/sub dir/file: Copied (new)
2024/11/26 03:30:20 INFO  : nested/sub dir/file: Deleted
2024/11/26 03:30:20 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/11/26 03:30:21 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/26 03:30:21 INFO  : nested: Set directory modification time (using DirSetModTime)
2024/11/26 03:30:21 INFO  : sub dir: Removing directory
2024/11/26 03:30:21 INFO  : nested/sub dir: Removing directory
2024/11/26 03:30:21 INFO  : nested: Removing directory
2024/11/26 03:30:21 DEBUG : Local file system at /tmp/rclone2855278465: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:30:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/26 03:30:25 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/11/26 03:30:25 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (12.71s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:30:27 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/11/26 03:30:27 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/26 03:30:27 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/26 03:30:27 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/11/26 03:30:27 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/11/26 03:30:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:30:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:30:30 DEBUG : sub dir/hello world: md5 = 5dea95bfef3f07bff9a152f3efeef88c OK
2024/11/26 03:30:30 INFO  : sub dir/hello world: Copied (new)
2024/11/26 03:30:30 INFO  : sub dir/hello world: Deleted
2024/11/26 03:30:32 DEBUG : nested/sub dir/file: md5 = 2f033a49c26f6091765533c3341f9d00 OK
2024/11/26 03:30:32 INFO  : nested/sub dir/file: Copied (new)
2024/11/26 03:30:32 INFO  : nested/sub dir/file: Deleted
2024/11/26 03:30:33 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/11/26 03:30:33 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/26 03:30:33 INFO  : nested: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:30:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/26 03:30:37 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/11/26 03:30:38 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (12.69s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:30:40 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/26 03:30:40 DEBUG : existing-b: Need to transfer - File not found at Destination
2024/11/26 03:30:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:30:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:30:41 DEBUG : existing-b: md5 = 195149d80397eb3114187314a9458582 OK
2024/11/26 03:30:41 INFO  : existing-b: Copied (new)
2024/11/26 03:30:41 INFO  : existing-b: Deleted
2024/11/26 03:30:41 DEBUG : existing: md5 = c827455ddda398c1774f1cd201bb0b57 OK
2024/11/26 03:30:41 INFO  : existing: Copied (new)
2024/11/26 03:30:41 INFO  : existing: Deleted
2024/11/26 03:30:42 DEBUG : existing: Destination exists, skipping
2024/11/26 03:30:42 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2024/11/26 03:30:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:30:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:30:42 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (4.64s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:30:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vaniruj9kaka"
2024/11/26 03:30:44 DEBUG : Config file has changed externally - reloading
2024/11/26 03:30:44 DEBUG : Creating backend with remote "TestDrive:crypt/4otm7v9orhk2dibeeeh1s70lrktqhe9poe0r8bfuqvfdnq38n660"
2024/11/26 03:30:47 DEBUG : potato2: md5 = a90f0b04ba8b803bbc56468906bd72b4 OK
2024/11/26 03:30:49 DEBUG : empty space: md5 = 4cc68243aedd9ccbea467fd09b08282f OK
2024/11/26 03:30:50 DEBUG : potato3: md5 = d1549bf57b89440c2d857df0b3bb0749 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya' -> Encrypted drive 'TestCryptDrive:rclone-test-vaniruj9kaka'
2024/11/26 03:30:53 DEBUG : empty space: md5 = 49a979184e618e77a1fc830f3155753a OK
2024/11/26 03:30:55 DEBUG : potato3: md5 = 903fcb87bf72676708f97b4a9c8b06e1 OK
2024/11/26 03:30:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vaniruj9kaka': Using server-side directory move
2024/11/26 03:30:55 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-vaniruj9kaka': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/26 03:30:56 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/26 03:30:56 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/11/26 03:30:56 DEBUG : empty space: Unchanged skipping
2024/11/26 03:30:56 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/26 03:30:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vaniruj9kaka': Waiting for checks to finish
2024/11/26 03:30:56 INFO  : empty space: Deleted
2024/11/26 03:30:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vaniruj9kaka': Waiting for transfers to finish
2024/11/26 03:30:56 INFO  : potato3: Deleted
2024/11/26 03:30:57 INFO  : potato2: Moved (server-side)
2024/11/26 03:30:57 INFO  : potato3: Moved (server-side)
2024/11/26 03:30:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuxiqih0yate"
2024/11/26 03:30:58 DEBUG : Creating backend with remote "TestDrive:crypt/9f45i37b6ufrn0nnk3ilgb3iiobhi0cvrgagfqhn7qrr6oheocug"
2024/11/26 03:30:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuxiqih0yate': Using server-side directory move
2024/11/26 03:30:59 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-wuxiqih0yate': Server side directory move succeeded
2024/11/26 03:31:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuxiqih0yate': Purge remote
2024/11/26 03:31:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vaniruj9kaka': Purge remote
2024/11/26 03:31:01 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (17.59s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:31:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gopayiv8gere"
2024/11/26 03:31:02 DEBUG : Creating backend with remote "TestDrive:crypt/6tumvajr8oq5jurbmgc277k7pnm0ngtes1286q1bun4em01ri460"
2024/11/26 03:31:05 DEBUG : potato2: md5 = fd5027f08f2267ff3f597b61e02d9f4c OK
2024/11/26 03:31:06 DEBUG : empty space: md5 = f1b401c4f170e9a5832b5d0c95ae5309 OK
2024/11/26 03:31:08 DEBUG : potato3: md5 = 885215b2378f95a45bbebd2990c0c1a0 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya' -> Encrypted drive 'TestCryptDrive:rclone-test-gopayiv8gere'
2024/11/26 03:31:11 DEBUG : empty space: md5 = 6e3aec6a420e3ebc5513d309d23d42cc OK
2024/11/26 03:31:13 DEBUG : potato3: md5 = c7e6a8ff94c193c4dd91af7efe3cd32b OK
2024/11/26 03:31:13 DEBUG : empty space: Excluded (Size Filter)
2024/11/26 03:31:13 DEBUG : empty space: Excluded
2024/11/26 03:31:13 DEBUG : empty space: Excluded (Size Filter)
2024/11/26 03:31:13 DEBUG : empty space: Excluded
2024/11/26 03:31:13 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/26 03:31:13 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/26 03:31:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gopayiv8gere': Waiting for checks to finish
2024/11/26 03:31:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gopayiv8gere': Waiting for transfers to finish
2024/11/26 03:31:14 INFO  : potato3: Deleted
2024/11/26 03:31:14 INFO  : potato2: Moved (server-side)
2024/11/26 03:31:15 INFO  : potato3: Moved (server-side)
2024/11/26 03:31:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zujawih9niru"
2024/11/26 03:31:15 DEBUG : Creating backend with remote "TestDrive:crypt/a2m09k6euaoaq911a8lj6lnc85pcmujpjjhgq4j4cqvfu5kd8310"
2024/11/26 03:31:16 DEBUG : empty space: Excluded (Size Filter)
2024/11/26 03:31:16 DEBUG : empty space: Excluded
2024/11/26 03:31:16 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/26 03:31:16 DEBUG : potato3: Need to transfer - File not found at Destination
2024/11/26 03:31:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zujawih9niru': Waiting for checks to finish
2024/11/26 03:31:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zujawih9niru': Waiting for transfers to finish
2024/11/26 03:31:18 INFO  : potato3: Moved (server-side)
2024/11/26 03:31:19 INFO  : potato2: Moved (server-side)
2024/11/26 03:31:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zujawih9niru': Purge remote
2024/11/26 03:31:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gopayiv8gere': Purge remote
--- PASS: TestServerSideMoveWithFilter (19.78s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:31:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qedidev8laqa"
2024/11/26 03:31:22 DEBUG : Creating backend with remote "TestDrive:crypt/2t8468k2ckv3l8omoncdo5va6kt4jant51jbbb6b9fdo32urskd0"
2024/11/26 03:31:24 DEBUG : potato2: md5 = a9a16bd511208a3a9288e67d30234ecf OK
2024/11/26 03:31:26 DEBUG : empty space: md5 = 343ddc87d5f270c091ccca90f9731615 OK
2024/11/26 03:31:28 DEBUG : potato3: md5 = fdeaada7d233c48c0c893d3b0ff4397a OK
2024/11/26 03:31:28 DEBUG : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya' -> Encrypted drive 'TestCryptDrive:rclone-test-qedidev8laqa'
2024/11/26 03:31:32 DEBUG : empty space: md5 = 0dd5cc86ec07842072b2c25085a05d19 OK
2024/11/26 03:31:34 DEBUG : potato3: md5 = 6d6cc825bc44918751b634da3cc8725c OK
2024/11/26 03:31:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qedidev8laqa': Using server-side directory move
2024/11/26 03:31:34 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-qedidev8laqa': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/26 03:31:34 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/26 03:31:34 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2024/11/26 03:31:34 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/11/26 03:31:34 DEBUG : empty space: Unchanged skipping
2024/11/26 03:31:34 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/26 03:31:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qedidev8laqa': Waiting for checks to finish
2024/11/26 03:31:35 INFO  : empty space: Deleted
2024/11/26 03:31:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qedidev8laqa': Waiting for transfers to finish
2024/11/26 03:31:35 INFO  : potato3: Deleted
2024/11/26 03:31:36 INFO  : potato2: Moved (server-side)
2024/11/26 03:31:36 INFO  : potato3: Moved (server-side)
2024/11/26 03:31:36 INFO  : tomatoDir: Removing directory
2024/11/26 03:31:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': deleted 1 directories
2024/11/26 03:31:38 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vulixem6lape"
2024/11/26 03:31:38 DEBUG : Creating backend with remote "TestDrive:crypt/7mf9og42gicmttl68i859qqjclvaodauuqsafktdi8s0n8ruehsg"
2024/11/26 03:31:39 DEBUG : tomatoDir: Making directory
2024/11/26 03:31:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vulixem6lape': Using server-side directory move
2024/11/26 03:31:41 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-vulixem6lape': Server side directory move succeeded
2024/11/26 03:31:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vulixem6lape': Purge remote
2024/11/26 03:31:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qedidev8laqa': Purge remote
2024/11/26 03:31:43 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (22.25s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.43s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:31:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/rclone-sync-test"
2024/11/26 03:31:44 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncOverlap (3.79s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:31:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/rclone-sync-test"
2024/11/26 03:31:48 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2024/11/26 03:31:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/rclone-sync-test-include/layer2"
2024/11/26 03:31:51 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2024/11/26 03:31:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/rclone-sync-test-ignore-file"
2024/11/26 03:31:54 DEBUG : Config file has changed externally - reloading
2024/11/26 03:31:54 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2024/11/26 03:31:58 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = e8c8805ae21f5fee8733089bce2306b3 OK
2024/11/26 03:31:59 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/26 03:32:00 DEBUG : rclone-sync-test: Excluded
2024/11/26 03:32:00 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/26 03:32:00 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/26 03:32:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/rclone-sync-test': Waiting for checks to finish
2024/11/26 03:32:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/rclone-sync-test': Waiting for transfers to finish
2024/11/26 03:32:00 DEBUG : Waiting for deletions to finish
2024/11/26 03:32:00 INFO  : There was nothing to transfer
2024/11/26 03:32:01 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/26 03:32:02 DEBUG : rclone-sync-test: Excluded
2024/11/26 03:32:02 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/26 03:32:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:32:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:32:02 DEBUG : Waiting for deletions to finish
2024/11/26 03:32:02 INFO  : rclone-sync-test-include: Removing directory
2024/11/26 03:32:02 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/26 03:32:02 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/11/26 03:32:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': failed to delete 1 directories
2024/11/26 03:32:02 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:32:03 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/26 03:32:04 DEBUG : rclone-sync-test: Excluded
2024/11/26 03:32:04 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/26 03:32:04 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/26 03:32:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/rclone-sync-test-include/layer2': Waiting for checks to finish
2024/11/26 03:32:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/rclone-sync-test-include/layer2': Waiting for transfers to finish
2024/11/26 03:32:04 DEBUG : Waiting for deletions to finish
2024/11/26 03:32:04 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:32:05 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/26 03:32:05 DEBUG : rclone-sync-test: Excluded
2024/11/26 03:32:06 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/26 03:32:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:32:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:32:06 DEBUG : Waiting for deletions to finish
2024/11/26 03:32:06 INFO  : rclone-sync-test-include: Removing directory
2024/11/26 03:32:06 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/26 03:32:06 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/11/26 03:32:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': failed to delete 1 directories
2024/11/26 03:32:06 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:32:06 DEBUG : : Excluded
2024/11/26 03:32:07 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/26 03:32:07 DEBUG : rclone-sync-test: Excluded
2024/11/26 03:32:07 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/26 03:32:08 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/26 03:32:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/rclone-sync-test-ignore-file': Waiting for checks to finish
2024/11/26 03:32:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/rclone-sync-test-ignore-file': Waiting for transfers to finish
2024/11/26 03:32:08 DEBUG : Waiting for deletions to finish
2024/11/26 03:32:08 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:32:10 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/26 03:32:11 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (32.62s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:32:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/dst"
2024/11/26 03:32:21 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/26 03:32:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/CompareDest"
2024/11/26 03:32:22 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/gveqi14airsml4bgu7krj116o8"
2024/11/26 03:32:24 DEBUG : one: Need to transfer - File not found at Destination
2024/11/26 03:32:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:32:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:32:27 DEBUG : one: md5 = f8ef1c3ee740dce015ff559f7bd1fa65 OK
2024/11/26 03:32:27 INFO  : one: Copied (new)
2024/11/26 03:32:27 DEBUG : Waiting for deletions to finish
2024/11/26 03:32:28 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/26 03:32:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:32:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:32:30 DEBUG : one: md5 = 0b1184b262be721b53221c75947266e8 OK
2024/11/26 03:32:30 INFO  : one: Copied (replaced existing)
2024/11/26 03:32:30 DEBUG : Waiting for deletions to finish
2024/11/26 03:32:33 DEBUG : dst/one: md5 = a532d6141b7b071f9ce43c17a8cff540 OK
2024/11/26 03:32:36 DEBUG : CompareDest/one: md5 = dd3a3657dc0b9b48d37f7e0e28eaea89 OK
2024/11/26 03:32:37 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/26 03:32:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:32:37 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:32:37 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/26 03:32:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:32:37 DEBUG : Waiting for deletions to finish
2024/11/26 03:32:37 INFO  : There was nothing to transfer
2024/11/26 03:32:40 DEBUG : CompareDest/two: md5 = d8a04ddd7a395e2f17df9f84ae27548b OK
2024/11/26 03:32:41 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:32:41 DEBUG : two: Destination found in --compare-dest, skipping
2024/11/26 03:32:41 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/26 03:32:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:32:41 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:32:41 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/26 03:32:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:32:41 DEBUG : Waiting for deletions to finish
2024/11/26 03:32:41 INFO  : There was nothing to transfer
2024/11/26 03:32:42 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:32:42 DEBUG : two: Destination found in --compare-dest, skipping
2024/11/26 03:32:42 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/26 03:32:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:32:42 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:32:42 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/26 03:32:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:32:42 DEBUG : Waiting for deletions to finish
2024/11/26 03:32:42 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2024/11/26 03:32:44 DEBUG : two: Sizes differ (src 5 vs dst 3)
2024/11/26 03:32:44 DEBUG : two: Need to transfer - File not found at Destination
2024/11/26 03:32:44 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/26 03:32:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:32:44 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:32:44 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/26 03:32:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:32:45 DEBUG : two: md5 = 9cd1dd0c2a66504a64db27e01379416d OK
2024/11/26 03:32:45 INFO  : two: Copied (new)
2024/11/26 03:32:45 DEBUG : Waiting for deletions to finish
2024/11/26 03:32:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/26 03:32:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/26 03:32:50 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/26 03:32:50 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncCompareDest (30.46s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:32:54 DEBUG : pre-dest1/1: md5 = e97ebe3c426eb1b67b80f1f4f999db1a OK
2024/11/26 03:32:56 DEBUG : pre-dest2/2: md5 = ce052b696d85832d96c06f24fd085da2 OK
2024/11/26 03:32:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/dest"
2024/11/26 03:32:57 DEBUG : Config file has changed externally - reloading
2024/11/26 03:32:57 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/rg03c1jvnehrrc617i0lnqjddc"
2024/11/26 03:32:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/pre-dest1"
2024/11/26 03:32:58 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/bbnblvh6k061ssopqrp18kd7gc"
2024/11/26 03:32:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/pre-dest2"
2024/11/26 03:32:59 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/dgicm1h6b5ejvlltm8eeif0bnk"
2024/11/26 03:33:01 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:33:01 DEBUG : 1: Destination found in --compare-dest, skipping
2024/11/26 03:33:01 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:33:01 DEBUG : 2: Destination found in --compare-dest, skipping
2024/11/26 03:33:01 DEBUG : 3: Need to transfer - File not found at Destination
2024/11/26 03:33:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dest': Waiting for checks to finish
2024/11/26 03:33:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dest': Waiting for transfers to finish
2024/11/26 03:33:04 DEBUG : 3: md5 = c7d3475395c5d8ffbb84294b2edfac81 OK
2024/11/26 03:33:04 INFO  : 3: Copied (new)
2024/11/26 03:33:04 DEBUG : Waiting for deletions to finish
2024/11/26 03:33:08 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2024/11/26 03:33:08 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2024/11/26 03:33:09 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (18.94s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:33:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/dst"
2024/11/26 03:33:10 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/26 03:33:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/CopyDest"
2024/11/26 03:33:12 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/d09o6po3f7bm6ce32vdgs8h9ls"
2024/11/26 03:33:14 DEBUG : one: Need to transfer - File not found at Destination
2024/11/26 03:33:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:33:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:33:16 DEBUG : one: md5 = 228569d22b166966bba80eb710ad2594 OK
2024/11/26 03:33:16 INFO  : one: Copied (new)
2024/11/26 03:33:16 DEBUG : Waiting for deletions to finish
2024/11/26 03:33:17 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/26 03:33:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:33:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:33:19 DEBUG : one: md5 = 4c8538fdeb7681f68f520e0f32b7b9c9 OK
2024/11/26 03:33:19 INFO  : one: Copied (replaced existing)
2024/11/26 03:33:19 DEBUG : Waiting for deletions to finish
2024/11/26 03:33:21 DEBUG : dst/one: md5 = fc4f08cb8e7a2ff4a4eb9700ddeb200a OK
2024/11/26 03:33:24 DEBUG : CopyDest/one: md5 = 983d979b5f1574e92df72564513d83c9 OK
2024/11/26 03:33:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/BackupDir"
2024/11/26 03:33:24 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/s6dbk3lfi7c9kfvo6j7bla9m0g"
2024/11/26 03:33:26 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/26 03:33:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:33:26 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:33:26 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/26 03:33:29 INFO  : one: Moved (server-side)
2024/11/26 03:33:30 INFO  : one: Copied (server-side copy)
2024/11/26 03:33:30 DEBUG : one: Destination found in --copy-dest, using server-side copy
2024/11/26 03:33:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:33:30 DEBUG : Waiting for deletions to finish
2024/11/26 03:33:32 DEBUG : CopyDest/two: md5 = 94efd7b8b5e9199c08f3142711da28b3 OK
2024/11/26 03:33:33 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:33:35 INFO  : two: Copied (server-side copy)
2024/11/26 03:33:35 DEBUG : two: Destination found in --copy-dest, using server-side copy
2024/11/26 03:33:35 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:33:35 DEBUG : one: Unchanged skipping
2024/11/26 03:33:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:33:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:33:35 DEBUG : Waiting for deletions to finish
2024/11/26 03:33:35 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:33:35 DEBUG : one: Unchanged skipping
2024/11/26 03:33:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:33:35 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:33:35 DEBUG : two: Unchanged skipping
2024/11/26 03:33:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:33:35 DEBUG : Waiting for deletions to finish
2024/11/26 03:33:35 INFO  : There was nothing to transfer
2024/11/26 03:33:38 DEBUG : CopyDest/three: md5 = 9c9e78e7abd94f6e580052985de40b16 OK
2024/11/26 03:33:39 DEBUG : three: Sizes differ (src 7 vs dst 5)
2024/11/26 03:33:39 DEBUG : three: Destination not found in --copy-dest
2024/11/26 03:33:39 DEBUG : three: Need to transfer - File not found at Destination
2024/11/26 03:33:39 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:33:39 DEBUG : one: Unchanged skipping
2024/11/26 03:33:39 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/26 03:33:39 DEBUG : two: Unchanged skipping
2024/11/26 03:33:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:33:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:33:40 DEBUG : three: md5 = dac349582232ad2719e0173f568d7368 OK
2024/11/26 03:33:40 INFO  : three: Copied (new)
2024/11/26 03:33:40 DEBUG : Waiting for deletions to finish
2024/11/26 03:33:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/11/26 03:33:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/26 03:33:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/26 03:33:47 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/26 03:33:47 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/11/26 03:33:47 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/26 03:33:48 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (38.32s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:33:52 DEBUG : dst/one: md5 = 4f7c86449cfeff531a081f75ee8baefa OK
2024/11/26 03:33:54 DEBUG : dst/two: md5 = 39c2e0b51c965ac660a215b60b4551cd OK
2024/11/26 03:33:55 DEBUG : dst/three.txt: md5 = d8acff0fe69a29871d077b2e65dbda74 OK
2024/11/26 03:33:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/dst"
2024/11/26 03:33:56 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/26 03:33:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/backup"
2024/11/26 03:33:57 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/1nrff024r7pq65ecp72fc28jb0"
2024/11/26 03:33:59 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/26 03:33:59 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:33:59 DEBUG : two: Unchanged skipping
2024/11/26 03:33:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:34:01 INFO  : one: Moved (server-side)
2024/11/26 03:34:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:34:02 DEBUG : one: md5 = 99148f5fc710683090aa9f0b7694a654 OK
2024/11/26 03:34:02 INFO  : one: Copied (new)
2024/11/26 03:34:02 DEBUG : Waiting for deletions to finish
2024/11/26 03:34:04 INFO  : three.txt: Moved (server-side)
2024/11/26 03:34:04 INFO  : three.txt: Moved into backup dir
2024/11/26 03:34:06 DEBUG : dst/three.txt: md5 = 6cb3f644954161476e50dd43ee589ba3 OK
2024/11/26 03:34:07 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/26 03:34:07 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:34:07 DEBUG : two: Unchanged skipping
2024/11/26 03:34:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:34:08 INFO  : one: Deleted
2024/11/26 03:34:09 INFO  : one: Moved (server-side)
2024/11/26 03:34:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:34:10 DEBUG : one: md5 = f11e99a5b2a6da6646b055f1b27fac5f OK
2024/11/26 03:34:10 INFO  : one: Copied (new)
2024/11/26 03:34:10 DEBUG : Waiting for deletions to finish
2024/11/26 03:34:11 INFO  : three.txt: Deleted
2024/11/26 03:34:12 INFO  : three.txt: Moved (server-side)
2024/11/26 03:34:12 INFO  : three.txt: Moved into backup dir
2024/11/26 03:34:16 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/26 03:34:16 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/26 03:34:16 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/26 03:34:16 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/26 03:34:16 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/26 03:34:16 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
--- PASS: TestSyncBackupDir (28.91s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:34:20 DEBUG : dst/one: md5 = 61dff1b0a993549b83fe79187c5f27ca OK
2024/11/26 03:34:22 DEBUG : dst/two: md5 = fc5bb22784499c219e2a7b281feabad3 OK
2024/11/26 03:34:23 DEBUG : dst/three.txt: md5 = 5e6e0922c1c421660841597a916c4d84 OK
2024/11/26 03:34:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/dst"
2024/11/26 03:34:24 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/26 03:34:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/backup"
2024/11/26 03:34:25 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/1nrff024r7pq65ecp72fc28jb0"
2024/11/26 03:34:27 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/26 03:34:27 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:34:27 DEBUG : two: Unchanged skipping
2024/11/26 03:34:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:34:29 INFO  : one: Moved (server-side) to: one.bak
2024/11/26 03:34:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:34:31 DEBUG : one: md5 = 31c18306e6d5ac23e8dc39c2c2809765 OK
2024/11/26 03:34:31 INFO  : one: Copied (new)
2024/11/26 03:34:31 DEBUG : Waiting for deletions to finish
2024/11/26 03:34:32 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/26 03:34:32 INFO  : three.txt: Moved into backup dir
2024/11/26 03:34:34 DEBUG : dst/three.txt: md5 = b7ce25c810a9920cffc496bae9d675f8 OK
2024/11/26 03:34:35 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/26 03:34:35 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:34:35 DEBUG : two: Unchanged skipping
2024/11/26 03:34:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:34:35 INFO  : one.bak: Deleted
2024/11/26 03:34:36 INFO  : one: Moved (server-side) to: one.bak
2024/11/26 03:34:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:34:38 DEBUG : one: md5 = 5069c0c6ff687c79afba75f6b01cebeb OK
2024/11/26 03:34:38 INFO  : one: Copied (new)
2024/11/26 03:34:38 DEBUG : Waiting for deletions to finish
2024/11/26 03:34:39 INFO  : three.txt.bak: Deleted
2024/11/26 03:34:40 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/26 03:34:40 INFO  : three.txt: Moved into backup dir
2024/11/26 03:34:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/26 03:34:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/26 03:34:44 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/26 03:34:44 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/26 03:34:44 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/26 03:34:44 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirWithSuffix (28.16s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:34:48 DEBUG : dst/one: md5 = 8f385e1eb8b783094babfc17b766e4d3 OK
2024/11/26 03:34:50 DEBUG : dst/two: md5 = f3a9cbee3d118edd8fbfe28b116933f2 OK
2024/11/26 03:34:51 DEBUG : dst/three.txt: md5 = 022c5aef62f3ddba23e582f78f78954e OK
2024/11/26 03:34:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/dst"
2024/11/26 03:34:52 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/26 03:34:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/backup"
2024/11/26 03:34:53 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/1nrff024r7pq65ecp72fc28jb0"
2024/11/26 03:34:55 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/26 03:34:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:34:55 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:34:55 DEBUG : two: Unchanged skipping
2024/11/26 03:34:57 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/26 03:34:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:34:59 DEBUG : one: md5 = 63c634723062fe21117b493e5625edcd OK
2024/11/26 03:34:59 INFO  : one: Copied (new)
2024/11/26 03:34:59 DEBUG : Waiting for deletions to finish
2024/11/26 03:35:00 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/26 03:35:00 INFO  : three.txt: Moved into backup dir
2024/11/26 03:35:02 DEBUG : dst/three.txt: md5 = fc6b3aefc7410095d5f1dbd4cdf5b4eb OK
2024/11/26 03:35:03 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/26 03:35:03 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:35:03 DEBUG : two: Unchanged skipping
2024/11/26 03:35:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:35:04 INFO  : one-2019-01-01: Deleted
2024/11/26 03:35:05 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/26 03:35:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:35:07 DEBUG : one: md5 = d08fc2e3a2faebff58950b420220c255 OK
2024/11/26 03:35:07 INFO  : one: Copied (new)
2024/11/26 03:35:07 DEBUG : Waiting for deletions to finish
2024/11/26 03:35:08 INFO  : three-2019-01-01.txt: Deleted
2024/11/26 03:35:09 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/26 03:35:09 INFO  : three.txt: Moved into backup dir
2024/11/26 03:35:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/26 03:35:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/26 03:35:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/26 03:35:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/26 03:35:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/26 03:35:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (29.32s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:35:18 DEBUG : dst/one: md5 = 666363e49ab0fdcde47a7f4e7d03490e OK
2024/11/26 03:35:19 DEBUG : dst/two: md5 = 3c9ebab2adf16dae66ed3cab0b2e5693 OK
2024/11/26 03:35:21 DEBUG : dst/three.txt: md5 = 2267a036459a68af41421051157b044e OK
2024/11/26 03:35:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/dst"
2024/11/26 03:35:21 DEBUG : Config file has changed externally - reloading
2024/11/26 03:35:21 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/26 03:35:22 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/26 03:35:22 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:35:22 DEBUG : two: Unchanged skipping
2024/11/26 03:35:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:35:23 INFO  : one: Moved (server-side) to: one.bak
2024/11/26 03:35:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:35:25 DEBUG : one: md5 = d432c62d58df36d6719d385bdaad5123 OK
2024/11/26 03:35:25 INFO  : one: Copied (new)
2024/11/26 03:35:25 DEBUG : Waiting for deletions to finish
2024/11/26 03:35:26 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/26 03:35:26 INFO  : three.txt: Moved into backup dir
2024/11/26 03:35:28 DEBUG : dst/three.txt: md5 = 6a954011cb696021722889eca8325fce OK
2024/11/26 03:35:29 DEBUG : one.bak: Excluded (Path Filter)
2024/11/26 03:35:29 DEBUG : one.bak: Excluded
2024/11/26 03:35:29 DEBUG : three.txt.bak: Excluded (Path Filter)
2024/11/26 03:35:29 DEBUG : three.txt.bak: Excluded
2024/11/26 03:35:29 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/26 03:35:29 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:35:29 DEBUG : two: Unchanged skipping
2024/11/26 03:35:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for checks to finish
2024/11/26 03:35:29 INFO  : one.bak: Deleted
2024/11/26 03:35:30 INFO  : one: Moved (server-side) to: one.bak
2024/11/26 03:35:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya/dst': Waiting for transfers to finish
2024/11/26 03:35:32 DEBUG : one: md5 = 6edcf1194ccb78c4c21fcffe6413a3fa OK
2024/11/26 03:35:32 INFO  : one: Copied (new)
2024/11/26 03:35:32 DEBUG : Waiting for deletions to finish
2024/11/26 03:35:33 INFO  : three.txt.bak: Deleted
2024/11/26 03:35:33 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/26 03:35:33 INFO  : three.txt: Moved into backup dir
2024/11/26 03:35:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/26 03:35:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/26 03:35:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/26 03:35:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/26 03:35:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/26 03:35:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirSuffixOnly (22.98s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:35:41 DEBUG : dst/one: md5 = 787c969c7292ef28ca447daf24f1b6a1 OK
2024/11/26 03:35:42 DEBUG : dst/two: md5 = 89b3125fd58da286e8e8150018caad28 OK
2024/11/26 03:35:44 DEBUG : dst/three.txt: md5 = 481ec4cfed9bc8c5851dbcc3d89566d2 OK
2024/11/26 03:35:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/dst"
2024/11/26 03:35:45 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/26 03:35:46 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/26 03:35:47 INFO  : one: Moved (server-side) to: one.bak
2024/11/26 03:35:48 DEBUG : one: md5 = a911c079ae74f6248d2b01a7add1f82d OK
2024/11/26 03:35:48 INFO  : one: Copied (new)
2024/11/26 03:35:48 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:35:48 DEBUG : two: Unchanged skipping
2024/11/26 03:35:49 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/11/26 03:35:50 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/26 03:35:51 DEBUG : three.txt: md5 = 6f761c89cfbbe40961edc096db95a018 OK
2024/11/26 03:35:51 INFO  : three.txt: Copied (new)
2024/11/26 03:35:53 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/26 03:35:54 INFO  : one.bak: Deleted
2024/11/26 03:35:54 INFO  : one: Moved (server-side) to: one.bak
2024/11/26 03:35:56 DEBUG : one: md5 = e4c01ad708e1eb303640b7f4acdb395b OK
2024/11/26 03:35:56 INFO  : one: Copied (new)
2024/11/26 03:35:56 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:35:56 DEBUG : two: Unchanged skipping
2024/11/26 03:35:56 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/11/26 03:35:57 INFO  : three.txt.bak: Deleted
2024/11/26 03:35:58 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/26 03:35:59 DEBUG : three.txt: md5 = 146c711c86bfe918bb8cae90943db7c2 OK
2024/11/26 03:35:59 INFO  : three.txt: Copied (new)
2024/11/26 03:36:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/26 03:36:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/26 03:36:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/26 03:36:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/26 03:36:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/26 03:36:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/26 03:36:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncSuffix (26.83s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:36:07 DEBUG : dst/one: md5 = bc6e90d49bf269b2903db29973f83cbc OK
2024/11/26 03:36:09 DEBUG : dst/two: md5 = 928b49d541b6baec92a4902e01a75644 OK
2024/11/26 03:36:11 DEBUG : dst/three.txt: md5 = 8e9ef613a062b255ddb75a845c361cf6 OK
2024/11/26 03:36:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-busewiw5biya/dst"
2024/11/26 03:36:11 DEBUG : Creating backend with remote "TestDrive:crypt/7fnkqo1trqb2cpel869oejq0oi1m7p7p5ocm426aaol5t47qjb80/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/26 03:36:12 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/26 03:36:14 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/26 03:36:16 DEBUG : one: md5 = e71b9ebea7ad6ec83b44f98388087b75 OK
2024/11/26 03:36:16 INFO  : one: Copied (new)
2024/11/26 03:36:16 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:36:16 DEBUG : two: Unchanged skipping
2024/11/26 03:36:16 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/11/26 03:36:17 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/26 03:36:19 DEBUG : three.txt: md5 = a831ebe6ee03dc17d4967f53b5e85ea6 OK
2024/11/26 03:36:19 INFO  : three.txt: Copied (new)
2024/11/26 03:36:20 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/26 03:36:21 INFO  : one-2019-01-01: Deleted
2024/11/26 03:36:21 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/26 03:36:23 DEBUG : one: md5 = 40ab7837f7fb6f0a47df7b871f52cdd3 OK
2024/11/26 03:36:23 INFO  : one: Copied (new)
2024/11/26 03:36:23 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:36:23 DEBUG : two: Unchanged skipping
2024/11/26 03:36:24 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/11/26 03:36:24 INFO  : three-2019-01-01.txt: Deleted
2024/11/26 03:36:25 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/26 03:36:27 DEBUG : three.txt: md5 = 7d1b57aaa75cb85b2eead74d1072fdda OK
2024/11/26 03:36:27 INFO  : three.txt: Copied (new)
2024/11/26 03:36:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/26 03:36:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/26 03:36:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/26 03:36:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/26 03:36:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/26 03:36:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/26 03:36:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncSuffixKeepExtension (27.34s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:36:34 DEBUG : Testêé: md5 = ad68c3f2d8cad3e6b06840bf2fef1bba OK
2024/11/26 03:36:34 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2024/11/26 03:36:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:36:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:36:36 DEBUG : Testêé: md5 = 3c59b62213f4ed6961d10cf94f1df48b OK
2024/11/26 03:36:36 INFO  : Testêé: Copied (replaced existing) to: Testêé
2024/11/26 03:36:36 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (4.93s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:36:37 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/26 03:36:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:36:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:36:39 DEBUG : existing: md5 = 5ac76469b5d47a521e9eae9ae07615e3 OK
2024/11/26 03:36:39 INFO  : existing: Copied (new)
2024/11/26 03:36:39 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:36:40 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2024/11/26 03:36:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:36:40 ERROR : existing: Source and destination exist but do not match: immutable file modified
2024/11/26 03:36:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:36:40 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': not deleting files as there were IO errors
2024/11/26 03:36:40 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncImmutable (5.15s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:36:44 DEBUG : EXISTING: md5 = ef94199460dc9469bebcc2f11926f2af OK
2024/11/26 03:36:44 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:36:44 DEBUG : existing: Unchanged skipping
2024/11/26 03:36:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:36:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:36:44 DEBUG : Waiting for deletions to finish
2024/11/26 03:36:44 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (3.46s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", 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-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", 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-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", 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-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.38s)
    --- SKIP: TestMaxTransfer/Hard (0.46s)
    --- SKIP: TestMaxTransfer/Soft (0.46s)
    --- SKIP: TestMaxTransfer/Cautious (0.46s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:36:49 DEBUG : both0: md5 = 3cd1d91e9c3ce7209a3c70bf7ff47e65 OK
2024/11/26 03:36:51 DEBUG : only0: md5 = 77665bbe3392c230ea036cf955a3bf61 OK
2024/11/26 03:36:53 DEBUG : both1: md5 = 91eb11b190d7e357bd202a0a3b5c71e5 OK
2024/11/26 03:36:54 DEBUG : only1: md5 = d9cb269ce43f7f40998da877ab904b50 OK
2024/11/26 03:36:56 DEBUG : both2: md5 = 5b0c6da10ffbc3c67eb7ca0261937cc6 OK
2024/11/26 03:36:58 DEBUG : only2: md5 = b12e021b9d63cef8297b11a149e02dc1 OK
2024/11/26 03:37:00 DEBUG : both3: md5 = 27f473a17e4940f7f40c8dbc391a60e9 OK
2024/11/26 03:37:02 DEBUG : only3: md5 = 27812d6746b27f0b4a778330dbb3332e OK
2024/11/26 03:37:03 DEBUG : both4: md5 = 7615c96ab18cd73e35449dc436a4530c OK
2024/11/26 03:37:05 DEBUG : only4: md5 = fe62c38aad89119f0d394be26c118c1b OK
2024/11/26 03:37:07 DEBUG : both5: md5 = 87bf4faaaf22fd653014cf6fad354327 OK
2024/11/26 03:37:08 DEBUG : only5: md5 = 18bdfd2068430e11d6a5f6ce0f850fcf OK
2024/11/26 03:37:10 DEBUG : both6: md5 = 22951781ad47afb008111833db22946b OK
2024/11/26 03:37:12 DEBUG : only6: md5 = aa7e755e1fa987a824fdd05f38ad8890 OK
2024/11/26 03:37:13 DEBUG : both7: md5 = 28eacc1c3f2ec08a71cffbeaa21de0e4 OK
2024/11/26 03:37:15 DEBUG : only7: md5 = db3dc8398d5c3a6f510e839e2be99c40 OK
2024/11/26 03:37:17 DEBUG : both8: md5 = c90dad92c8fa469cc3a36f2d3920772c OK
2024/11/26 03:37:18 DEBUG : only8: md5 = ac1192a5586af4e5b18301cb00ead4d2 OK
2024/11/26 03:37:21 DEBUG : both9: md5 = 283085b7d044dba7c77458b5534c49fa OK
2024/11/26 03:37:23 DEBUG : only9: md5 = 23b20ec3eb9bc0fee7a142ce6dd07f5a OK
2024/11/26 03:37:24 DEBUG : both10: md5 = 6b0c85724d22895cf0ebd24c7b10a8de OK
2024/11/26 03:37:26 DEBUG : only10: md5 = f1f776be33163895ca608f5baaeffaa6 OK
2024/11/26 03:37:28 DEBUG : both11: md5 = 9efec1209ca47e77a2e34c351aa8ad67 OK
2024/11/26 03:37:29 DEBUG : only11: md5 = 3242a923c6c24887bb9a186f65c96062 OK
2024/11/26 03:37:31 DEBUG : both12: md5 = 4f6e8603371317944c97151d5a9c7957 OK
2024/11/26 03:37:33 DEBUG : only12: md5 = 2fbb15d34d1c53c7ebb22531479a9d83 OK
2024/11/26 03:37:35 DEBUG : both13: md5 = bc104157416b9099001f378362f2226a OK
2024/11/26 03:37:36 DEBUG : only13: md5 = b5eec72ca160a9be2965ca6359a33db8 OK
2024/11/26 03:37:38 DEBUG : both14: md5 = a1b1303ff01969efc14ffe255f54823d OK
2024/11/26 03:37:40 DEBUG : only14: md5 = edbf7716ca748800045172c09a5479ea OK
2024/11/26 03:37:41 DEBUG : both15: md5 = 3ac8d255ae2f99ad404bc657de167576 OK
2024/11/26 03:37:43 DEBUG : only15: md5 = 153aa2ced069d1ae350acaa12994adc1 OK
2024/11/26 03:37:45 DEBUG : both16: md5 = 199c8ae0a9be97b26734e5f40e8c5ec8 OK
2024/11/26 03:37:47 DEBUG : only16: md5 = 43c4aa02121722a24101b6a7f74fb9c7 OK
2024/11/26 03:37:48 DEBUG : both17: md5 = ccfcfd78bfb2af87e5ccea2aced5589a OK
2024/11/26 03:37:50 DEBUG : only17: md5 = db5a04d4a0c3bb655faf5c4f99b7d763 OK
2024/11/26 03:37:52 DEBUG : both18: md5 = 2ba4976d7adc24c946991e375c9c1854 OK
2024/11/26 03:37:54 DEBUG : only18: md5 = 06faa17cbae0e3ac7f202f97575feeeb OK
2024/11/26 03:37:55 DEBUG : both19: md5 = d265f39683f742a2a599cc65e3a62303 OK
2024/11/26 03:37:57 DEBUG : only19: md5 = 3adffd44e895128fb2b017758bfdd8e8 OK
2024/11/26 03:37:58 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:37:58 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both0: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both1: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both13: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both10: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both11: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both12: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both14: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both15: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both19: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both16: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both3: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both4: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both17: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both5: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both18: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both2: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:37:58 DEBUG : both6: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both7: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both8: Unchanged skipping
2024/11/26 03:37:58 DEBUG : both9: Unchanged skipping
2024/11/26 03:37:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:37:58 DEBUG : Waiting for deletions to finish
2024/11/26 03:37:58 INFO  : only14: Deleted
2024/11/26 03:37:58 INFO  : only6: Deleted
2024/11/26 03:37:58 INFO  : only17: Deleted
2024/11/26 03:37:58 INFO  : only4: Deleted
2024/11/26 03:37:59 INFO  : only3: Deleted
2024/11/26 03:37:59 INFO  : only16: Deleted
2024/11/26 03:37:59 INFO  : only13: Deleted
2024/11/26 03:37:59 INFO  : only2: Deleted
2024/11/26 03:37:59 INFO  : only10: Deleted
2024/11/26 03:37:59 INFO  : only7: Deleted
2024/11/26 03:37:59 INFO  : only11: Deleted
2024/11/26 03:38:00 INFO  : only5: Deleted
2024/11/26 03:38:00 INFO  : only0: Deleted
2024/11/26 03:38:00 INFO  : only9: Deleted
2024/11/26 03:38:00 INFO  : only19: Deleted
2024/11/26 03:38:00 INFO  : only18: Deleted
2024/11/26 03:38:01 INFO  : only8: Deleted
2024/11/26 03:38:01 INFO  : only1: Deleted
2024/11/26 03:38:01 INFO  : only15: Deleted
2024/11/26 03:38:01 INFO  : only12: Deleted
2024/11/26 03:38:01 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (87.52s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:38:16 DEBUG : both0: md5 = 0224e4fe602926d6e1251bb33c03c829 OK
2024/11/26 03:38:18 DEBUG : only0: md5 = 9ff457720ff9cb050840aacd328dc9d2 OK
2024/11/26 03:38:20 DEBUG : both1: md5 = 5ed23ebe1b0442e8bb5d5971e9a0ae65 OK
2024/11/26 03:38:22 DEBUG : only1: md5 = bac1b2cb2fcab49f4d42aedf299f8b07 OK
2024/11/26 03:38:24 DEBUG : both2: md5 = fdb2dc2056952e5fbf616e0eb80b40b3 OK
2024/11/26 03:38:25 DEBUG : only2: md5 = 0bf8ae9a158d9367053b11561d912c4a OK
2024/11/26 03:38:27 DEBUG : both3: md5 = 6a1209baef1d1be1bbfc30fdb4c9641b OK
2024/11/26 03:38:29 DEBUG : only3: md5 = a2ce0d82450828e2096dcad86a0d7656 OK
2024/11/26 03:38:31 DEBUG : both4: md5 = 623dad0e7d4672866cd18219bfa964f6 OK
2024/11/26 03:38:32 DEBUG : only4: md5 = 47a95f461a5a4f651db721ca73d8d0bb OK
2024/11/26 03:38:34 DEBUG : both5: md5 = 09686b271825c1341fe3e02c9704a90e OK
2024/11/26 03:38:36 DEBUG : only5: md5 = 1c06bc31d0e2402001de38a007c41458 OK
2024/11/26 03:38:37 DEBUG : both6: md5 = ab22553339cf2ec7bcebda414a24c13e OK
2024/11/26 03:38:39 DEBUG : only6: md5 = 1c7c3ff01b336ad2a4e5a29924513f30 OK
2024/11/26 03:38:41 DEBUG : both7: md5 = 10a671e3a74f9d4cbf4361c1303814e0 OK
2024/11/26 03:38:43 DEBUG : only7: md5 = 613c3eb09a5fc63bc6643569a8c9b433 OK
2024/11/26 03:38:45 DEBUG : both8: md5 = eef0ab8fe0786e4f2443732c3ea8e89e OK
2024/11/26 03:38:46 DEBUG : only8: md5 = 287548ca842b59c7e71f8d61a67c4192 OK
2024/11/26 03:38:48 DEBUG : both9: md5 = bcf1a8ff6d412720bdcb1f9d8d629508 OK
2024/11/26 03:38:50 DEBUG : only9: md5 = 84dc078dc0fcfecb23189228615efb28 OK
2024/11/26 03:38:51 DEBUG : both10: md5 = f0fd1776bc5b6dda9a062d9b0a0e5773 OK
2024/11/26 03:38:53 DEBUG : only10: md5 = b75a35a613341391162b3846820ec24b OK
2024/11/26 03:38:55 DEBUG : both11: md5 = ade6b1914c5c05e6e5779ac16b187a62 OK
2024/11/26 03:38:57 DEBUG : only11: md5 = ba87ef4c62fc9d3f26a04e9decf387a8 OK
2024/11/26 03:38:58 DEBUG : both12: md5 = d92f3a663eaa59f46503dcd060036c36 OK
2024/11/26 03:39:00 DEBUG : only12: md5 = cb2597e3b8a27a5904f32e3e5feafbce OK
2024/11/26 03:39:02 DEBUG : both13: md5 = a7d3a1473724b7c6bcd4e515445ca631 OK
2024/11/26 03:39:04 DEBUG : only13: md5 = 62c46165546a6105c05616e0420e8089 OK
2024/11/26 03:39:05 DEBUG : both14: md5 = bb6dc5bc1637048afd817c26e7a464ef OK
2024/11/26 03:39:07 DEBUG : only14: md5 = a2e9f95c725fa08b48034756abccea7a OK
2024/11/26 03:39:09 DEBUG : both15: md5 = f57c119982adc5f003a61fce742850f6 OK
2024/11/26 03:39:10 DEBUG : only15: md5 = 7ee96f693121108d17281d95fd8f9ed5 OK
2024/11/26 03:39:12 DEBUG : both16: md5 = 243d231dfb32ecf0e4bad09ec37a0105 OK
2024/11/26 03:39:14 DEBUG : only16: md5 = da47ddb28f3db84863a1a5d11ca3c12a OK
2024/11/26 03:39:16 DEBUG : both17: md5 = bc0e943a6e77a793efc84b0bc15c9dc5 OK
2024/11/26 03:39:17 DEBUG : only17: md5 = f12537caae04a84877359a23419db74c OK
2024/11/26 03:39:19 DEBUG : both18: md5 = 4940146c26886b661dda4b9bd14a2230 OK
2024/11/26 03:39:21 DEBUG : only18: md5 = 4bc0d87cae872a3b9545d47d0a7ed0dd OK
2024/11/26 03:39:22 DEBUG : both19: md5 = a6b4bf9200b028ab2cc151c684f63c06 OK
2024/11/26 03:39:24 DEBUG : only19: md5 = 8f8338ef12beb52a1dff18dd0821bf9a OK
2024/11/26 03:39:25 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both0: Unchanged skipping
2024/11/26 03:39:25 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both1: Unchanged skipping
2024/11/26 03:39:25 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both10: Unchanged skipping
2024/11/26 03:39:25 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for checks to finish
2024/11/26 03:39:25 DEBUG : both11: Unchanged skipping
2024/11/26 03:39:25 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both15: Unchanged skipping
2024/11/26 03:39:25 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both16: Unchanged skipping
2024/11/26 03:39:25 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both17: Unchanged skipping
2024/11/26 03:39:25 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both18: Unchanged skipping
2024/11/26 03:39:25 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both19: Unchanged skipping
2024/11/26 03:39:25 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both2: Unchanged skipping
2024/11/26 03:39:25 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both3: Unchanged skipping
2024/11/26 03:39:25 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both4: Unchanged skipping
2024/11/26 03:39:25 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both5: Unchanged skipping
2024/11/26 03:39:25 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both6: Unchanged skipping
2024/11/26 03:39:25 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both7: Unchanged skipping
2024/11/26 03:39:25 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both8: Unchanged skipping
2024/11/26 03:39:25 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/26 03:39:25 DEBUG : both9: Unchanged skipping
2024/11/26 03:39:25 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2024/11/26 03:39:25 DEBUG : both12: Unchanged skipping
2024/11/26 03:39:25 DEBUG : both13: Unchanged skipping
2024/11/26 03:39:25 DEBUG : both14: Unchanged skipping
2024/11/26 03:39:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Waiting for transfers to finish
2024/11/26 03:39:26 DEBUG : only10: md5 = 0bdd019324545b668e7808b2497a79d4 OK
2024/11/26 03:39:26 INFO  : only10: Copied (replaced existing)
2024/11/26 03:39:26 DEBUG : only11: md5 = fc108555fb76b06e7fe5b3cdd69d7d3e OK
2024/11/26 03:39:26 INFO  : only11: Copied (replaced existing)
2024/11/26 03:39:26 DEBUG : only1: md5 = 617c676f2bbb9b3259c4b03f02163e54 OK
2024/11/26 03:39:26 INFO  : only1: Copied (replaced existing)
2024/11/26 03:39:26 DEBUG : only0: md5 = dde3378762bd9b8c9a82470854411561 OK
2024/11/26 03:39:26 INFO  : only0: Copied (replaced existing)
2024/11/26 03:39:28 DEBUG : only12: md5 = 36e954b33249d2dd02c2942fe2a53509 OK
2024/11/26 03:39:28 INFO  : only12: Copied (replaced existing)
2024/11/26 03:39:28 DEBUG : only14: md5 = 4d39b9d64e7ae3f2b046a958f4afc3c3 OK
2024/11/26 03:39:28 INFO  : only14: Copied (replaced existing)
2024/11/26 03:39:28 DEBUG : only13: md5 = bd55ff5065f5525d690fed9f146d3bb0 OK
2024/11/26 03:39:28 INFO  : only13: Copied (replaced existing)
2024/11/26 03:39:28 DEBUG : only15: md5 = c1bf20964b2bb122084d131b59e542a6 OK
2024/11/26 03:39:28 INFO  : only15: Copied (replaced existing)
2024/11/26 03:39:29 DEBUG : only16: md5 = 2045c770f040593adb9a49fd59b07bf4 OK
2024/11/26 03:39:29 INFO  : only16: Copied (replaced existing)
2024/11/26 03:39:29 DEBUG : only17: md5 = cbc09a9a684c9cef6556ef3aed15a7f0 OK
2024/11/26 03:39:29 INFO  : only17: Copied (replaced existing)
2024/11/26 03:39:29 DEBUG : only18: md5 = 59b441c976a745cfdfa738fadb2c3068 OK
2024/11/26 03:39:29 INFO  : only18: Copied (replaced existing)
2024/11/26 03:39:29 DEBUG : only19: md5 = 5ff52f9e883b178b14cadea8a1d3b784 OK
2024/11/26 03:39:29 INFO  : only19: Copied (replaced existing)
2024/11/26 03:39:30 DEBUG : only2: md5 = fb1ef207e70fc84afc9739b6a939cb10 OK
2024/11/26 03:39:30 INFO  : only2: Copied (replaced existing)
2024/11/26 03:39:30 DEBUG : only3: md5 = 8f18b32b2d54e5a42d21802cad1c4c3b OK
2024/11/26 03:39:30 INFO  : only3: Copied (replaced existing)
2024/11/26 03:39:30 DEBUG : only4: md5 = ac7b076069089fcf3329240cf54d2afb OK
2024/11/26 03:39:30 INFO  : only4: Copied (replaced existing)
2024/11/26 03:39:30 DEBUG : only5: md5 = 381b2e4704d5a2812464f45ddfa266f7 OK
2024/11/26 03:39:30 INFO  : only5: Copied (replaced existing)
2024/11/26 03:39:31 DEBUG : only6: md5 = 568c8f60379074eefda0b42d193e7a24 OK
2024/11/26 03:39:31 INFO  : only6: Copied (replaced existing)
2024/11/26 03:39:32 DEBUG : only7: md5 = d331fd9758c9026d8310cc06a032265c OK
2024/11/26 03:39:32 INFO  : only7: Copied (replaced existing)
2024/11/26 03:39:32 DEBUG : only9: md5 = 0e359fb45c3ed03804256b99802f414b OK
2024/11/26 03:39:32 INFO  : only9: Copied (replaced existing)
2024/11/26 03:39:32 DEBUG : only8: md5 = 41f0e9120bf5807bf2ea0562b4753074 OK
2024/11/26 03:39:32 INFO  : only8: Copied (replaced existing)
2024/11/26 03:39:32 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (102.64s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:39:57 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/26 03:39:57 DEBUG : sub dir: Making directory with metadata
2024/11/26 03:39:59 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:40:19 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/26 03:40:20 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/26 03:40:20 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/26 03:40:20 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:40:34 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2024/11/26 03:40:35 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/26 03:40:36 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/11/26 03:40:37 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/11/26 03:40:38 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/26 03:40:39 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/26 03:40:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/26 03:40:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/26 03:40:41 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/26 03:40:42 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/11/26 03:40:42 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/26 03:40:43 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (48.14s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:40:46 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/26 03:40:46 DEBUG : sub dir: Making directory with metadata
2024/11/26 03:40:47 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:41:13 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/26 03:41:13 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/26 03:41:13 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/26 03:41:13 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya'", Local "Local file system at /tmp/rclone2855278465", Modify Window "1ms"
2024/11/26 03:41:26 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/26 03:41:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/11/26 03:41:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/11/26 03:41:29 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/26 03:41:30 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/26 03:41:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/26 03:41:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/26 03:41:32 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/26 03:41:33 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/11/26 03:41:33 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/26 03:41:34 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (51.04s)
PASS
2024/11/26 03:41:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-busewiw5biya': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 18m12.784515683s (try 1/5)