"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5)
2024/11/29 02:27:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci"
2024/11/29 02:27:41 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/11/29 02:27:42 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg"
2024/11/29 02:27:43 DEBUG : Creating backend with remote "/tmp/rclone4249100962"
=== 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-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:27:44 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:27:44 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:27:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:27:44 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2024/11/29 02:27:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:27:44 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.79s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:27:45 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:27:46 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:27:46 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:27:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:27:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:27:49 DEBUG : sub dir/hello world: md5 = c10f11456b3f3199656096c279612894 OK
2024/11/29 02:27:49 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:27:50 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:27:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (7.91s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:27:53 DEBUG : metadata sub dir: Making directory with metadata
2024/11/29 02:27:53 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:27:53 DEBUG : empty metadata sub dir: Making directory with metadata
2024/11/29 02:27:53 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:27:53 DEBUG : Local file system at /tmp/rclone4249100962: File to upload is small (21 bytes), uploading instead of streaming
2024/11/29 02:27:53 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/11/29 02:27:53 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/11/29 02:27:53 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:27:54 DEBUG : Google drive root 'crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg': Skipping btime metadata as can't update it on an existing file: 2024-11-29T02:27:53.873173443Z
2024/11/29 02:27:55 INFO  : empty metadata sub dir: Updated directory metadata
2024/11/29 02:27:55 DEBUG : Google drive root 'crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg': Skipping btime metadata as can't update it on an existing file: 2024-11-29T02:27:53.873173443Z
2024/11/29 02:27:56 INFO  : metadata sub dir: Updated directory metadata
2024/11/29 02:27:56 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/11/29 02:27:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:27:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:27:58 DEBUG : metadata sub dir/hello metadata world: md5 = 0a45418f70f0fa4645ebe6059f18bcdf OK
2024/11/29 02:27:58 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:28:01 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (10.14s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:28:04 DEBUG : metadata sub dir: Making directory with metadata
2024/11/29 02:28:04 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:28:04 DEBUG : empty metadata sub dir: Making directory with metadata
2024/11/29 02:28:04 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:28:04 DEBUG : Local file system at /tmp/rclone4249100962: File to upload is small (21 bytes), uploading instead of streaming
2024/11/29 02:28:04 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/11/29 02:28:04 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/11/29 02:28:04 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:28:04 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2024/11/29 02:28:04 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2024/11/29 02:28:04 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/11/29 02:28:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:28:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:28:07 DEBUG : metadata sub dir/hello metadata world: md5 = 8b20c484dffb3c78d46a295c4e568753 OK
2024/11/29 02:28:07 INFO  : metadata sub dir/hello metadata world: Copied (new)
2024/11/29 02:28:07 DEBUG : Google drive root 'crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg': Skipping btime metadata as can't update it on an existing file: 2024-11-29T02:28:04.017106277Z
2024/11/29 02:28:07 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:28:11 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (8.48s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:28:12 DEBUG : Creating backend with remote "/non-existing"
2024/11/29 02:28:12 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2024/11/29 02:28:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:28:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.24s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:28:13 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:28:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:28:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:28:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:28:16 DEBUG : sub dir/hello world: md5 = e2d195d8ad7f908f5ef61be54e5d5ea2 OK
2024/11/29 02:28:16 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:28:17 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:28:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (7.27s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:28:21 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Running all checks before starting transfers
2024/11/29 02:28:21 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:28:21 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:28:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:28:21 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Checks finished, now starting transfers
2024/11/29 02:28:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:28:24 DEBUG : sub dir/hello world: md5 = 135590dc6544d48e06ba996212536887 OK
2024/11/29 02:28:24 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:28:24 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:28:26 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (7.17s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:28:28 ERROR : Ignoring --no-traverse with sync
2024/11/29 02:28:28 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:28:28 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:28:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:28:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:28:31 DEBUG : sub dir/hello world: md5 = 167424591eefc2f5719fbdf57423be54 OK
2024/11/29 02:28:31 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:28:31 DEBUG : Waiting for deletions to finish
2024/11/29 02:28:32 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:28:34 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (7.43s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:28:35 DEBUG : hello world2: Need to transfer - File not found at Destination
2024/11/29 02:28:35 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:28:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:28:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:28:37 DEBUG : hello world2: md5 = 0933de0a2fb4d99270495c88093e7498 OK
2024/11/29 02:28:37 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestCopyWithDepth (3.91s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:28:39 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:28:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:28:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:28:41 DEBUG : potato2: md5 = cc01ab4f789e5306e8bd1936600fdd04 OK
2024/11/29 02:28:41 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.96s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:28:43 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:28:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:28:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:28:45 DEBUG : potato2: md5 = 33658a05106d8b0d54d745884c9dea69 OK
2024/11/29 02:28:45 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (4.07s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:28:47 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/29 02:28:47 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:28:47 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/29 02:28:47 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:28:47 DEBUG : sub dir: Making directory with metadata
2024/11/29 02:28:49 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/29 02:28:49 DEBUG : sub dir2: Making directory with metadata
2024/11/29 02:28:50 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:28:50 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/29 02:28:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:28:51 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:28:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:28:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:28:52 DEBUG : sub dir/hello world: md5 = 0c6744a53fa4c5cafe7bcf40fed6f26c OK
2024/11/29 02:28:52 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:28:56 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2024/11/29 02:28:57 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (11.24s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:28:58 DEBUG : sub dir2: Making directory
2024/11/29 02:28:58 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/29 02:28:58 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:28:59 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:28:59 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/29 02:28:59 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2024/11/29 02:28:59 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:28:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:28:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:29:01 DEBUG : sub dir/hello world: md5 = ef9b54ac4038a18c7dd2635d714d0866 OK
2024/11/29 02:29:01 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:29:02 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:29:04 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (6.87s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:29:05 DEBUG : sub dir2: Making directory with metadata
2024/11/29 02:29:05 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:29:05 DEBUG : sub dir: Making directory with metadata
2024/11/29 02:29:07 INFO  : sub dir: Made directory with metadata (mtime=2024-11-29T02:29:05.656697038Z)
2024/11/29 02:29:07 DEBUG : sub dir2: Making directory with metadata
2024/11/29 02:29:08 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:29:08 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:29:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:29:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:29:10 DEBUG : sub dir/hello world: md5 = ff82315007d66d0890d965647ae2797d OK
2024/11/29 02:29:10 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:29:10 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:29:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (9.09s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:29:14 DEBUG : sub dir no update dir modtime: Making directory with metadata
2024/11/29 02:29:14 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/29 02:29:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:29:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:29:16 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (4.87s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:29:19 DEBUG : sub dir2: Making directory
2024/11/29 02:29:19 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:29:19 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/29 02:29:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:29:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:29:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:29:22 DEBUG : sub dir/hello world: md5 = 65c6c063ac051c8680aec777d6fb746d OK
2024/11/29 02:29:22 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:29:22 INFO  : sub dir/hello world: Deleted
2024/11/29 02:29:23 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:29:25 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (6.86s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:29:26 DEBUG : sub dir2: Making directory with metadata
2024/11/29 02:29:26 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:29:26 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:29:26 DEBUG : sub dir: Making directory with metadata
2024/11/29 02:29:27 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/29 02:29:27 DEBUG : sub dir2: Making directory with metadata
2024/11/29 02:29:29 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:29:29 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:29:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:29:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:29:30 DEBUG : sub dir/hello world: md5 = 3d6ae0b662a9dbc629c53f649c435835 OK
2024/11/29 02:29:30 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:29:30 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:29:34 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (9.28s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", 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-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:29:36 DEBUG : sub dir2: Making directory
2024/11/29 02:29:36 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:29:36 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/29 02:29:36 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:29:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:29:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:29:39 DEBUG : sub dir/hello world: md5 = e7db08b945c5a9fa2ef6f924b12b9986 OK
2024/11/29 02:29:39 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:29:39 DEBUG : Waiting for deletions to finish
2024/11/29 02:29:39 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:29:41 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (6.56s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:29:45 DEBUG : sub dir/hello world: md5 = 3c21f4ba563c30914020925e8efaa166 OK
2024/11/29 02:29:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lifozeg0paje"
2024/11/29 02:29:46 DEBUG : Creating backend with remote "TestDrive:crypt/rjtk7p90gs47i050ec06l356ue8gvhdo1q74ggomvpl4o2ckfc8g"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci' -> Encrypted drive 'TestCryptDrive:rclone-test-lifozeg0paje'
2024/11/29 02:29:47 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:29:47 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:29:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lifozeg0paje': Waiting for checks to finish
2024/11/29 02:29:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lifozeg0paje': Waiting for transfers to finish
2024/11/29 02:29:51 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/29 02:29:51 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:29:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lifozeg0paje': Purge remote
2024/11/29 02:29:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (13.08s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:29:58 DEBUG : sub dir/hello world: md5 = ad8474fb2fe3212e303ba49c1002d119 OK
2024/11/29 02:29:59 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/29 02:29:59 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/29 02:29:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:29:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:30:01 DEBUG : sub dir/hello world: md5 = 344882f6987e20e60d413e86bc3c1f2a OK
2024/11/29 02:30:01 INFO  : sub dir/hello world: Copied (replaced existing)
2024/11/29 02:30:01 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:30:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (9.03s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:30:07 DEBUG : sub dir/hello world: md5 = c5f1322218266447bfcf14ae3b4d6c07 OK
2024/11/29 02:30:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-licaqey0kune"
2024/11/29 02:30:08 DEBUG : Creating backend with remote "TestDrive:crypt/8j44j5frnq5jr3nudfl0ncj5ihc42mlf0tcia7t7uqg086viv2tg"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci' -> Encrypted drive 'TestCryptDrive:rclone-test-licaqey0kune'
2024/11/29 02:30:10 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:30:10 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:30:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-licaqey0kune': Waiting for checks to finish
2024/11/29 02:30:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-licaqey0kune': Waiting for transfers to finish
2024/11/29 02:30:13 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/29 02:30:15 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:30:17 DEBUG : sub dir/hello world: md5 = 26a2d6efd2d421b05175d1818a829545 OK
2024/11/29 02:30:18 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/29 02:30:18 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/29 02:30:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-licaqey0kune': Waiting for checks to finish
2024/11/29 02:30:18 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/29 02:30:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-licaqey0kune': Waiting for transfers to finish
2024/11/29 02:30:20 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/29 02:30:21 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:30:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-licaqey0kune': Purge remote
2024/11/29 02:30:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (20.73s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:30:28 DEBUG : sub dir/hello world: md5 = 4ae49729c00e2323843a16a5d488a17b OK
2024/11/29 02:30:29 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/29 02:30:29 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/29 02:30:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:30:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:30:31 DEBUG : sub dir/hello world: md5 = 51088c85cc670654829bd22d3172989e OK
2024/11/29 02:30:31 INFO  : sub dir/hello world: Copied (replaced existing)
2024/11/29 02:30:31 INFO  : sub dir/hello world: Deleted
2024/11/29 02:30:32 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:30:34 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (9.76s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:30:38 DEBUG : sub dir/hello world: md5 = 0e1212ba06de3f5bda1ec5702b935cd3 OK
2024/11/29 02:30:38 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-digugih1huwe"
2024/11/29 02:30:38 DEBUG : Creating backend with remote "TestDrive:crypt/rq7aefkhk8tqp9bintkacvincfervf5jfm4bbnncollrp7t9ahng"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci' -> Encrypted drive 'TestCryptDrive:rclone-test-digugih1huwe'
2024/11/29 02:30:40 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:30:40 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:30:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-digugih1huwe': Waiting for checks to finish
2024/11/29 02:30:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-digugih1huwe': Waiting for transfers to finish
2024/11/29 02:30:44 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/29 02:30:44 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:30:47 DEBUG : sub dir/hello world: md5 = d2a4584164431b71ce41b28887d4aeee OK
2024/11/29 02:30:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-digugih1huwe': Using server-side directory move
2024/11/29 02:30:47 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-digugih1huwe': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/29 02:30:48 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/29 02:30:48 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/29 02:30:48 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/29 02:30:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-digugih1huwe': Waiting for checks to finish
2024/11/29 02:30:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-digugih1huwe': Waiting for transfers to finish
2024/11/29 02:30:48 INFO  : sub dir/hello world: Deleted
2024/11/29 02:30:49 INFO  : sub dir/hello world: Moved (server-side)
2024/11/29 02:30:50 INFO  : sub dir: Set directory modification time (using SetModTime)
2024/11/29 02:30:53 DEBUG : sub dir/hello world: md5 = c5d9d75d2228eceae33553d9c4c1eb51 OK
2024/11/29 02:30:53 DEBUG : testing file moves
2024/11/29 02:30:54 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/29 02:30:54 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/29 02:30:54 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2024/11/29 02:30:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-digugih1huwe': Waiting for checks to finish
2024/11/29 02:30:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-digugih1huwe': Waiting for transfers to finish
2024/11/29 02:30:54 INFO  : sub dir/hello world: Deleted
2024/11/29 02:30:55 INFO  : sub dir/hello world: Moved (server-side)
2024/11/29 02:30:56 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:30:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-digugih1huwe': Purge remote
--- PASS: TestServerSideMoveOverSelf (25.03s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:31:03 DEBUG : sub dir/hello world: md5 = 8e85aaca75c7b5fc9dc1de69ee34e8ad OK
2024/11/29 02:31:03 ERROR : : error listing: directory not found
2024/11/29 02:31:03 DEBUG : Local file system at /tmp/rclone4249100962: Making directory
2024/11/29 02:31:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:31:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:31:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (7.04s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:31:10 DEBUG : sub dir/hello world: md5 = 7ea9884673470f1dc24d3312b877b491 OK
2024/11/29 02:31:11 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:31:11 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:31:11 DEBUG : Local file system at /tmp/rclone4249100962: Waiting for checks to finish
2024/11/29 02:31:11 DEBUG : Local file system at /tmp/rclone4249100962: Waiting for transfers to finish
2024/11/29 02:31:12 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2024/11/29 02:31:12 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:31:12 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:31:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (7.62s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:31:15 DEBUG : check sum: Need to transfer - File not found at Destination
2024/11/29 02:31:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:31:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:31:17 DEBUG : check sum: md5 = f14f609dd941659888196024c21c9f0c OK
2024/11/29 02:31:17 INFO  : check sum: Copied (new)
2024/11/29 02:31:17 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:31:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:31:17 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2024/11/29 02:31:17 DEBUG : check sum: Size of src and dst objects identical
2024/11/29 02:31:17 DEBUG : check sum: Unchanged skipping
2024/11/29 02:31:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:31:17 DEBUG : Waiting for deletions to finish
2024/11/29 02:31:17 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (5.01s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:31:20 DEBUG : sizeonly: Need to transfer - File not found at Destination
2024/11/29 02:31:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:31:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:31:21 DEBUG : sizeonly: md5 = aeb761e61a8444835628d10ee9c913c0 OK
2024/11/29 02:31:21 INFO  : sizeonly: Copied (new)
2024/11/29 02:31:21 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:31:22 DEBUG : sizeonly: Sizes identical
2024/11/29 02:31:22 DEBUG : sizeonly: Unchanged skipping
2024/11/29 02:31:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:31:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:31:22 DEBUG : Waiting for deletions to finish
2024/11/29 02:31:22 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (4.67s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:31:25 DEBUG : ignore-size: Need to transfer - File not found at Destination
2024/11/29 02:31:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:31:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:31:26 DEBUG : ignore-size: md5 = 54aae651a0b94457a87c2f36e4873bac OK
2024/11/29 02:31:26 INFO  : ignore-size: Copied (new)
2024/11/29 02:31:26 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:31:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:31:27 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:31:27 DEBUG : ignore-size: Unchanged skipping
2024/11/29 02:31:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:31:27 DEBUG : Waiting for deletions to finish
2024/11/29 02:31:27 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (5.05s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:31:32 DEBUG : existing: md5 = 3bb4593bffb7a222f8131ff86ded961b OK
2024/11/29 02:31:32 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:31:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:31:32 DEBUG : existing: Unchanged skipping
2024/11/29 02:31:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:31:32 DEBUG : Waiting for deletions to finish
2024/11/29 02:31:32 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:31:32 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2024/11/29 02:31:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:31:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:31:34 DEBUG : existing: md5 = 1b267ce0732fe8b1e0a27d5e8b15162f OK
2024/11/29 02:31:34 INFO  : existing: Copied (replaced existing)
2024/11/29 02:31:34 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (6.92s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:31:36 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/29 02:31:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:31:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:31:38 DEBUG : existing: md5 = 8bc03256bb1f0b5195adea6a8f67df30 OK
2024/11/29 02:31:38 INFO  : existing: Copied (new)
2024/11/29 02:31:38 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:31:39 DEBUG : existing: Destination exists, skipping
2024/11/29 02:31:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:31:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:31:39 DEBUG : Waiting for deletions to finish
2024/11/29 02:31:39 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (4.59s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:31:44 DEBUG : b/potato: md5 = 532898f1bea65f2603d9455b5c208d00 OK
2024/11/29 02:31:46 DEBUG : c/non empty space: md5 = ac163ca056a2a73f362c89c0181c877c OK
2024/11/29 02:31:46 DEBUG : d: Making directory
2024/11/29 02:31:49 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/29 02:31:49 DEBUG : Added delayed dir = "c", newDst=c
2024/11/29 02:31:49 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:31:49 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/29 02:31:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:31:49 DEBUG : c/non empty space: Unchanged skipping
2024/11/29 02:31:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:31:52 DEBUG : a/potato2: md5 = f6af6774f4a1170f82438282d4252fdd OK
2024/11/29 02:31:52 INFO  : a/potato2: Copied (new)
2024/11/29 02:31:52 DEBUG : Waiting for deletions to finish
2024/11/29 02:31:53 INFO  : b/potato: Deleted
2024/11/29 02:31:53 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/29 02:31:53 INFO  : d: Removing directory
2024/11/29 02:31:54 INFO  : b: Removing directory
2024/11/29 02:31:54 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/29 02:31:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:31:58 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/29 02:31:58 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (18.93s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:32:02 DEBUG : empty space: md5 = 243e067f6cf8aa3caefaad2e51abe623 OK
2024/11/29 02:32:02 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/29 02:32:02 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2024/11/29 02:32:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:32:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:32:02 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:32:03 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/29 02:32:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:32:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:32:04 DEBUG : empty space: md5 = 570f3ea939f0569efd83df5afb1ba14c OK
2024/11/29 02:32:04 INFO  : empty space: Copied (replaced existing)
2024/11/29 02:32:04 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (6.56s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.49s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:32:09 DEBUG : foo: md5 = 3af38fba9a9425c290908c64f77d3fb5 OK
2024/11/29 02:32:09 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/29 02:32:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:32:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:32:11 DEBUG : foo: md5 = 822ea52dbbac22a6285b1d9f656e5fb9 OK
2024/11/29 02:32:11 INFO  : foo: Copied (replaced existing)
2024/11/29 02:32:11 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (5.79s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:32:14 DEBUG : empty space: md5 = 9467cf34d8e7eec798ed2518f59dfc05 OK
2024/11/29 02:32:15 DEBUG : potato: Need to transfer - File not found at Destination
2024/11/29 02:32:15 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:32:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:32:15 DEBUG : empty space: Unchanged skipping
2024/11/29 02:32:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:32:17 DEBUG : potato: md5 = e08d486baeb487c0dfebc316a6c67e8b OK
2024/11/29 02:32:17 INFO  : potato: Copied (new)
2024/11/29 02:32:17 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (6.38s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:32:21 DEBUG : potato: md5 = 0efc90d379a20c19d8e64e5338b23a15 OK
2024/11/29 02:32:21 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2024/11/29 02:32:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:32:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:32:23 DEBUG : potato: md5 = 31a257cfcd5997f9bec16a3a1b54ab58 OK
2024/11/29 02:32:23 INFO  : potato: Copied (replaced existing)
2024/11/29 02:32:23 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (5.87s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:32:27 DEBUG : potato: md5 = 7a6f48dcf8301e8f2db5031ca1c42b40 OK
2024/11/29 02:32:27 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/29 02:32:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:32:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:32:28 DEBUG : potato: md5 = d2fb065d0b71c00e8ed6edcebb21fa65 OK
2024/11/29 02:32:28 INFO  : potato: Copied (replaced existing)
2024/11/29 02:32:28 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (5.44s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:32:32 DEBUG : potato: md5 = 5f699005c9d16f9a634402dd2fbade6f OK
2024/11/29 02:32:34 DEBUG : empty space: md5 = 762a7e8ce946e28edb1a2bd6d3110196 OK
2024/11/29 02:32:34 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:32:34 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2024/11/29 02:32:34 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:32:34 DEBUG : empty space: Unchanged skipping
2024/11/29 02:32:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:32:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:32:34 DEBUG : Waiting for deletions to finish
2024/11/29 02:32:34 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (6.24s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:32:38 DEBUG : potato: md5 = f73477fd211ac8a4c2ffe462e1873377 OK
2024/11/29 02:32:40 DEBUG : empty space: md5 = 07b341c5ca8792aa3dca3e86a7e550dc OK
2024/11/29 02:32:41 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:32:41 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:32:41 DEBUG : empty space: Unchanged skipping
2024/11/29 02:32:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:32:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:32:43 DEBUG : potato2: md5 = 5647ab96ded40d06db364929d65832df OK
2024/11/29 02:32:43 INFO  : potato2: Copied (new)
2024/11/29 02:32:43 DEBUG : Waiting for deletions to finish
2024/11/29 02:32:43 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (9.12s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:32:49 DEBUG : b/potato: md5 = 8ece15a101869add9f10793f910d0fce OK
2024/11/29 02:32:51 DEBUG : c/non empty space: md5 = 34fc064a4b10a705bc986e305a9708e9 OK
2024/11/29 02:32:51 DEBUG : d: Making directory
2024/11/29 02:32:53 DEBUG : d/e: Making directory
2024/11/29 02:32:55 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/29 02:32:55 DEBUG : Added delayed dir = "c", newDst=c
2024/11/29 02:32:55 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:32:55 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/29 02:32:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:32:55 DEBUG : c/non empty space: Unchanged skipping
2024/11/29 02:32:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:32:58 DEBUG : a/potato2: md5 = 00eea1b1a057d623d902ba0899fb41c5 OK
2024/11/29 02:32:58 INFO  : a/potato2: Copied (new)
2024/11/29 02:32:58 DEBUG : Waiting for deletions to finish
2024/11/29 02:32:59 INFO  : b/potato: Deleted
2024/11/29 02:32:59 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/29 02:32:59 INFO  : d/e: Removing directory
2024/11/29 02:33:00 INFO  : d: Removing directory
2024/11/29 02:33:01 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2024/11/29 02:33:01 INFO  : b: Removing directory
2024/11/29 02:33:01 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/29 02:33:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:33:05 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/29 02:33:06 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (21.54s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:33:10 DEBUG : b/potato: md5 = d22aae9e2b0280d0c41a6624e8f7a0df OK
2024/11/29 02:33:14 DEBUG : c/non empty space: md5 = d8cd821fb12373064eaa03e3b635e4ea OK
2024/11/29 02:33:14 DEBUG : d: Making directory
2024/11/29 02:33:16 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/29 02:33:16 DEBUG : Added delayed dir = "c", newDst=c
2024/11/29 02:33:16 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:33:16 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/29 02:33:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:33:16 DEBUG : c/non empty space: Unchanged skipping
2024/11/29 02:33:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:33:19 DEBUG : a/potato2: md5 = 8b896843682a1d117d070951bd40ca3d OK
2024/11/29 02:33:19 INFO  : a/potato2: Copied (new)
2024/11/29 02:33:19 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': not deleting files as there were IO errors
2024/11/29 02:33:19 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/29 02:33:19 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:33:23 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/29 02:33:24 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/29 02:33:25 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (19.06s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:33:28 DEBUG : potato: md5 = 7502f5d6e0e22d7c17dcfbbcc2bda69f OK
2024/11/29 02:33:30 DEBUG : empty space: md5 = 3e24a7a70147a477a55029accdf792f2 OK
2024/11/29 02:33:30 DEBUG : Waiting for deletions to finish
2024/11/29 02:33:30 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:33:30 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:33:30 DEBUG : empty space: Unchanged skipping
2024/11/29 02:33:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:33:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:33:31 INFO  : potato: Deleted
2024/11/29 02:33:32 DEBUG : potato2: md5 = 433071e5a5ff631839fbac24c7870641 OK
2024/11/29 02:33:32 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (8.57s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:33:36 DEBUG : potato: md5 = bfc7b17f7c46ccc5c51cb1b9919085be OK
2024/11/29 02:33:38 DEBUG : empty space: md5 = f922f4f49e6577a473d4b047cc25e609 OK
2024/11/29 02:33:39 DEBUG : Waiting for deletions to finish
2024/11/29 02:33:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:33:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:33:39 INFO  : potato: Deleted
2024/11/29 02:33:40 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:33:40 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:33:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:33:40 DEBUG : empty space: Unchanged skipping
2024/11/29 02:33:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:33:41 DEBUG : potato2: md5 = c5c92e73fb9adf5d4dbb2820e8247ebc OK
2024/11/29 02:33:41 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (9.07s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:33:46 DEBUG : potato: md5 = a675f9035f3be462deb0cd02207817f2 OK
2024/11/29 02:33:46 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:33:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:33:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:33:48 DEBUG : potato2: md5 = ed2c9e99eb379053d5eac38abb909cf7 OK
2024/11/29 02:33:48 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (6.54s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:33:52 DEBUG : potato2: md5 = 0a836e3bec44759763b5fd9c649ec0d5 OK
2024/11/29 02:33:54 DEBUG : empty space: md5 = ff31e84ccca00bf28d80dbe6ada70e51 OK
2024/11/29 02:33:54 DEBUG : enormous: Excluded (Size Filter)
2024/11/29 02:33:54 DEBUG : enormous: Excluded
2024/11/29 02:33:54 DEBUG : potato2: Excluded (Size Filter)
2024/11/29 02:33:54 DEBUG : potato2: Excluded
2024/11/29 02:33:54 DEBUG : potato2: Excluded (Size Filter)
2024/11/29 02:33:54 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:33:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:33:54 DEBUG : empty space: Unchanged skipping
2024/11/29 02:33:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:33:54 DEBUG : Waiting for deletions to finish
2024/11/29 02:33:54 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:33:55 DEBUG : enormous: Excluded (Size Filter)
2024/11/29 02:33:55 DEBUG : enormous: Excluded
2024/11/29 02:33:55 DEBUG : potato2: Excluded (Size Filter)
2024/11/29 02:33:55 DEBUG : potato2: Excluded
2024/11/29 02:33:55 DEBUG : potato2: Excluded (Size Filter)
2024/11/29 02:33:55 DEBUG : Local file system at /tmp/rclone4249100962: Waiting for checks to finish
2024/11/29 02:33:55 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/11/29 02:33:55 DEBUG : empty space: Unchanged skipping
2024/11/29 02:33:55 DEBUG : Local file system at /tmp/rclone4249100962: Waiting for transfers to finish
2024/11/29 02:33:55 DEBUG : Waiting for deletions to finish
2024/11/29 02:33:55 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncWithExclude (7.14s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:33:59 DEBUG : potato2: md5 = 658fdff03045ecaab26dbacf00b565d8 OK
2024/11/29 02:34:01 DEBUG : empty space: md5 = b40143d6c633921ed534a96f9ad1ee3e OK
2024/11/29 02:34:03 DEBUG : enormous: md5 = 559a3530aedb6dbdc8adbe84960765e1 OK
2024/11/29 02:34:03 DEBUG : enormous: Excluded (Size Filter)
2024/11/29 02:34:03 DEBUG : enormous: Excluded
2024/11/29 02:34:03 DEBUG : potato2: Excluded (Size Filter)
2024/11/29 02:34:03 DEBUG : potato2: Excluded
2024/11/29 02:34:04 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:34:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:34:04 DEBUG : empty space: Unchanged skipping
2024/11/29 02:34:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:34:04 DEBUG : Waiting for deletions to finish
2024/11/29 02:34:04 INFO  : enormous: Deleted
2024/11/29 02:34:04 INFO  : potato2: Deleted
2024/11/29 02:34:04 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:34:05 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/11/29 02:34:05 DEBUG : empty space: Unchanged skipping
2024/11/29 02:34:05 DEBUG : Local file system at /tmp/rclone4249100962: Waiting for checks to finish
2024/11/29 02:34:05 DEBUG : Local file system at /tmp/rclone4249100962: Waiting for transfers to finish
2024/11/29 02:34:05 DEBUG : Waiting for deletions to finish
2024/11/29 02:34:05 INFO  : potato2: Deleted
2024/11/29 02:34:05 INFO  : enormous: Deleted
2024/11/29 02:34:05 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (9.10s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:34:09 DEBUG : one: md5 = 318104debc55e1845f9a543ee3cd0878 OK
2024/11/29 02:34:10 DEBUG : two: md5 = dd283ca570e4c80376ac9a74ad3e9364 OK
2024/11/29 02:34:12 DEBUG : three: md5 = c8f3d5105a00ea8d4bed201cd70481ce OK
2024/11/29 02:34:13 DEBUG : four: md5 = 10624d2dc590d7d153914f7a8ca22733 OK
2024/11/29 02:34:14 DEBUG : five: Need to transfer - File not found at Destination
2024/11/29 02:34:14 DEBUG : four: Sizes differ (src 4 vs dst 8)
2024/11/29 02:34:14 DEBUG : one: Destination is newer than source, skipping
2024/11/29 02:34:14 DEBUG : three: Sizes identical
2024/11/29 02:34:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:34:14 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2024/11/29 02:34:14 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2024/11/29 02:34:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:34:15 DEBUG : four: md5 = b7aaada3acd835f4c6a7e5e00fbaf9b0 OK
2024/11/29 02:34:15 INFO  : four: Copied (replaced existing)
2024/11/29 02:34:15 DEBUG : two: md5 = a99cf58d789eb2dbf8ff84d9cf88bdc2 OK
2024/11/29 02:34:15 INFO  : two: Copied (replaced existing)
2024/11/29 02:34:16 DEBUG : five: md5 = 57cab45b321214d6fb6c3b91c098edeb OK
2024/11/29 02:34:16 INFO  : five: Copied (new)
2024/11/29 02:34:16 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (12.80s)
=== RUN   TestSyncWithMaxDuration
=== RUN   TestSyncWithMaxDuration/Hard
    sync_test.go:1466: Skipping test on non local remote
=== RUN   TestSyncWithMaxDuration/Soft
    sync_test.go:1466: Skipping test on non local remote
--- PASS: TestSyncWithMaxDuration (0.00s)
    --- SKIP: TestSyncWithMaxDuration/Hard (0.00s)
    --- SKIP: TestSyncWithMaxDuration/Soft (0.00s)
=== RUN   TestSyncWithTrackRenames
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2024/11/29 02:34:19 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Ignoring --track-renames as the source and destination do not have a common hash
2024/11/29 02:34:20 DEBUG : potato: Need to transfer - File not found at Destination
2024/11/29 02:34:20 DEBUG : yam: Need to transfer - File not found at Destination
2024/11/29 02:34:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:34:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:34:21 DEBUG : yam: md5 = cbba58fc25364a72f9b5f71a6df90a48 OK
2024/11/29 02:34:21 INFO  : yam: Copied (new)
2024/11/29 02:34:21 DEBUG : potato: md5 = aa672561a1bb7f5dbdd1a491843d5f67 OK
2024/11/29 02:34:21 INFO  : potato: Copied (new)
2024/11/29 02:34:21 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:34:22 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Ignoring --track-renames as the source and destination do not have a common hash
2024/11/29 02:34:22 DEBUG : yaml: Need to transfer - File not found at Destination
2024/11/29 02:34:22 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:34:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:34:22 DEBUG : potato: Unchanged skipping
2024/11/29 02:34:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:34:24 DEBUG : yaml: md5 = 710676ff7e8d4a815791773cddfa6be4 OK
2024/11/29 02:34:24 INFO  : yaml: Copied (new)
2024/11/29 02:34:24 DEBUG : Waiting for deletions to finish
2024/11/29 02:34:24 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (7.91s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2024/11/29 02:34:28 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Making map for --track-renames
2024/11/29 02:34:28 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Finished making map for --track-renames
2024/11/29 02:34:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:34:28 DEBUG : yam: Need to transfer - No matching file found at Destination
2024/11/29 02:34:28 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/11/29 02:34:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for renames to finish
2024/11/29 02:34:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:34:29 DEBUG : yam: md5 = 2cbebe4cbb74f8b0639f7fa4339ccd83 OK
2024/11/29 02:34:29 INFO  : yam: Copied (new)
2024/11/29 02:34:30 DEBUG : potato: md5 = 1854df57139d7379c684fab5552d99aa OK
2024/11/29 02:34:30 INFO  : potato: Copied (new)
2024/11/29 02:34:30 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:34:30 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:34:30 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Making map for --track-renames
2024/11/29 02:34:30 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Finished making map for --track-renames
2024/11/29 02:34:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:34:30 DEBUG : potato: Unchanged skipping
2024/11/29 02:34:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for renames to finish
2024/11/29 02:34:31 INFO  : yam: Moved (server-side) to: yaml
2024/11/29 02:34:31 INFO  : yaml: Renamed from "yam"
2024/11/29 02:34:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:34:31 DEBUG : Waiting for deletions to finish
2024/11/29 02:34:31 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (6.24s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2024/11/29 02:34:34 DEBUG : Added delayed dir = "sub", newDst=<nil>
2024/11/29 02:34:34 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Making map for --track-renames
2024/11/29 02:34:34 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Finished making map for --track-renames
2024/11/29 02:34:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:34:34 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/11/29 02:34:34 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2024/11/29 02:34:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for renames to finish
2024/11/29 02:34:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:34:37 DEBUG : potato: md5 = 1d0784b966d553a46b426ebb9833f759 OK
2024/11/29 02:34:37 INFO  : potato: Copied (new)
2024/11/29 02:34:37 DEBUG : sub/yam: md5 = 4bae887bf2975e662d79def156381ccf OK
2024/11/29 02:34:37 INFO  : sub/yam: Copied (new)
2024/11/29 02:34:37 DEBUG : Waiting for deletions to finish
2024/11/29 02:34:37 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:34:39 DEBUG : Added delayed dir = "sub", newDst=sub
2024/11/29 02:34:39 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:34:39 DEBUG : potato: Unchanged skipping
2024/11/29 02:34:39 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Making map for --track-renames
2024/11/29 02:34:39 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Finished making map for --track-renames
2024/11/29 02:34:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:34:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for renames to finish
2024/11/29 02:34:40 INFO  : sub/yam: Moved (server-side) to: yam
2024/11/29 02:34:40 INFO  : yam: Renamed from "sub/yam"
2024/11/29 02:34:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:34:40 DEBUG : Waiting for deletions to finish
2024/11/29 02:34:40 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (10.45s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:34:44 DEBUG : Creating backend with remote "/tmp/rclone4249100962/dir1"
2024/11/29 02:34:44 DEBUG : Creating backend with remote "/tmp/rclone4249100962/dir2"
2024/11/29 02:34:44 DEBUG : Local file system at /tmp/rclone4249100962/dir2: Using server-side directory move
2024/11/29 02:34:44 INFO  : Local file system at /tmp/rclone4249100962/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/29 02:34:44 DEBUG : file1.txt: Need to transfer - File not found at Destination
2024/11/29 02:34:44 INFO  : file1.txt: Moved (server-side)
2024/11/29 02:34:44 DEBUG : Local file system at /tmp/rclone4249100962/dir2: Waiting for checks to finish
2024/11/29 02:34:44 DEBUG : Local file system at /tmp/rclone4249100962/dir2: Waiting for transfers to finish
--- PASS: TestServerSideMoveLocal (0.51s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:34:45 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/11/29 02:34:45 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:34:45 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:34:45 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/11/29 02:34:45 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/11/29 02:34:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:34:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:34:48 DEBUG : sub dir/hello world: md5 = 553e3bef7a8d591735f15cd0e4630f96 OK
2024/11/29 02:34:48 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:34:48 INFO  : sub dir/hello world: Deleted
2024/11/29 02:34:51 DEBUG : nested/sub dir/file: md5 = abf1ce2bcdb7bb20ab9b4ec39c61a9ce OK
2024/11/29 02:34:51 INFO  : nested/sub dir/file: Copied (new)
2024/11/29 02:34:51 INFO  : nested/sub dir/file: Deleted
2024/11/29 02:34:52 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:34:52 INFO  : nested: Set directory modification time (using DirSetModTime)
2024/11/29 02:34:52 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:34:52 INFO  : sub dir: Removing directory
2024/11/29 02:34:52 INFO  : nested/sub dir: Removing directory
2024/11/29 02:34:52 INFO  : nested: Removing directory
2024/11/29 02:34:52 DEBUG : Local file system at /tmp/rclone4249100962: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:34:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/29 02:34:56 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/11/29 02:34:57 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (13.80s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:34:59 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/11/29 02:34:59 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:34:59 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/11/29 02:34:59 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:34:59 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/11/29 02:34:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:34:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:35:01 DEBUG : sub dir/hello world: md5 = eb11ee5b6d94b3a6d82f740bd54e6e07 OK
2024/11/29 02:35:01 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:35:01 INFO  : sub dir/hello world: Deleted
2024/11/29 02:35:04 DEBUG : nested/sub dir/file: md5 = f6101ecf3597ff064a46e65ae51ca6be OK
2024/11/29 02:35:04 INFO  : nested/sub dir/file: Copied (new)
2024/11/29 02:35:04 INFO  : nested/sub dir/file: Deleted
2024/11/29 02:35:05 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:35:05 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:35:06 INFO  : nested: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:35:08 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/29 02:35:09 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/11/29 02:35:10 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (13.30s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:35:12 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/29 02:35:12 DEBUG : existing-b: Need to transfer - File not found at Destination
2024/11/29 02:35:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:35:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:35:14 DEBUG : existing: md5 = 5846d55bf5acdeb7b7335a21a4ed7d77 OK
2024/11/29 02:35:14 INFO  : existing: Copied (new)
2024/11/29 02:35:14 INFO  : existing: Deleted
2024/11/29 02:35:14 DEBUG : existing-b: md5 = fe1f10d8bb5a8b5059f7cdc566791a2b OK
2024/11/29 02:35:14 INFO  : existing-b: Copied (new)
2024/11/29 02:35:14 INFO  : existing-b: Deleted
2024/11/29 02:35:14 DEBUG : existing: Destination exists, skipping
2024/11/29 02:35:14 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2024/11/29 02:35:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:35:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:35:14 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (4.92s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:35:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dimoqid4suxe"
2024/11/29 02:35:17 DEBUG : Creating backend with remote "TestDrive:crypt/42odrgkco52ldrfb5scjaransmfvc8tk4cqosop3kfmv8ku46l5g"
2024/11/29 02:35:19 DEBUG : potato2: md5 = 97f6cec23a02b56f2173b42b2aecec4c OK
2024/11/29 02:35:21 DEBUG : empty space: md5 = 45df6c45bd2b3ee13aa98c362969e76b OK
2024/11/29 02:35:23 DEBUG : potato3: md5 = 61ad9ae8204d48618cac0313f35140bd OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci' -> Encrypted drive 'TestCryptDrive:rclone-test-dimoqid4suxe'
2024/11/29 02:35:26 DEBUG : empty space: md5 = 26a94565b6790541377ac70c0c709cb9 OK
2024/11/29 02:35:28 DEBUG : potato3: md5 = d1a025d9c72cd236a01377c7b6cecb1a OK
2024/11/29 02:35:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dimoqid4suxe': Using server-side directory move
2024/11/29 02:35:28 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-dimoqid4suxe': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/29 02:35:28 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:35:28 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/11/29 02:35:28 DEBUG : empty space: Unchanged skipping
2024/11/29 02:35:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dimoqid4suxe': Waiting for checks to finish
2024/11/29 02:35:28 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/29 02:35:29 INFO  : empty space: Deleted
2024/11/29 02:35:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dimoqid4suxe': Waiting for transfers to finish
2024/11/29 02:35:29 INFO  : potato3: Deleted
2024/11/29 02:35:29 INFO  : potato2: Moved (server-side)
2024/11/29 02:35:30 INFO  : potato3: Moved (server-side)
2024/11/29 02:35:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mowixif3mixo"
2024/11/29 02:35:30 DEBUG : Creating backend with remote "TestDrive:crypt/279rsobqo44uaecqnso9f95tfvr72ngmp2mqvd0a98tcq8cag2h0"
2024/11/29 02:35:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mowixif3mixo': Using server-side directory move
2024/11/29 02:35:32 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mowixif3mixo': Server side directory move succeeded
2024/11/29 02:35:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mowixif3mixo': Purge remote
2024/11/29 02:35:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dimoqid4suxe': Purge remote
2024/11/29 02:35:34 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (18.12s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:35:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-garujey1huza"
2024/11/29 02:35:35 DEBUG : Creating backend with remote "TestDrive:crypt/884iipo2jqffltbe78h92nksttjiuaqtjkjikj5uavqgd6oph050"
2024/11/29 02:35:38 DEBUG : potato2: md5 = 1c0570fb20489bcc6db6bcccdff13b7d OK
2024/11/29 02:35:39 DEBUG : empty space: md5 = cc6e09a6f3eed1b28052e5ecd0fdd6d3 OK
2024/11/29 02:35:41 DEBUG : potato3: md5 = dedf8fbb0c61ad0abc3d849e9902a29f OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci' -> Encrypted drive 'TestCryptDrive:rclone-test-garujey1huza'
2024/11/29 02:35:44 DEBUG : empty space: md5 = 034d69649806268e13800f57d123c091 OK
2024/11/29 02:35:46 DEBUG : potato3: md5 = 91544ef21f9ba4df58bc13df6cd1afb2 OK
2024/11/29 02:35:46 DEBUG : empty space: Excluded (Size Filter)
2024/11/29 02:35:46 DEBUG : empty space: Excluded (Size Filter)
2024/11/29 02:35:46 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:35:46 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/29 02:35:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-garujey1huza': Waiting for checks to finish
2024/11/29 02:35:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-garujey1huza': Waiting for transfers to finish
2024/11/29 02:35:47 INFO  : potato3: Deleted
2024/11/29 02:35:47 INFO  : potato2: Moved (server-side)
2024/11/29 02:35:48 INFO  : potato3: Moved (server-side)
2024/11/29 02:35:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bifomig5xugo"
2024/11/29 02:35:48 DEBUG : Creating backend with remote "TestDrive:crypt/rt9efl7h2790b21j1q337djvb08j1ic4qvg8sekmngmrn02q52hg"
2024/11/29 02:35:50 DEBUG : empty space: Excluded (Size Filter)
2024/11/29 02:35:50 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:35:50 DEBUG : potato3: Need to transfer - File not found at Destination
2024/11/29 02:35:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bifomig5xugo': Waiting for checks to finish
2024/11/29 02:35:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bifomig5xugo': Waiting for transfers to finish
2024/11/29 02:35:52 INFO  : potato2: Moved (server-side)
2024/11/29 02:35:52 INFO  : potato3: Moved (server-side)
2024/11/29 02:35:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bifomig5xugo': Purge remote
2024/11/29 02:35:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-garujey1huza': Purge remote
--- PASS: TestServerSideMoveWithFilter (20.19s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:35:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fucacoq5nefi"
2024/11/29 02:35:55 DEBUG : Creating backend with remote "TestDrive:crypt/s870sn376io03sq7qs12gj2ilkafga1qadelcar9c00kvot4i2e0"
2024/11/29 02:35:58 DEBUG : potato2: md5 = 9fe658d17a57d1a92a4fb83767d97b3e OK
2024/11/29 02:35:59 DEBUG : empty space: md5 = 30254c01fcd457fb552f369efdf02680 OK
2024/11/29 02:36:01 DEBUG : potato3: md5 = 829790846b76b68b293a9ac4df2fcb70 OK
2024/11/29 02:36:01 DEBUG : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci' -> Encrypted drive 'TestCryptDrive:rclone-test-fucacoq5nefi'
2024/11/29 02:36:05 DEBUG : empty space: md5 = 214787fa33f033614549569eae03fa11 OK
2024/11/29 02:36:07 DEBUG : potato3: md5 = 036648edb6af6d6b30992d390a5afcf7 OK
2024/11/29 02:36:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fucacoq5nefi': Using server-side directory move
2024/11/29 02:36:07 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-fucacoq5nefi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/29 02:36:08 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:36:08 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2024/11/29 02:36:08 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/11/29 02:36:08 DEBUG : empty space: Unchanged skipping
2024/11/29 02:36:08 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/29 02:36:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fucacoq5nefi': Waiting for checks to finish
2024/11/29 02:36:08 INFO  : empty space: Deleted
2024/11/29 02:36:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fucacoq5nefi': Waiting for transfers to finish
2024/11/29 02:36:09 INFO  : potato2: Moved (server-side)
2024/11/29 02:36:09 INFO  : potato3: Deleted
2024/11/29 02:36:10 INFO  : potato3: Moved (server-side)
2024/11/29 02:36:10 INFO  : tomatoDir: Removing directory
2024/11/29 02:36:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': deleted 1 directories
2024/11/29 02:36:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qepezuk9ximo"
2024/11/29 02:36:11 DEBUG : Creating backend with remote "TestDrive:crypt/2ii310lud978flrhvf2hev5t1up7276qk5530kn2ert463t40eig"
2024/11/29 02:36:13 DEBUG : tomatoDir: Making directory
2024/11/29 02:36:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qepezuk9ximo': Using server-side directory move
2024/11/29 02:36:14 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-qepezuk9ximo': Server side directory move succeeded
2024/11/29 02:36:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qepezuk9ximo': Purge remote
2024/11/29 02:36:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fucacoq5nefi': Purge remote
2024/11/29 02:36:17 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (22.38s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.46s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:36:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/rclone-sync-test"
2024/11/29 02:36:18 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncOverlap (4.06s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:36:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/rclone-sync-test"
2024/11/29 02:36:22 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2024/11/29 02:36:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/rclone-sync-test-include/layer2"
2024/11/29 02:36:24 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2024/11/29 02:36:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/rclone-sync-test-ignore-file"
2024/11/29 02:36:28 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2024/11/29 02:36:32 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 8b56687c368c811bfdaa279ea6ae3f6a OK
2024/11/29 02:36:35 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/29 02:36:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/rclone-sync-test': Waiting for checks to finish
2024/11/29 02:36:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/rclone-sync-test': Waiting for transfers to finish
2024/11/29 02:36:35 DEBUG : Waiting for deletions to finish
2024/11/29 02:36:35 INFO  : There was nothing to transfer
2024/11/29 02:36:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:36:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:36:36 DEBUG : Waiting for deletions to finish
2024/11/29 02:36:36 INFO  : rclone-sync-test-include: Removing directory
2024/11/29 02:36:37 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/29 02:36:37 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/11/29 02:36:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': failed to delete 1 directories
2024/11/29 02:36:37 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:36:39 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/29 02:36:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/rclone-sync-test-include/layer2': Waiting for checks to finish
2024/11/29 02:36:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/rclone-sync-test-include/layer2': Waiting for transfers to finish
2024/11/29 02:36:39 DEBUG : Waiting for deletions to finish
2024/11/29 02:36:39 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:36:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:36:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:36:41 DEBUG : Waiting for deletions to finish
2024/11/29 02:36:41 INFO  : rclone-sync-test-include: Removing directory
2024/11/29 02:36:41 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/29 02:36:41 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/11/29 02:36:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': failed to delete 1 directories
2024/11/29 02:36:41 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:36:43 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/29 02:36:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/rclone-sync-test-ignore-file': Waiting for checks to finish
2024/11/29 02:36:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/rclone-sync-test-ignore-file': Waiting for transfers to finish
2024/11/29 02:36:43 DEBUG : Waiting for deletions to finish
2024/11/29 02:36:43 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:36:45 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/29 02:36:46 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (34.13s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:36:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/dst"
2024/11/29 02:36:56 DEBUG : Config file has changed externally - reloading
2024/11/29 02:36:56 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/29 02:36:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/CompareDest"
2024/11/29 02:36:58 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/gveqi14airsml4bgu7krj116o8"
2024/11/29 02:37:00 DEBUG : one: Need to transfer - File not found at Destination
2024/11/29 02:37:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:37:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:37:03 DEBUG : one: md5 = a72728033f92a75dbea8556d47b51d46 OK
2024/11/29 02:37:03 INFO  : one: Copied (new)
2024/11/29 02:37:03 DEBUG : Waiting for deletions to finish
2024/11/29 02:37:04 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/29 02:37:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:37:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:37:06 DEBUG : one: md5 = 3dcfa17d45efc30f38df65f8c4a4515b OK
2024/11/29 02:37:06 INFO  : one: Copied (replaced existing)
2024/11/29 02:37:06 DEBUG : Waiting for deletions to finish
2024/11/29 02:37:08 DEBUG : dst/one: md5 = db0d2caca3e963f302820e8f35e68989 OK
2024/11/29 02:37:11 DEBUG : CompareDest/one: md5 = c53cec1f8a1044b0cdc4e0814c762839 OK
2024/11/29 02:37:11 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/29 02:37:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:37:12 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:37:12 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/29 02:37:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:37:12 DEBUG : Waiting for deletions to finish
2024/11/29 02:37:12 INFO  : There was nothing to transfer
2024/11/29 02:37:14 DEBUG : CompareDest/two: md5 = 525692fa1476fa512c384febbbdcb1fe OK
2024/11/29 02:37:15 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:37:15 DEBUG : two: Destination found in --compare-dest, skipping
2024/11/29 02:37:15 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/29 02:37:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:37:15 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:37:15 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/29 02:37:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:37:15 DEBUG : Waiting for deletions to finish
2024/11/29 02:37:15 INFO  : There was nothing to transfer
2024/11/29 02:37:16 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:37:16 DEBUG : two: Destination found in --compare-dest, skipping
2024/11/29 02:37:16 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/29 02:37:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:37:17 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:37:17 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/29 02:37:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:37:17 DEBUG : Waiting for deletions to finish
2024/11/29 02:37:17 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2024/11/29 02:37:18 DEBUG : two: Sizes differ (src 5 vs dst 3)
2024/11/29 02:37:18 DEBUG : two: Need to transfer - File not found at Destination
2024/11/29 02:37:18 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/29 02:37:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:37:19 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:37:19 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/29 02:37:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:37:20 DEBUG : two: md5 = b9562d6f3245d810f66e9f20fa6c2c78 OK
2024/11/29 02:37:20 INFO  : two: Copied (new)
2024/11/29 02:37:20 DEBUG : Waiting for deletions to finish
2024/11/29 02:37:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:37:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:37:24 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:37:24 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCompareDest (29.37s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:37:28 DEBUG : pre-dest1/1: md5 = b593612cd44fdd9186db7e73db026f71 OK
2024/11/29 02:37:31 DEBUG : pre-dest2/2: md5 = 37314cf9599dfbe3e221cb32280b796a OK
2024/11/29 02:37:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/dest"
2024/11/29 02:37:31 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/rg03c1jvnehrrc617i0lnqjddc"
2024/11/29 02:37:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/pre-dest1"
2024/11/29 02:37:33 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/bbnblvh6k061ssopqrp18kd7gc"
2024/11/29 02:37:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/pre-dest2"
2024/11/29 02:37:34 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/dgicm1h6b5ejvlltm8eeif0bnk"
2024/11/29 02:37:35 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:37:35 DEBUG : 1: Destination found in --compare-dest, skipping
2024/11/29 02:37:36 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:37:36 DEBUG : 2: Destination found in --compare-dest, skipping
2024/11/29 02:37:36 DEBUG : 3: Need to transfer - File not found at Destination
2024/11/29 02:37:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dest': Waiting for checks to finish
2024/11/29 02:37:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dest': Waiting for transfers to finish
2024/11/29 02:37:39 DEBUG : 3: md5 = a36b3df769a9d6d6e8e0129411d43298 OK
2024/11/29 02:37:39 INFO  : 3: Copied (new)
2024/11/29 02:37:39 DEBUG : Waiting for deletions to finish
2024/11/29 02:37:42 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2024/11/29 02:37:43 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2024/11/29 02:37:44 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (19.74s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:37:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/dst"
2024/11/29 02:37:45 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/29 02:37:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/CopyDest"
2024/11/29 02:37:47 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/d09o6po3f7bm6ce32vdgs8h9ls"
2024/11/29 02:37:49 DEBUG : one: Need to transfer - File not found at Destination
2024/11/29 02:37:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:37:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:37:51 DEBUG : one: md5 = 4151c5467372b6e073b6e23df76c7382 OK
2024/11/29 02:37:51 INFO  : one: Copied (new)
2024/11/29 02:37:51 DEBUG : Waiting for deletions to finish
2024/11/29 02:37:53 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/29 02:37:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:37:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:37:54 DEBUG : one: md5 = f4931d3e86a66af0ed4a6e35a557c490 OK
2024/11/29 02:37:54 INFO  : one: Copied (replaced existing)
2024/11/29 02:37:54 DEBUG : Waiting for deletions to finish
2024/11/29 02:37:56 DEBUG : dst/one: md5 = a27c36d804183daa7bc4245d7efc0e2d OK
2024/11/29 02:37:59 DEBUG : CopyDest/one: md5 = 52512eefe2cf38304bef505cb712a78b OK
2024/11/29 02:38:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/BackupDir"
2024/11/29 02:38:00 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/s6dbk3lfi7c9kfvo6j7bla9m0g"
2024/11/29 02:38:02 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/29 02:38:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:38:02 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:38:02 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/29 02:38:05 INFO  : one: Moved (server-side)
2024/11/29 02:38:06 INFO  : one: Copied (server-side copy)
2024/11/29 02:38:06 DEBUG : one: Destination found in --copy-dest, using server-side copy
2024/11/29 02:38:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:38:06 DEBUG : Waiting for deletions to finish
2024/11/29 02:38:08 DEBUG : CopyDest/two: md5 = c6a831ef69c50cc234a90a9e40590620 OK
2024/11/29 02:38:09 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:38:11 INFO  : two: Copied (server-side copy)
2024/11/29 02:38:11 DEBUG : two: Destination found in --copy-dest, using server-side copy
2024/11/29 02:38:11 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:38:11 DEBUG : one: Unchanged skipping
2024/11/29 02:38:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:38:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:38:11 DEBUG : Waiting for deletions to finish
2024/11/29 02:38:11 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:38:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:38:11 DEBUG : one: Unchanged skipping
2024/11/29 02:38:11 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:38:11 DEBUG : two: Unchanged skipping
2024/11/29 02:38:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:38:11 DEBUG : Waiting for deletions to finish
2024/11/29 02:38:11 INFO  : There was nothing to transfer
2024/11/29 02:38:14 DEBUG : CopyDest/three: md5 = 548767f38fdb57b88376cf68fd196576 OK
2024/11/29 02:38:15 DEBUG : three: Sizes differ (src 7 vs dst 5)
2024/11/29 02:38:15 DEBUG : three: Destination not found in --copy-dest
2024/11/29 02:38:15 DEBUG : three: Need to transfer - File not found at Destination
2024/11/29 02:38:15 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:38:15 DEBUG : one: Unchanged skipping
2024/11/29 02:38:15 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:38:15 DEBUG : two: Unchanged skipping
2024/11/29 02:38:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:38:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:38:16 DEBUG : three: md5 = 9413a6e73ba69991c35a97e3b7eea927 OK
2024/11/29 02:38:16 INFO  : three: Copied (new)
2024/11/29 02:38:16 DEBUG : Waiting for deletions to finish
2024/11/29 02:38:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/11/29 02:38:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:38:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:38:23 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:38:23 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:38:23 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/11/29 02:38:24 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (39.45s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:38:27 DEBUG : dst/one: md5 = 951cdafc0b46e71d6cc0ad5c2dbefbad OK
2024/11/29 02:38:29 DEBUG : dst/two: md5 = 218cbbed2e3cdecff59e9587bfa69840 OK
2024/11/29 02:38:31 DEBUG : dst/three.txt: md5 = a617e862d3a775e99ae389e2762309c8 OK
2024/11/29 02:38:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/dst"
2024/11/29 02:38:31 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/29 02:38:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/backup"
2024/11/29 02:38:32 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/1nrff024r7pq65ecp72fc28jb0"
2024/11/29 02:38:34 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/29 02:38:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:38:34 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:38:34 DEBUG : two: Unchanged skipping
2024/11/29 02:38:36 INFO  : one: Moved (server-side)
2024/11/29 02:38:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:38:38 DEBUG : one: md5 = fe94fe120574bf6c721bd9596c8629f3 OK
2024/11/29 02:38:38 INFO  : one: Copied (new)
2024/11/29 02:38:38 DEBUG : Waiting for deletions to finish
2024/11/29 02:38:39 INFO  : three.txt: Moved (server-side)
2024/11/29 02:38:39 INFO  : three.txt: Moved into backup dir
2024/11/29 02:38:42 DEBUG : dst/three.txt: md5 = f9a9df62b494dab9e38e755aafd93035 OK
2024/11/29 02:38:42 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/29 02:38:42 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:38:42 DEBUG : two: Unchanged skipping
2024/11/29 02:38:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:38:43 INFO  : one: Deleted
2024/11/29 02:38:44 INFO  : one: Moved (server-side)
2024/11/29 02:38:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:38:46 DEBUG : one: md5 = 78da2c5cd184af1b717efa173f9a97db OK
2024/11/29 02:38:46 INFO  : one: Copied (new)
2024/11/29 02:38:46 DEBUG : Waiting for deletions to finish
2024/11/29 02:38:47 INFO  : three.txt: Deleted
2024/11/29 02:38:48 INFO  : three.txt: Moved (server-side)
2024/11/29 02:38:48 INFO  : three.txt: Moved into backup dir
2024/11/29 02:38:52 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:38:52 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:38:53 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:38:53 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/29 02:38:53 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:38:53 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
--- PASS: TestSyncBackupDir (28.99s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:38:56 DEBUG : dst/one: md5 = ac7bfefbe1615abc100a190e0ac45bc6 OK
2024/11/29 02:38:58 DEBUG : dst/two: md5 = dbc61b3de2842d9a14c2e4510615190f OK
2024/11/29 02:39:00 DEBUG : dst/three.txt: md5 = c2f33b59e18df9d0cbdb76f437f294f4 OK
2024/11/29 02:39:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/dst"
2024/11/29 02:39:00 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/29 02:39:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/backup"
2024/11/29 02:39:01 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/1nrff024r7pq65ecp72fc28jb0"
2024/11/29 02:39:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:39:03 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/29 02:39:03 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:39:03 DEBUG : two: Unchanged skipping
2024/11/29 02:39:05 INFO  : one: Moved (server-side) to: one.bak
2024/11/29 02:39:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:39:07 DEBUG : one: md5 = ed356f2e85b1569cc4af89c17b2eab60 OK
2024/11/29 02:39:07 INFO  : one: Copied (new)
2024/11/29 02:39:07 DEBUG : Waiting for deletions to finish
2024/11/29 02:39:09 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/29 02:39:09 INFO  : three.txt: Moved into backup dir
2024/11/29 02:39:11 DEBUG : dst/three.txt: md5 = 0a8109e4b22de6ce2688882062b5e343 OK
2024/11/29 02:39:11 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/29 02:39:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:39:11 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:39:11 DEBUG : two: Unchanged skipping
2024/11/29 02:39:12 INFO  : one.bak: Deleted
2024/11/29 02:39:13 INFO  : one: Moved (server-side) to: one.bak
2024/11/29 02:39:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:39:15 DEBUG : one: md5 = 462f9d51f0f9eaed7860ef56db8c9731 OK
2024/11/29 02:39:15 INFO  : one: Copied (new)
2024/11/29 02:39:15 DEBUG : Waiting for deletions to finish
2024/11/29 02:39:16 INFO  : three.txt.bak: Deleted
2024/11/29 02:39:17 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/29 02:39:17 INFO  : three.txt: Moved into backup dir
2024/11/29 02:39:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:39:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:39:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/29 02:39:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/29 02:39:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/29 02:39:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirWithSuffix (28.76s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:39:25 DEBUG : dst/one: md5 = afa0ef6dbcc55a8c2c867b7835c6cd38 OK
2024/11/29 02:39:27 DEBUG : dst/two: md5 = 63a47d81c7f95844e7a3b3e7139f4f87 OK
2024/11/29 02:39:29 DEBUG : dst/three.txt: md5 = de28ac968aa75e0c486de293884a8a9e OK
2024/11/29 02:39:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/dst"
2024/11/29 02:39:29 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/29 02:39:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/backup"
2024/11/29 02:39:30 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/1nrff024r7pq65ecp72fc28jb0"
2024/11/29 02:39:32 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/29 02:39:32 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:39:32 DEBUG : two: Unchanged skipping
2024/11/29 02:39:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:39:35 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/29 02:39:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:39:36 DEBUG : one: md5 = eadf811c8f680d23cd3ca6766be38a55 OK
2024/11/29 02:39:36 INFO  : one: Copied (new)
2024/11/29 02:39:36 DEBUG : Waiting for deletions to finish
2024/11/29 02:39:37 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/29 02:39:37 INFO  : three.txt: Moved into backup dir
2024/11/29 02:39:40 DEBUG : dst/three.txt: md5 = cc4e27a92ed0fe5fd8d8bb25633aafd3 OK
2024/11/29 02:39:40 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/29 02:39:40 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:39:40 DEBUG : two: Unchanged skipping
2024/11/29 02:39:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:39:41 INFO  : one-2019-01-01: Deleted
2024/11/29 02:39:42 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/29 02:39:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:39:44 DEBUG : one: md5 = 403b401657cce8d811adf659b8d810a3 OK
2024/11/29 02:39:44 INFO  : one: Copied (new)
2024/11/29 02:39:44 DEBUG : Waiting for deletions to finish
2024/11/29 02:39:45 INFO  : three-2019-01-01.txt: Deleted
2024/11/29 02:39:45 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/29 02:39:45 INFO  : three.txt: Moved into backup dir
2024/11/29 02:39:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:39:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:39:50 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/29 02:39:50 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/29 02:39:50 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/29 02:39:50 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (28.84s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:39:54 DEBUG : dst/one: md5 = d86c63add120dabc3f1bb08574f69b79 OK
2024/11/29 02:39:56 DEBUG : dst/two: md5 = 6df6a127ec9c8d54290286e2f22516e6 OK
2024/11/29 02:39:57 DEBUG : dst/three.txt: md5 = cbdc80fd45c085a7b74fdf79d34ad427 OK
2024/11/29 02:39:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/dst"
2024/11/29 02:39:58 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/29 02:39:59 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/29 02:39:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:39:59 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:39:59 DEBUG : two: Unchanged skipping
2024/11/29 02:40:00 INFO  : one: Moved (server-side) to: one.bak
2024/11/29 02:40:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:40:02 DEBUG : one: md5 = e970725fcca7a398980ce91a5b4b3751 OK
2024/11/29 02:40:02 INFO  : one: Copied (new)
2024/11/29 02:40:02 DEBUG : Waiting for deletions to finish
2024/11/29 02:40:03 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/29 02:40:03 INFO  : three.txt: Moved into backup dir
2024/11/29 02:40:05 DEBUG : dst/three.txt: md5 = cfdf086b077335647ce90b61c66ea917 OK
2024/11/29 02:40:06 DEBUG : one.bak: Excluded (Path Filter)
2024/11/29 02:40:06 DEBUG : three.txt.bak: Excluded (Path Filter)
2024/11/29 02:40:06 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/29 02:40:06 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:40:06 DEBUG : two: Unchanged skipping
2024/11/29 02:40:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for checks to finish
2024/11/29 02:40:06 INFO  : one.bak: Deleted
2024/11/29 02:40:07 INFO  : one: Moved (server-side) to: one.bak
2024/11/29 02:40:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci/dst': Waiting for transfers to finish
2024/11/29 02:40:09 DEBUG : one: md5 = 5492134a7d73f4023f513c55cf3b13be OK
2024/11/29 02:40:09 INFO  : one: Copied (new)
2024/11/29 02:40:09 DEBUG : Waiting for deletions to finish
2024/11/29 02:40:10 INFO  : three.txt.bak: Deleted
2024/11/29 02:40:10 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/29 02:40:10 INFO  : three.txt: Moved into backup dir
2024/11/29 02:40:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:40:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/29 02:40:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/29 02:40:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/29 02:40:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/29 02:40:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncBackupDirSuffixOnly (23.88s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:40:18 DEBUG : dst/one: md5 = 36d1a1e321645e3186ec45235e0a772f OK
2024/11/29 02:40:19 DEBUG : dst/two: md5 = 39212e8ed4663f10afc93bf9c467b540 OK
2024/11/29 02:40:21 DEBUG : dst/three.txt: md5 = 93180dc2453f0b199ddaf0fa05e46ec1 OK
2024/11/29 02:40:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/dst"
2024/11/29 02:40:21 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/29 02:40:23 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/29 02:40:23 INFO  : one: Moved (server-side) to: one.bak
2024/11/29 02:40:25 DEBUG : one: md5 = 1b1f2ff50d89ad5dbbcee91c4c385e71 OK
2024/11/29 02:40:25 INFO  : one: Copied (new)
2024/11/29 02:40:25 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:40:25 DEBUG : two: Unchanged skipping
2024/11/29 02:40:26 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/11/29 02:40:27 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/29 02:40:28 DEBUG : three.txt: md5 = c73464e32fa43621034e8f961eaaa1f2 OK
2024/11/29 02:40:28 INFO  : three.txt: Copied (new)
2024/11/29 02:40:30 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/29 02:40:31 INFO  : one.bak: Deleted
2024/11/29 02:40:31 INFO  : one: Moved (server-side) to: one.bak
2024/11/29 02:40:33 DEBUG : one: md5 = ed97046430841fa953bf31af721cd1c8 OK
2024/11/29 02:40:33 INFO  : one: Copied (new)
2024/11/29 02:40:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:40:33 DEBUG : two: Unchanged skipping
2024/11/29 02:40:34 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/11/29 02:40:34 INFO  : three.txt.bak: Deleted
2024/11/29 02:40:35 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/29 02:40:37 DEBUG : three.txt: md5 = 7cbfb78b0acd64c4e67e627bb82f5c07 OK
2024/11/29 02:40:37 INFO  : three.txt: Copied (new)
2024/11/29 02:40:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:40:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/29 02:40:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/29 02:40:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/29 02:40:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:40:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/29 02:40:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncSuffix (27.06s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:40:45 DEBUG : dst/one: md5 = d989602784694fd759ddb3f82937f2c1 OK
2024/11/29 02:40:46 DEBUG : dst/two: md5 = 2c2df27ce48898516ab5cf912ef8a0a8 OK
2024/11/29 02:40:48 DEBUG : dst/three.txt: md5 = ea2b0ae39d1fe8146d10a261ee081685 OK
2024/11/29 02:40:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lakiyim9hoci/dst"
2024/11/29 02:40:49 DEBUG : Creating backend with remote "TestDrive:crypt/ah5erg465so353qg8iqfebq8mjafte2mefamivi6ffd9tj35jsvg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/29 02:40:50 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/29 02:40:51 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/29 02:40:52 DEBUG : one: md5 = 659a3b2ff2ceae14328f19acde031e35 OK
2024/11/29 02:40:52 INFO  : one: Copied (new)
2024/11/29 02:40:52 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:40:52 DEBUG : two: Unchanged skipping
2024/11/29 02:40:53 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/11/29 02:40:54 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/29 02:40:55 DEBUG : three.txt: md5 = 2fc30ac93dd7484c6f66bcb022c7cab5 OK
2024/11/29 02:40:55 INFO  : three.txt: Copied (new)
2024/11/29 02:40:57 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/29 02:40:58 INFO  : one-2019-01-01: Deleted
2024/11/29 02:40:59 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/29 02:41:00 DEBUG : one: md5 = e1168d53a198a23f7c59f3dc9ff01274 OK
2024/11/29 02:41:00 INFO  : one: Copied (new)
2024/11/29 02:41:01 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:41:01 DEBUG : two: Unchanged skipping
2024/11/29 02:41:01 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/11/29 02:41:02 INFO  : three-2019-01-01.txt: Deleted
2024/11/29 02:41:02 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/29 02:41:04 DEBUG : three.txt: md5 = 6abb9799420dd74c315f4a9a442f47d7 OK
2024/11/29 02:41:04 INFO  : three.txt: Copied (new)
2024/11/29 02:41:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:41:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/29 02:41:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/29 02:41:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/29 02:41:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/29 02:41:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:41:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncSuffixKeepExtension (27.53s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:41:11 DEBUG : Testêé: md5 = 0c746052ad4ee2275cebfa3efb115984 OK
2024/11/29 02:41:12 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2024/11/29 02:41:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:41:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:41:13 DEBUG : Testêé: md5 = 03f04f90559b2feef8f98bc9dccdfa47 OK
2024/11/29 02:41:13 INFO  : Testêé: Copied (replaced existing) to: Testêé
2024/11/29 02:41:13 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (5.21s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:41:15 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/29 02:41:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:41:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:41:17 DEBUG : existing: md5 = bfbc0826f467372d4a34bd7e70ce7271 OK
2024/11/29 02:41:17 INFO  : existing: Copied (new)
2024/11/29 02:41:17 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:41:18 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2024/11/29 02:41:18 ERROR : existing: Source and destination exist but do not match: immutable file modified
2024/11/29 02:41:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:41:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:41:18 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': not deleting files as there were IO errors
2024/11/29 02:41:18 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncImmutable (5.65s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:41:22 DEBUG : EXISTING: md5 = 226b71e5cd973a4ed45fb7c14c0616ff OK
2024/11/29 02:41:23 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:41:23 DEBUG : existing: Unchanged skipping
2024/11/29 02:41:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:41:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:41:23 DEBUG : Waiting for deletions to finish
2024/11/29 02:41:23 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (4.38s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.48s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", 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-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", 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-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.43s)
    --- SKIP: TestMaxTransfer/Hard (0.47s)
    --- SKIP: TestMaxTransfer/Soft (0.47s)
    --- SKIP: TestMaxTransfer/Cautious (0.49s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:41:29 DEBUG : both0: md5 = 6037427edd13d4ae5e516b1eb2fefdfb OK
2024/11/29 02:41:30 DEBUG : only0: md5 = b160b6a91be086631c32c3c72dbe2b1f OK
2024/11/29 02:41:32 DEBUG : both1: md5 = 7d26f396cc16ba3baec2ffec86fb2094 OK
2024/11/29 02:41:34 DEBUG : only1: md5 = 9678c13a17800c7907e071c0044057bb OK
2024/11/29 02:41:35 DEBUG : both2: md5 = 3bb45cb89771ea203c4e4cc5772e7727 OK
2024/11/29 02:41:37 DEBUG : only2: md5 = 2f07c767e660ce9c524dda20b113df46 OK
2024/11/29 02:41:39 DEBUG : both3: md5 = ed6bf3525423ed00e987d851f50a104f OK
2024/11/29 02:41:41 DEBUG : only3: md5 = 2486e51e290736b130ea2063c6fe378b OK
2024/11/29 02:41:43 DEBUG : both4: md5 = 2c71106d7f74d6879e6e2e241d600603 OK
2024/11/29 02:41:44 DEBUG : only4: md5 = 4d1a8e89a28e5cf6596f3dba9009a96a OK
2024/11/29 02:41:46 DEBUG : both5: md5 = a178e0749a8896ebb9a6b5c83d751123 OK
2024/11/29 02:41:48 DEBUG : only5: md5 = 2dade7b9febb437d8357dee106be5735 OK
2024/11/29 02:41:49 DEBUG : both6: md5 = 4969374bd5afb90e1a17f6cd5f812e7f OK
2024/11/29 02:41:51 DEBUG : only6: md5 = 5396dd6b656258d075a6530d1c8ecc0f OK
2024/11/29 02:41:53 DEBUG : both7: md5 = 1787c667e971f5505cfd9cbcef07b29f OK
2024/11/29 02:41:55 DEBUG : only7: md5 = dfd0d24bef7e989090f8829a4861fc3b OK
2024/11/29 02:41:56 DEBUG : both8: md5 = 0337045fd81983ece3cf12f636c04625 OK
2024/11/29 02:41:58 DEBUG : only8: md5 = 260ddf38b83bc5c611122062ada22d46 OK
2024/11/29 02:42:00 DEBUG : both9: md5 = c91d446505e2c8837a1b90965a1235b0 OK
2024/11/29 02:42:01 DEBUG : only9: md5 = 63569cc2ddb0e593fe82ca0bc9e2a83a OK
2024/11/29 02:42:03 DEBUG : both10: md5 = a2131f631efdd62a0aac92421b907b7e OK
2024/11/29 02:42:05 DEBUG : only10: md5 = 06c240ff88f4e63e04c70487f4be37d0 OK
2024/11/29 02:42:07 DEBUG : both11: md5 = 4944d70701957c3987e20bf75fad5f7e OK
2024/11/29 02:42:08 DEBUG : only11: md5 = 6dad35e6382971ab2a0e02450aaf24aa OK
2024/11/29 02:42:10 DEBUG : both12: md5 = bdad2af1cc66a2d5857215bf5206be24 OK
2024/11/29 02:42:11 DEBUG : only12: md5 = b58c1260bd300b7b295693a85881bdcc OK
2024/11/29 02:42:13 DEBUG : both13: md5 = f90d92cb9554d8bc738c63758a46c8ba OK
2024/11/29 02:42:15 DEBUG : only13: md5 = bc29da913da4704f2c355e61fa2db289 OK
2024/11/29 02:42:17 DEBUG : both14: md5 = 72f8c43207b371fa5f562ab6324d75b5 OK
2024/11/29 02:42:18 DEBUG : only14: md5 = a9442c9c1c27f411fc4b8a33534b3a88 OK
2024/11/29 02:42:20 DEBUG : both15: md5 = 0ef4828fd176bc6c047cdb8691deb0de OK
2024/11/29 02:42:22 DEBUG : only15: md5 = 212d6569dfd5829075ae67cbbd521064 OK
2024/11/29 02:42:24 DEBUG : both16: md5 = d0dec57b5ecc34c5dc409899a73b1b6a OK
2024/11/29 02:42:25 DEBUG : only16: md5 = 48bd4125204363c268dc7e6dca559b50 OK
2024/11/29 02:42:27 DEBUG : both17: md5 = 7feadc4c68bfe749689cf174e55e0aad OK
2024/11/29 02:42:28 DEBUG : only17: md5 = 0d92d49bf8248d2b383eab9fc424b0c9 OK
2024/11/29 02:42:30 DEBUG : both18: md5 = c7a5831d669719fd20cbc448d1496ea4 OK
2024/11/29 02:42:32 DEBUG : only18: md5 = 8bad612d26e1370b003b8f1b22656cde OK
2024/11/29 02:42:34 DEBUG : both19: md5 = 69890b485e50c9765db46980d537fe26 OK
2024/11/29 02:42:35 DEBUG : only19: md5 = 00ba1f0910671a9b13934e7035225a15 OK
2024/11/29 02:42:36 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both0: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both1: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both10: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both11: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both12: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both13: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both14: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both15: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both16: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both17: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both18: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both19: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both2: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both3: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both4: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both5: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both6: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both7: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both8: Unchanged skipping
2024/11/29 02:42:36 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:42:36 DEBUG : both9: Unchanged skipping
2024/11/29 02:42:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:42:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:42:36 DEBUG : Waiting for deletions to finish
2024/11/29 02:42:36 INFO  : only11: Deleted
2024/11/29 02:42:37 INFO  : only15: Deleted
2024/11/29 02:42:37 INFO  : only10: Deleted
2024/11/29 02:42:37 INFO  : only14: Deleted
2024/11/29 02:42:37 INFO  : only19: Deleted
2024/11/29 02:42:37 INFO  : only13: Deleted
2024/11/29 02:42:37 INFO  : only17: Deleted
2024/11/29 02:42:37 INFO  : only1: Deleted
2024/11/29 02:42:38 INFO  : only2: Deleted
2024/11/29 02:42:38 INFO  : only3: Deleted
2024/11/29 02:42:38 INFO  : only12: Deleted
2024/11/29 02:42:38 INFO  : only16: Deleted
2024/11/29 02:42:38 INFO  : only18: Deleted
2024/11/29 02:42:38 INFO  : only6: Deleted
2024/11/29 02:42:39 INFO  : only5: Deleted
2024/11/29 02:42:39 INFO  : only4: Deleted
2024/11/29 02:42:39 INFO  : only7: Deleted
2024/11/29 02:42:39 INFO  : only9: Deleted
2024/11/29 02:42:39 INFO  : only8: Deleted
2024/11/29 02:42:39 INFO  : only0: Deleted
2024/11/29 02:42:39 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (85.88s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:42:54 DEBUG : both0: md5 = 63200fbadeb56af19625ec8cc8c3c22a OK
2024/11/29 02:42:56 DEBUG : only0: md5 = 2264771ab35a3e7c2447fa48d5f91c28 OK
2024/11/29 02:42:58 DEBUG : both1: md5 = 78825ce149d6301f5b698c610a1e7dcc OK
2024/11/29 02:43:00 DEBUG : only1: md5 = 128e47a8d10831867241d86f74087863 OK
2024/11/29 02:43:01 DEBUG : both2: md5 = 96f18335b593185fc5ff869fe1476b46 OK
2024/11/29 02:43:03 DEBUG : only2: md5 = 7ac4c43958cd68373af0b5280628a08d OK
2024/11/29 02:43:05 DEBUG : both3: md5 = a6dfe6c7a9d5f65b742ecebf97abd01e OK
2024/11/29 02:43:06 DEBUG : only3: md5 = e9cefe53cdaeb6719ada513c999a4087 OK
2024/11/29 02:43:08 DEBUG : both4: md5 = d242b828cc6121dd3c5246c2a607e6e6 OK
2024/11/29 02:43:10 DEBUG : only4: md5 = 1712a2571b86e69deed622e8df03fde9 OK
2024/11/29 02:43:11 DEBUG : both5: md5 = fd4914ff20ef5f89ed469a483ac06e2c OK
2024/11/29 02:43:13 DEBUG : only5: md5 = f28808183b0f1534f5fc620bd6d54c48 OK
2024/11/29 02:43:15 DEBUG : both6: md5 = f7d1a1f4c87606ca3e8b2509138605cd OK
2024/11/29 02:43:17 DEBUG : only6: md5 = 4f616e933dbec5c8e77615d322baef18 OK
2024/11/29 02:43:19 DEBUG : both7: md5 = 111ab7c48e70ec1c0447291b8f174b1d OK
2024/11/29 02:43:21 DEBUG : only7: md5 = 5d8d438428d03c5d06d14c86f7577a9f OK
2024/11/29 02:43:22 DEBUG : both8: md5 = 5caa3ad5d8f3183389ca7688c7589dfd OK
2024/11/29 02:43:24 DEBUG : only8: md5 = 2647dfd39b58afa2b2cea474ab50ce9f OK
2024/11/29 02:43:26 DEBUG : both9: md5 = 3e236e47255271847b7de34ad4894ef7 OK
2024/11/29 02:43:27 DEBUG : only9: md5 = 111af7ce75f1f3fbab9d10d815500a7a OK
2024/11/29 02:43:29 DEBUG : both10: md5 = d5c6fa7b0b56bd2f2ae98210255b682d OK
2024/11/29 02:43:31 DEBUG : only10: md5 = a68297db235e4adae409372a278416a6 OK
2024/11/29 02:43:33 DEBUG : both11: md5 = cde52f1bbae3e4bcac72a4d5682118f9 OK
2024/11/29 02:43:34 DEBUG : only11: md5 = e93f7f750982923686d54cfa1b9fbe22 OK
2024/11/29 02:43:36 DEBUG : both12: md5 = 4c5ad97b34b009207715e4d39abd7468 OK
2024/11/29 02:43:38 DEBUG : only12: md5 = 35db22ee8a1705c788f233ad0d00eef1 OK
2024/11/29 02:43:39 DEBUG : both13: md5 = 2466a5de34d050a44123bbd9eb05371b OK
2024/11/29 02:43:41 DEBUG : only13: md5 = ea4ebc068faff570f1618b93fc54d7b3 OK
2024/11/29 02:43:43 DEBUG : both14: md5 = b0908963b8b0ef57aee74c0b5b81e97c OK
2024/11/29 02:43:45 DEBUG : only14: md5 = 5b51078d1c2c6eb2ddec41e0b11b42d4 OK
2024/11/29 02:43:46 DEBUG : both15: md5 = 68f57c952bc109c94432b539dcdc49c0 OK
2024/11/29 02:43:48 DEBUG : only15: md5 = f9f80acb71ff4b698dd91d51395a0ddf OK
2024/11/29 02:43:50 DEBUG : both16: md5 = 5348ca503ad28d816eab3f5e0ceef83e OK
2024/11/29 02:43:52 DEBUG : only16: md5 = 86832d08f71ac30ac439ba8f6eccff6d OK
2024/11/29 02:43:54 DEBUG : both17: md5 = 43c5df63cdaf0e244a0a283303560820 OK
2024/11/29 02:43:55 DEBUG : only17: md5 = d6bcd0fd7630e70fde40ca085bf362d7 OK
2024/11/29 02:43:57 DEBUG : both18: md5 = f93ee28b4bd2814323b9cf68dc9a1cee OK
2024/11/29 02:43:59 DEBUG : only18: md5 = 8af867c5d3450342c6184e26ad850f36 OK
2024/11/29 02:44:01 DEBUG : both19: md5 = bf9db98e68de90c1f0d6bd57deb8ab8f OK
2024/11/29 02:44:02 DEBUG : only19: md5 = 82c45e82ad8df5005a93edb26ec44b70 OK
2024/11/29 02:44:03 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for checks to finish
2024/11/29 02:44:03 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both0: Unchanged skipping
2024/11/29 02:44:03 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both12: Unchanged skipping
2024/11/29 02:44:03 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both13: Unchanged skipping
2024/11/29 02:44:03 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both14: Unchanged skipping
2024/11/29 02:44:03 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both15: Unchanged skipping
2024/11/29 02:44:03 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both16: Unchanged skipping
2024/11/29 02:44:03 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both17: Unchanged skipping
2024/11/29 02:44:03 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both18: Unchanged skipping
2024/11/29 02:44:03 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both19: Unchanged skipping
2024/11/29 02:44:03 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both10: Unchanged skipping
2024/11/29 02:44:03 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both3: Unchanged skipping
2024/11/29 02:44:03 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both4: Unchanged skipping
2024/11/29 02:44:03 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both5: Unchanged skipping
2024/11/29 02:44:03 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both6: Unchanged skipping
2024/11/29 02:44:03 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both7: Unchanged skipping
2024/11/29 02:44:03 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both8: Unchanged skipping
2024/11/29 02:44:03 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:44:03 DEBUG : both9: Unchanged skipping
2024/11/29 02:44:03 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : both11: Unchanged skipping
2024/11/29 02:44:03 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : both1: Unchanged skipping
2024/11/29 02:44:03 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2024/11/29 02:44:03 DEBUG : both2: Unchanged skipping
2024/11/29 02:44:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Waiting for transfers to finish
2024/11/29 02:44:04 DEBUG : only12: md5 = 54f60f92eb18b91bfb17cb0b091e56f7 OK
2024/11/29 02:44:04 INFO  : only12: Copied (replaced existing)
2024/11/29 02:44:04 DEBUG : only0: md5 = 6a379e0d5f395cce23473bedc992ab26 OK
2024/11/29 02:44:04 INFO  : only0: Copied (replaced existing)
2024/11/29 02:44:04 DEBUG : only1: md5 = cabdcd0cf59340786ff15855d79ce71f OK
2024/11/29 02:44:04 INFO  : only1: Copied (replaced existing)
2024/11/29 02:44:04 DEBUG : only10: md5 = 06a154d8106291079d34314fa7738483 OK
2024/11/29 02:44:04 INFO  : only10: Copied (replaced existing)
2024/11/29 02:44:05 DEBUG : only13: md5 = af7c95b31237930ea48b9087b3756121 OK
2024/11/29 02:44:05 INFO  : only13: Copied (replaced existing)
2024/11/29 02:44:06 DEBUG : only15: md5 = b633eb551527a372b1987161bfcfa1ae OK
2024/11/29 02:44:06 INFO  : only15: Copied (replaced existing)
2024/11/29 02:44:06 DEBUG : only14: md5 = a11277dd53246dfb76789fc11c086286 OK
2024/11/29 02:44:06 INFO  : only14: Copied (replaced existing)
2024/11/29 02:44:06 DEBUG : only17: md5 = 9b0571605a92a4446aaad37ecfe11aa7 OK
2024/11/29 02:44:06 INFO  : only17: Copied (replaced existing)
2024/11/29 02:44:07 DEBUG : only19: md5 = 51f21cc1c7068f3f0058b9c30de6d835 OK
2024/11/29 02:44:07 INFO  : only19: Copied (replaced existing)
2024/11/29 02:44:07 DEBUG : only18: md5 = b681bcde37abbf3f0bfda49bd67b21ea OK
2024/11/29 02:44:07 INFO  : only18: Copied (replaced existing)
2024/11/29 02:44:07 DEBUG : only3: md5 = 52092f57a3e13a2e0bac80d9cb377107 OK
2024/11/29 02:44:07 INFO  : only3: Copied (replaced existing)
2024/11/29 02:44:07 DEBUG : only2: md5 = 29584bdb99918acf031a4436887e58b9 OK
2024/11/29 02:44:07 INFO  : only2: Copied (replaced existing)
2024/11/29 02:44:08 DEBUG : only4: md5 = f41acf7c08b8646d1c626b487bbd21a5 OK
2024/11/29 02:44:08 INFO  : only4: Copied (replaced existing)
2024/11/29 02:44:08 DEBUG : only16: md5 = 204c21778ee37a5c8ef1de9b965e7af6 OK
2024/11/29 02:44:08 INFO  : only16: Copied (replaced existing)
2024/11/29 02:44:09 DEBUG : only6: md5 = 8929842e7bcdbfb7e3ba9fcef337c50f OK
2024/11/29 02:44:09 INFO  : only6: Copied (replaced existing)
2024/11/29 02:44:09 DEBUG : only5: md5 = 60b3f3a8b8035843d8a049dc89461528 OK
2024/11/29 02:44:09 INFO  : only5: Copied (replaced existing)
2024/11/29 02:44:10 DEBUG : only8: md5 = 42da7a3be09b29888d3fc200cc23da63 OK
2024/11/29 02:44:10 INFO  : only8: Copied (replaced existing)
2024/11/29 02:44:10 DEBUG : only9: md5 = 8e2ec68facb85734a8a84a848c80a35e OK
2024/11/29 02:44:10 INFO  : only9: Copied (replaced existing)
2024/11/29 02:44:10 DEBUG : only7: md5 = 11e2d9146c38603a6f27b5236630891b OK
2024/11/29 02:44:10 INFO  : only7: Copied (replaced existing)
2024/11/29 02:44:10 DEBUG : only11: md5 = def2dca85378f3aa8ac4b2bd363f8da7 OK
2024/11/29 02:44:10 INFO  : only11: Copied (replaced existing)
2024/11/29 02:44:10 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (104.29s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:44:37 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:44:37 DEBUG : sub dir: Making directory with metadata
2024/11/29 02:44:38 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:45:00 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/29 02:45:00 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/29 02:45:00 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:45:00 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:45:17 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2024/11/29 02:45:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/29 02:45:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/11/29 02:45:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/11/29 02:45:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:45:21 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:45:22 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:45:23 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:45:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/29 02:45:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/11/29 02:45:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:45:26 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (51.35s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:45:28 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:45:28 DEBUG : sub dir: Making directory with metadata
2024/11/29 02:45:29 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:45:55 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/29 02:45:56 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/29 02:45:56 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:45:56 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci'", Local "Local file system at /tmp/rclone4249100962", Modify Window "1ms"
2024/11/29 02:46:10 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/29 02:46:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/11/29 02:46:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/11/29 02:46:13 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:46:14 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:46:15 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:46:16 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:46:17 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/29 02:46:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/11/29 02:46:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:46:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (52.75s)
PASS
2024/11/29 02:46:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lakiyim9hoci': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 18m40.253890769s (try 1/5)