"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5)
2024/11/27 04:43:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji"
2024/11/27 04:43:08 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/11/27 04:43:08 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg"
2024/11/27 04:43:09 DEBUG : Creating backend with remote "/tmp/rclone3356454917"
=== RUN   TestPipe
--- PASS: TestPipe (0.00s)
=== RUN   TestPipeConcurrent
--- PASS: TestPipeConcurrent (0.02s)
=== 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-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:43:10 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/27 04:43:10 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/27 04:43:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:43:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:43:10 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2024/11/27 04:43:10 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.62s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:43:12 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/27 04:43:12 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/27 04:43:12 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/27 04:43:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:43:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:43:15 DEBUG : sub dir/hello world: md5 = bd1958e41e4f06bf9a5881b904a24328 OK
2024/11/27 04:43:15 INFO  : sub dir/hello world: Copied (new)
2024/11/27 04:43:15 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:43:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (6.93s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:43:19 DEBUG : metadata sub dir: Making directory with metadata
2024/11/27 04:43:19 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/27 04:43:19 DEBUG : empty metadata sub dir: Making directory with metadata
2024/11/27 04:43:19 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/27 04:43:19 DEBUG : Local file system at /tmp/rclone3356454917: File to upload is small (21 bytes), uploading instead of streaming
2024/11/27 04:43:19 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/11/27 04:43:19 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/11/27 04:43:19 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/11/27 04:43:19 DEBUG : Google drive root 'crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg': Skipping btime metadata as can't update it on an existing file: 2024-11-27T04:43:19.074495964Z
2024/11/27 04:43:20 INFO  : empty metadata sub dir: Updated directory metadata
2024/11/27 04:43:20 DEBUG : Google drive root 'crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg': Skipping btime metadata as can't update it on an existing file: 2024-11-27T04:43:19.070495989Z
2024/11/27 04:43:21 INFO  : metadata sub dir: Updated directory metadata
2024/11/27 04:43:21 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/11/27 04:43:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:43:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:43:23 DEBUG : metadata sub dir/hello metadata world: md5 = 7ec1a475242d293a5f2ad55018ab2c03 OK
2024/11/27 04:43:23 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:43:26 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (9.12s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:43:28 DEBUG : metadata sub dir: Making directory with metadata
2024/11/27 04:43:28 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/27 04:43:28 DEBUG : empty metadata sub dir: Making directory with metadata
2024/11/27 04:43:28 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/27 04:43:28 DEBUG : Local file system at /tmp/rclone3356454917: File to upload is small (21 bytes), uploading instead of streaming
2024/11/27 04:43:28 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/11/27 04:43:28 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/11/27 04:43:28 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/11/27 04:43:28 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2024/11/27 04:43:28 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2024/11/27 04:43:28 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/11/27 04:43:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:43:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:43:31 DEBUG : metadata sub dir/hello metadata world: md5 = b65b306886cbd3319e3b4ebd9aea979e OK
2024/11/27 04:43:31 INFO  : metadata sub dir/hello metadata world: Copied (new)
2024/11/27 04:43:31 DEBUG : Google drive root 'crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg': Skipping btime metadata as can't update it on an existing file: 2024-11-27T04:43:28.194437512Z
2024/11/27 04:43:31 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:43:34 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (7.90s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:43:36 DEBUG : Creating backend with remote "/non-existing"
2024/11/27 04:43:36 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2024/11/27 04:43:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:43:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.14s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:43:37 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/27 04:43:37 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/27 04:43:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:43:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:43:40 DEBUG : sub dir/hello world: md5 = 32a4da9c7daa9b996783c50f6399e92b OK
2024/11/27 04:43:40 INFO  : sub dir/hello world: Copied (new)
2024/11/27 04:43:40 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:43:42 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (6.75s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:43:43 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Running all checks before starting transfers
2024/11/27 04:43:44 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/27 04:43:44 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/27 04:43:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:43:44 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Checks finished, now starting transfers
2024/11/27 04:43:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:43:46 DEBUG : sub dir/hello world: md5 = 18ecbd113cdb3fe7bb6675155272468d OK
2024/11/27 04:43:46 INFO  : sub dir/hello world: Copied (new)
2024/11/27 04:43:47 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:43:49 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (6.75s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:43:50 ERROR : Ignoring --no-traverse with sync
2024/11/27 04:43:50 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/27 04:43:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/27 04:43:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:43:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:43:53 DEBUG : sub dir/hello world: md5 = 40c140acc736a1e3972980ad5f4fbdb5 OK
2024/11/27 04:43:53 INFO  : sub dir/hello world: Copied (new)
2024/11/27 04:43:53 DEBUG : Waiting for deletions to finish
2024/11/27 04:43:54 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:43:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (6.57s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:43:57 DEBUG : hello world2: Need to transfer - File not found at Destination
2024/11/27 04:43:57 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/27 04:43:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:43:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:43:59 DEBUG : hello world2: md5 = 1793d525226db8254964630653898547 OK
2024/11/27 04:43:59 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestCopyWithDepth (3.74s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:44:01 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/27 04:44:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:44:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:44:02 DEBUG : potato2: md5 = 70bb20ff61ae63fd68430697babe0817 OK
2024/11/27 04:44:02 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.70s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:44:04 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/27 04:44:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:44:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:44:06 DEBUG : potato2: md5 = d273f185b52e80a3cc2506c582560a90 OK
2024/11/27 04:44:06 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.74s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:44:08 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/27 04:44:08 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/27 04:44:08 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/27 04:44:08 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/27 04:44:08 DEBUG : sub dir: Making directory with metadata
2024/11/27 04:44:09 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/27 04:44:09 DEBUG : sub dir2: Making directory with metadata
2024/11/27 04:44:11 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/27 04:44:11 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/27 04:44:11 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/27 04:44:12 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/27 04:44:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:44:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:44:12 DEBUG : sub dir/hello world: md5 = f1eb640905d0dbed92ec354a8a8a00ef OK
2024/11/27 04:44:12 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:44:16 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2024/11/27 04:44:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (10.30s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:44:18 DEBUG : sub dir2: Making directory
2024/11/27 04:44:18 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/27 04:44:18 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/27 04:44:19 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/27 04:44:19 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/27 04:44:19 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2024/11/27 04:44:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/27 04:44:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:44:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:44:21 DEBUG : sub dir/hello world: md5 = 9930932894530c07d2972c0b919a2b05 OK
2024/11/27 04:44:21 INFO  : sub dir/hello world: Copied (new)
2024/11/27 04:44:22 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/27 04:44:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (6.38s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:44:25 DEBUG : sub dir2: Making directory with metadata
2024/11/27 04:44:25 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/27 04:44:25 DEBUG : sub dir: Making directory with metadata
2024/11/27 04:44:26 INFO  : sub dir: Made directory with metadata (mtime=2024-11-27T04:44:25.174072336Z)
2024/11/27 04:44:26 DEBUG : sub dir2: Making directory with metadata
2024/11/27 04:44:27 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/27 04:44:27 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/27 04:44:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:44:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:44:29 DEBUG : sub dir/hello world: md5 = 2f74db1c30066de023e9dd8b8e673f83 OK
2024/11/27 04:44:29 INFO  : sub dir/hello world: Copied (new)
2024/11/27 04:44:29 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:44:32 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (8.74s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:44:33 DEBUG : sub dir no update dir modtime: Making directory with metadata
2024/11/27 04:44:33 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/27 04:44:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:44:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:44:35 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (4.46s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:44:38 DEBUG : sub dir2: Making directory
2024/11/27 04:44:38 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/27 04:44:38 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/27 04:44:38 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/27 04:44:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:44:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:44:41 DEBUG : sub dir/hello world: md5 = 0488ee2e886825bfe3227094dea94aca OK
2024/11/27 04:44:41 INFO  : sub dir/hello world: Copied (new)
2024/11/27 04:44:41 INFO  : sub dir/hello world: Deleted
2024/11/27 04:44:41 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/27 04:44:43 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (6.10s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:44:44 DEBUG : sub dir2: Making directory with metadata
2024/11/27 04:44:44 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/27 04:44:44 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/27 04:44:44 DEBUG : sub dir: Making directory with metadata
2024/11/27 04:44:45 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/27 04:44:45 DEBUG : sub dir2: Making directory with metadata
2024/11/27 04:44:46 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/27 04:44:46 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/27 04:44:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:44:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:44:48 DEBUG : sub dir/hello world: md5 = 29215acd22f10af98e7e11329ed58c9a OK
2024/11/27 04:44:48 INFO  : sub dir/hello world: Copied (new)
2024/11/27 04:44:48 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:44:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (9.10s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.46s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:44:54 DEBUG : sub dir2: Making directory
2024/11/27 04:44:54 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/27 04:44:54 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/27 04:44:54 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/27 04:44:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:44:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:44:57 DEBUG : sub dir/hello world: md5 = a6230c801265591b5f454e7954e33d39 OK
2024/11/27 04:44:57 INFO  : sub dir/hello world: Copied (new)
2024/11/27 04:44:57 DEBUG : Waiting for deletions to finish
2024/11/27 04:44:57 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/27 04:44:59 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (6.45s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:45:03 DEBUG : sub dir/hello world: md5 = d48d7c17165404099e393b576f714d0d OK
2024/11/27 04:45:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-balufaw1bute"
2024/11/27 04:45:03 DEBUG : Creating backend with remote "TestDrive:crypt/ivc1sfgg9kki0jukeigegt25oqsqjd9f90tf6ahfc3nvvvaf8160"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji' -> Encrypted drive 'TestCryptDrive:rclone-test-balufaw1bute'
2024/11/27 04:45:05 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/27 04:45:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/27 04:45:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-balufaw1bute': Waiting for checks to finish
2024/11/27 04:45:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-balufaw1bute': Waiting for transfers to finish
2024/11/27 04:45:08 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/27 04:45:09 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:45:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-balufaw1bute': Purge remote
2024/11/27 04:45:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (12.74s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:45:15 DEBUG : sub dir/hello world: md5 = 37a1d287d881736c64f06952ab55bbe9 OK
2024/11/27 04:45:16 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/27 04:45:16 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/27 04:45:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:45:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:45:18 DEBUG : sub dir/hello world: md5 = 38a1c8c6f11d7301889418a7339f7370 OK
2024/11/27 04:45:18 INFO  : sub dir/hello world: Copied (replaced existing)
2024/11/27 04:45:18 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:45:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (8.83s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:45:24 DEBUG : sub dir/hello world: md5 = 0550765062cc9b3642fbe36b00c9d8a8 OK
2024/11/27 04:45:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tudacac0tehu"
2024/11/27 04:45:25 DEBUG : Creating backend with remote "TestDrive:crypt/ivf4etioi427qsc1c3cfbvg7bjag0ck47ep694fjcpct1k8bqch0"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji' -> Encrypted drive 'TestCryptDrive:rclone-test-tudacac0tehu'
2024/11/27 04:45:26 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/27 04:45:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/27 04:45:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tudacac0tehu': Waiting for checks to finish
2024/11/27 04:45:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tudacac0tehu': Waiting for transfers to finish
2024/11/27 04:45:30 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/27 04:45:31 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:45:33 DEBUG : sub dir/hello world: md5 = e39bc2480f7f0367379a7f9e02bea06f OK
2024/11/27 04:45:34 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/27 04:45:34 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/27 04:45:34 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/27 04:45:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tudacac0tehu': Waiting for checks to finish
2024/11/27 04:45:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tudacac0tehu': Waiting for transfers to finish
2024/11/27 04:45:36 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/27 04:45:37 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:45:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tudacac0tehu': Purge remote
2024/11/27 04:45:39 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (19.34s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:45:44 DEBUG : sub dir/hello world: md5 = 5d1136e607f6c890cc58b1392ee84d7d OK
2024/11/27 04:45:45 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/27 04:45:45 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/27 04:45:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:45:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:45:46 DEBUG : sub dir/hello world: md5 = 2c6394f26ac3f37caefef4b70dde7731 OK
2024/11/27 04:45:46 INFO  : sub dir/hello world: Copied (replaced existing)
2024/11/27 04:45:46 INFO  : sub dir/hello world: Deleted
2024/11/27 04:45:47 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:45:49 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (8.95s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:45:52 DEBUG : sub dir/hello world: md5 = dc687d0265cf5cca5f249b332acb55d2 OK
2024/11/27 04:45:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pequfif8rere"
2024/11/27 04:45:53 DEBUG : Creating backend with remote "TestDrive:crypt/rgag40gf3j7r1g8arpjjq6od147n07dnul41kp0ries8h4e6l42g"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji' -> Encrypted drive 'TestCryptDrive:rclone-test-pequfif8rere'
2024/11/27 04:45:54 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/27 04:45:54 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/27 04:45:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pequfif8rere': Waiting for checks to finish
2024/11/27 04:45:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pequfif8rere': Waiting for transfers to finish
2024/11/27 04:45:58 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/27 04:45:59 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:46:01 DEBUG : sub dir/hello world: md5 = a03073970d2120343a83ed4ea9bf9b69 OK
2024/11/27 04:46:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pequfif8rere': Using server-side directory move
2024/11/27 04:46:01 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pequfif8rere': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/27 04:46:02 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/27 04:46:02 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/27 04:46:02 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/27 04:46:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pequfif8rere': Waiting for checks to finish
2024/11/27 04:46:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pequfif8rere': Waiting for transfers to finish
2024/11/27 04:46:02 INFO  : sub dir/hello world: Deleted
2024/11/27 04:46:03 INFO  : sub dir/hello world: Moved (server-side)
2024/11/27 04:46:04 INFO  : sub dir: Set directory modification time (using SetModTime)
2024/11/27 04:46:06 DEBUG : sub dir/hello world: md5 = c505faca358db67af4a99d38006613b9 OK
2024/11/27 04:46:07 DEBUG : testing file moves
2024/11/27 04:46:07 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/27 04:46:07 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/27 04:46:07 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2024/11/27 04:46:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pequfif8rere': Waiting for checks to finish
2024/11/27 04:46:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pequfif8rere': Waiting for transfers to finish
2024/11/27 04:46:08 INFO  : sub dir/hello world: Deleted
2024/11/27 04:46:09 INFO  : sub dir/hello world: Moved (server-side)
2024/11/27 04:46:09 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:46:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pequfif8rere': Purge remote
--- PASS: TestServerSideMoveOverSelf (23.63s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:46:16 DEBUG : sub dir/hello world: md5 = aed985486907ba91bdc5e6ba30d215a7 OK
2024/11/27 04:46:16 ERROR : : error listing: directory not found
2024/11/27 04:46:17 DEBUG : Local file system at /tmp/rclone3356454917: Making directory
2024/11/27 04:46:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:46:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:46:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (6.72s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:46:23 DEBUG : sub dir/hello world: md5 = c2bb64b25d788df6d866227d389f38bf OK
2024/11/27 04:46:24 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/27 04:46:24 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/27 04:46:24 DEBUG : Local file system at /tmp/rclone3356454917: Waiting for checks to finish
2024/11/27 04:46:24 DEBUG : Local file system at /tmp/rclone3356454917: Waiting for transfers to finish
2024/11/27 04:46:25 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2024/11/27 04:46:25 INFO  : sub dir/hello world: Copied (new)
2024/11/27 04:46:25 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:46:26 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (7.42s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:46:28 DEBUG : check sum: Need to transfer - File not found at Destination
2024/11/27 04:46:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:46:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:46:30 DEBUG : check sum: md5 = 8f6713a274f18940a0a4ee5932fad455 OK
2024/11/27 04:46:30 INFO  : check sum: Copied (new)
2024/11/27 04:46:30 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:46:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:46:30 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2024/11/27 04:46:30 DEBUG : check sum: Size of src and dst objects identical
2024/11/27 04:46:30 DEBUG : check sum: Unchanged skipping
2024/11/27 04:46:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:46:30 DEBUG : Waiting for deletions to finish
2024/11/27 04:46:30 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (6.26s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:46:34 DEBUG : sizeonly: Need to transfer - File not found at Destination
2024/11/27 04:46:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:46:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:46:36 DEBUG : sizeonly: md5 = 139e6da9419520fc71c0f7420a3f8847 OK
2024/11/27 04:46:36 INFO  : sizeonly: Copied (new)
2024/11/27 04:46:36 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:46:36 DEBUG : sizeonly: Sizes identical
2024/11/27 04:46:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:46:36 DEBUG : sizeonly: Unchanged skipping
2024/11/27 04:46:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:46:36 DEBUG : Waiting for deletions to finish
2024/11/27 04:46:36 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (6.29s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:46:40 DEBUG : ignore-size: Need to transfer - File not found at Destination
2024/11/27 04:46:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:46:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:46:42 DEBUG : ignore-size: md5 = d13c1d6bd41c3a6261ecad940c5485ae OK
2024/11/27 04:46:42 INFO  : ignore-size: Copied (new)
2024/11/27 04:46:42 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:46:43 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:46:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:46:43 DEBUG : ignore-size: Unchanged skipping
2024/11/27 04:46:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:46:43 DEBUG : Waiting for deletions to finish
2024/11/27 04:46:43 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (4.66s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:46:47 DEBUG : existing: md5 = 5bda0a41f5a0ad3e3aaefed3d6fff547 OK
2024/11/27 04:46:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:46:47 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:46:47 DEBUG : existing: Unchanged skipping
2024/11/27 04:46:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:46:47 DEBUG : Waiting for deletions to finish
2024/11/27 04:46:47 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:46:47 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2024/11/27 04:46:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:46:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:46:49 DEBUG : existing: md5 = ecee5b11e9be5baa3556258f867f25d1 OK
2024/11/27 04:46:49 INFO  : existing: Copied (replaced existing)
2024/11/27 04:46:49 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (6.02s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:46:51 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/27 04:46:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:46:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:46:53 DEBUG : existing: md5 = 37fb0b457d28245a7a22938737cf3968 OK
2024/11/27 04:46:53 INFO  : existing: Copied (new)
2024/11/27 04:46:53 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:46:53 DEBUG : existing: Destination exists, skipping
2024/11/27 04:46:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:46:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:46:53 DEBUG : Waiting for deletions to finish
2024/11/27 04:46:53 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (4.60s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:46:58 DEBUG : b/potato: md5 = d98969b58ffead2f4832436dd215b1da OK
2024/11/27 04:47:01 DEBUG : c/non empty space: md5 = 51f61379597488cd16fc2389faf3a789 OK
2024/11/27 04:47:01 DEBUG : d: Making directory
2024/11/27 04:47:03 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/27 04:47:03 DEBUG : Added delayed dir = "c", newDst=c
2024/11/27 04:47:03 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:47:03 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/27 04:47:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:47:03 DEBUG : c/non empty space: Unchanged skipping
2024/11/27 04:47:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:47:06 DEBUG : a/potato2: md5 = 4fd027c421c66375a253a553a54ec3d0 OK
2024/11/27 04:47:06 INFO  : a/potato2: Copied (new)
2024/11/27 04:47:06 DEBUG : Waiting for deletions to finish
2024/11/27 04:47:06 INFO  : b/potato: Deleted
2024/11/27 04:47:07 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/27 04:47:07 INFO  : d: Removing directory
2024/11/27 04:47:08 INFO  : b: Removing directory
2024/11/27 04:47:08 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/27 04:47:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:47:11 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/27 04:47:12 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (18.11s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:47:15 DEBUG : empty space: md5 = 4effcd80e6b5996dc09811b70a6e7791 OK
2024/11/27 04:47:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:47:16 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/27 04:47:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:47:16 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2024/11/27 04:47:16 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:47:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:47:16 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/27 04:47:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:47:18 DEBUG : empty space: md5 = 4bc5e27c92f8400a24397e99c93ca886 OK
2024/11/27 04:47:18 INFO  : empty space: Copied (replaced existing)
2024/11/27 04:47:18 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (6.38s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.46s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:47:22 DEBUG : foo: md5 = e1aaea15e9f3a51b364f32e8c12dba3d OK
2024/11/27 04:47:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:47:23 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/27 04:47:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:47:24 DEBUG : foo: md5 = b821185268ba0cc1d01b4b8ce20f8729 OK
2024/11/27 04:47:24 INFO  : foo: Copied (replaced existing)
2024/11/27 04:47:24 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (5.61s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:47:28 DEBUG : empty space: md5 = 58de9255ea52490dd69486ee5e4862c2 OK
2024/11/27 04:47:28 DEBUG : potato: Need to transfer - File not found at Destination
2024/11/27 04:47:28 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:47:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:47:28 DEBUG : empty space: Unchanged skipping
2024/11/27 04:47:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:47:30 DEBUG : potato: md5 = 1a0811f422b2f0140ffa84d282edc17f OK
2024/11/27 04:47:30 INFO  : potato: Copied (new)
2024/11/27 04:47:30 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (6.26s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:47:34 DEBUG : potato: md5 = 3c84f1e8d89bb0e0f6639febb5a1c5f8 OK
2024/11/27 04:47:34 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2024/11/27 04:47:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:47:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:47:36 DEBUG : potato: md5 = 13b67241f876f5fbe3f0bb4ae0a57efa OK
2024/11/27 04:47:36 INFO  : potato: Copied (replaced existing)
2024/11/27 04:47:36 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (5.13s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:47:39 DEBUG : potato: md5 = 70359db4ec9c2956ce3e5544b43fd8be OK
2024/11/27 04:47:40 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/27 04:47:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:47:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:47:41 DEBUG : potato: md5 = ee8d07375bc83a021e100b21e961d2c0 OK
2024/11/27 04:47:41 INFO  : potato: Copied (replaced existing)
2024/11/27 04:47:41 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (5.50s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:47:45 DEBUG : potato: md5 = 784d9384934369d1cea85f288d995af1 OK
2024/11/27 04:47:46 DEBUG : empty space: md5 = 7ec431292f2994f8e94a2d04e880173f OK
2024/11/27 04:47:47 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/27 04:47:47 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2024/11/27 04:47:47 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:47:47 DEBUG : empty space: Unchanged skipping
2024/11/27 04:47:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:47:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:47:47 DEBUG : Waiting for deletions to finish
2024/11/27 04:47:47 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (6.31s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:47:51 DEBUG : potato: md5 = 18d306ac564556bda49b86a5856eb225 OK
2024/11/27 04:47:53 DEBUG : empty space: md5 = 8b093a1c642040dec5005b1cabd47d6b OK
2024/11/27 04:47:53 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/27 04:47:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:47:53 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:47:53 DEBUG : empty space: Unchanged skipping
2024/11/27 04:47:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:47:55 DEBUG : potato2: md5 = 11ac03b94c47961393516fb29d7f2847 OK
2024/11/27 04:47:55 INFO  : potato2: Copied (new)
2024/11/27 04:47:55 DEBUG : Waiting for deletions to finish
2024/11/27 04:47:55 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.43s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:48:00 DEBUG : b/potato: md5 = 02f8467ade0da03606ac9ea381300376 OK
2024/11/27 04:48:03 DEBUG : c/non empty space: md5 = bce9a12b7e748ad3934f8555a2b8ca19 OK
2024/11/27 04:48:03 DEBUG : d: Making directory
2024/11/27 04:48:04 DEBUG : d/e: Making directory
2024/11/27 04:48:07 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/27 04:48:07 DEBUG : Added delayed dir = "c", newDst=c
2024/11/27 04:48:07 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:48:07 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/27 04:48:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:48:07 DEBUG : c/non empty space: Unchanged skipping
2024/11/27 04:48:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:48:09 DEBUG : a/potato2: md5 = 4afb827fc68c82e0780e4cf6d4999943 OK
2024/11/27 04:48:09 INFO  : a/potato2: Copied (new)
2024/11/27 04:48:09 DEBUG : Waiting for deletions to finish
2024/11/27 04:48:10 INFO  : b/potato: Deleted
2024/11/27 04:48:10 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/27 04:48:10 INFO  : d/e: Removing directory
2024/11/27 04:48:11 INFO  : d: Removing directory
2024/11/27 04:48:12 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2024/11/27 04:48:12 INFO  : b: Removing directory
2024/11/27 04:48:12 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/27 04:48:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:48:15 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/27 04:48:16 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (19.80s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:48:20 DEBUG : b/potato: md5 = 4bf6f5b234d56c77250f39a48b22f536 OK
2024/11/27 04:48:23 DEBUG : c/non empty space: md5 = cbebcaa5ad8beefa7c654aa9390d9a7c OK
2024/11/27 04:48:23 DEBUG : d: Making directory
2024/11/27 04:48:25 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/27 04:48:25 DEBUG : Added delayed dir = "c", newDst=c
2024/11/27 04:48:25 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:48:25 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/27 04:48:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:48:25 DEBUG : c/non empty space: Unchanged skipping
2024/11/27 04:48:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:48:28 DEBUG : a/potato2: md5 = c3577e38c37a3fac1a306f052f622919 OK
2024/11/27 04:48:28 INFO  : a/potato2: Copied (new)
2024/11/27 04:48:28 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': not deleting files as there were IO errors
2024/11/27 04:48:29 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/27 04:48:29 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:48:33 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/27 04:48:34 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/27 04:48:35 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (18.63s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:48:38 DEBUG : potato: md5 = 3f7b679b128af479a22362445d32679e OK
2024/11/27 04:48:40 DEBUG : empty space: md5 = 5dea6f0e0948ef64e950453f607f399d OK
2024/11/27 04:48:40 DEBUG : Waiting for deletions to finish
2024/11/27 04:48:40 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/27 04:48:40 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:48:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:48:40 DEBUG : empty space: Unchanged skipping
2024/11/27 04:48:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:48:41 INFO  : potato: Deleted
2024/11/27 04:48:42 DEBUG : potato2: md5 = 0e43b3e712ac30035144ce361e7e34b2 OK
2024/11/27 04:48:42 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (8.28s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:48:46 DEBUG : potato: md5 = c15b2ec277dbba8bc2a3b2e64879ddb3 OK
2024/11/27 04:48:48 DEBUG : empty space: md5 = 13252dde31b3e4462ccc1bd699c676bb OK
2024/11/27 04:48:48 DEBUG : Waiting for deletions to finish
2024/11/27 04:48:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:48:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:48:49 INFO  : potato: Deleted
2024/11/27 04:48:49 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/27 04:48:49 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:48:49 DEBUG : empty space: Unchanged skipping
2024/11/27 04:48:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:48:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:48:51 DEBUG : potato2: md5 = c800c5ff8c4a2e71cd9ea50d2b96f8c2 OK
2024/11/27 04:48:51 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (8.78s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:48:55 DEBUG : potato: md5 = 46f7542138aed3e2f70b34d6a1192f6c OK
2024/11/27 04:48:55 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/27 04:48:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:48:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:48:57 DEBUG : potato2: md5 = 4e98b8c32ac8f706b63c7b2ce0ed88ae OK
2024/11/27 04:48:57 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (6.18s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:49:01 DEBUG : potato2: md5 = b1b9e10b279243b26fd0d338bfccb24b OK
2024/11/27 04:49:03 DEBUG : empty space: md5 = 94245ad191c136ae7442540a7b6303ef OK
2024/11/27 04:49:03 DEBUG : enormous: Excluded (Size Filter)
2024/11/27 04:49:03 DEBUG : enormous: Excluded
2024/11/27 04:49:03 DEBUG : potato2: Excluded (Size Filter)
2024/11/27 04:49:03 DEBUG : potato2: Excluded
2024/11/27 04:49:03 DEBUG : potato2: Excluded (Size Filter)
2024/11/27 04:49:03 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:49:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:49:03 DEBUG : empty space: Unchanged skipping
2024/11/27 04:49:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:49:03 DEBUG : Waiting for deletions to finish
2024/11/27 04:49:03 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:49:03 DEBUG : enormous: Excluded (Size Filter)
2024/11/27 04:49:03 DEBUG : enormous: Excluded
2024/11/27 04:49:03 DEBUG : potato2: Excluded (Size Filter)
2024/11/27 04:49:03 DEBUG : potato2: Excluded
2024/11/27 04:49:04 DEBUG : potato2: Excluded (Size Filter)
2024/11/27 04:49:04 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/11/27 04:49:04 DEBUG : empty space: Unchanged skipping
2024/11/27 04:49:04 DEBUG : Local file system at /tmp/rclone3356454917: Waiting for checks to finish
2024/11/27 04:49:04 DEBUG : Local file system at /tmp/rclone3356454917: Waiting for transfers to finish
2024/11/27 04:49:04 DEBUG : Waiting for deletions to finish
2024/11/27 04:49:04 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncWithExclude (6.84s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:49:08 DEBUG : potato2: md5 = d1219205c42645be287bb4909aa5c98a OK
2024/11/27 04:49:09 DEBUG : empty space: md5 = a1f175ea712ddb7f44d614244a2a4fc4 OK
2024/11/27 04:49:11 DEBUG : enormous: md5 = 42659187c37e4b520dd7ad626ed3601c OK
2024/11/27 04:49:12 DEBUG : enormous: Excluded (Size Filter)
2024/11/27 04:49:12 DEBUG : enormous: Excluded
2024/11/27 04:49:12 DEBUG : potato2: Excluded (Size Filter)
2024/11/27 04:49:12 DEBUG : potato2: Excluded
2024/11/27 04:49:12 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:49:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:49:12 DEBUG : empty space: Unchanged skipping
2024/11/27 04:49:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:49:12 DEBUG : Waiting for deletions to finish
2024/11/27 04:49:12 INFO  : potato2: Deleted
2024/11/27 04:49:13 INFO  : enormous: Deleted
2024/11/27 04:49:13 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:49:13 DEBUG : Local file system at /tmp/rclone3356454917: Waiting for checks to finish
2024/11/27 04:49:13 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/11/27 04:49:13 DEBUG : empty space: Unchanged skipping
2024/11/27 04:49:13 DEBUG : Local file system at /tmp/rclone3356454917: Waiting for transfers to finish
2024/11/27 04:49:13 DEBUG : Waiting for deletions to finish
2024/11/27 04:49:13 INFO  : enormous: Deleted
2024/11/27 04:49:13 INFO  : potato2: Deleted
2024/11/27 04:49:13 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (8.86s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:49:17 DEBUG : one: md5 = e92e0a0ef4288ff461b5e8d9737ff703 OK
2024/11/27 04:49:18 DEBUG : two: md5 = 4558b24bef7a75609b33b551a739782d OK
2024/11/27 04:49:20 DEBUG : three: md5 = 1e1202686ab46ae74c1d25fc7b3b1d83 OK
2024/11/27 04:49:22 DEBUG : four: md5 = 02489ad2ab62f246e1bb51274cf5183e OK
2024/11/27 04:49:22 DEBUG : five: Need to transfer - File not found at Destination
2024/11/27 04:49:22 DEBUG : four: Sizes differ (src 4 vs dst 8)
2024/11/27 04:49:22 DEBUG : one: Destination is newer than source, skipping
2024/11/27 04:49:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:49:22 DEBUG : three: Sizes identical
2024/11/27 04:49:22 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2024/11/27 04:49:22 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2024/11/27 04:49:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:49:23 DEBUG : two: md5 = d74e56c74033379c3206132f651acd5e OK
2024/11/27 04:49:23 INFO  : two: Copied (replaced existing)
2024/11/27 04:49:24 DEBUG : four: md5 = 8cb99c98b4d99522739e83c6b0cf6613 OK
2024/11/27 04:49:24 INFO  : four: Copied (replaced existing)
2024/11/27 04:49:24 DEBUG : five: md5 = 7aa4d37309ba5cb0ea0c71d4d6b41712 OK
2024/11/27 04:49:24 INFO  : five: Copied (new)
2024/11/27 04:49:24 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (12.35s)
=== 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-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2024/11/27 04:49:27 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Ignoring --track-renames as the source and destination do not have a common hash
2024/11/27 04:49:28 DEBUG : potato: Need to transfer - File not found at Destination
2024/11/27 04:49:28 DEBUG : yam: Need to transfer - File not found at Destination
2024/11/27 04:49:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:49:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:49:29 DEBUG : potato: md5 = 6d26ca4fc4efc8209c87bdd36ad1c90b OK
2024/11/27 04:49:29 INFO  : potato: Copied (new)
2024/11/27 04:49:29 DEBUG : yam: md5 = b5dcd5846752b8206f1bb1aaf9f85bee OK
2024/11/27 04:49:29 INFO  : yam: Copied (new)
2024/11/27 04:49:29 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:49:30 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Ignoring --track-renames as the source and destination do not have a common hash
2024/11/27 04:49:30 DEBUG : yaml: Need to transfer - File not found at Destination
2024/11/27 04:49:30 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:49:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:49:30 DEBUG : potato: Unchanged skipping
2024/11/27 04:49:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:49:32 DEBUG : yaml: md5 = eea78910de92d2a04399df9a500ea437 OK
2024/11/27 04:49:32 INFO  : yaml: Copied (new)
2024/11/27 04:49:32 DEBUG : Waiting for deletions to finish
2024/11/27 04:49:32 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (8.15s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2024/11/27 04:49:36 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Making map for --track-renames
2024/11/27 04:49:36 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Finished making map for --track-renames
2024/11/27 04:49:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:49:36 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/11/27 04:49:36 DEBUG : yam: Need to transfer - No matching file found at Destination
2024/11/27 04:49:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for renames to finish
2024/11/27 04:49:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:49:37 DEBUG : potato: md5 = 9b1fba8d931bb822e2936d015f18549a OK
2024/11/27 04:49:37 INFO  : potato: Copied (new)
2024/11/27 04:49:38 DEBUG : yam: md5 = 6e91791afada611bde617609ed9e54d3 OK
2024/11/27 04:49:38 INFO  : yam: Copied (new)
2024/11/27 04:49:38 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:49:38 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:49:38 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Making map for --track-renames
2024/11/27 04:49:38 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Finished making map for --track-renames
2024/11/27 04:49:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:49:38 DEBUG : potato: Unchanged skipping
2024/11/27 04:49:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for renames to finish
2024/11/27 04:49:39 INFO  : yam: Moved (server-side) to: yaml
2024/11/27 04:49:39 INFO  : yaml: Renamed from "yam"
2024/11/27 04:49:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:49:39 DEBUG : Waiting for deletions to finish
2024/11/27 04:49:39 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (6.27s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2024/11/27 04:49:42 DEBUG : Added delayed dir = "sub", newDst=<nil>
2024/11/27 04:49:42 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Making map for --track-renames
2024/11/27 04:49:42 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Finished making map for --track-renames
2024/11/27 04:49:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:49:42 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/11/27 04:49:42 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2024/11/27 04:49:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for renames to finish
2024/11/27 04:49:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:49:45 DEBUG : potato: md5 = 7aab0e0d1dae64cdc98128182b85e54f OK
2024/11/27 04:49:45 INFO  : potato: Copied (new)
2024/11/27 04:49:45 DEBUG : sub/yam: md5 = 5592fd97e2117dccf0774b1c84d2f340 OK
2024/11/27 04:49:45 INFO  : sub/yam: Copied (new)
2024/11/27 04:49:45 DEBUG : Waiting for deletions to finish
2024/11/27 04:49:46 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:49:47 DEBUG : Added delayed dir = "sub", newDst=sub
2024/11/27 04:49:47 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:49:47 DEBUG : potato: Unchanged skipping
2024/11/27 04:49:47 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Making map for --track-renames
2024/11/27 04:49:47 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Finished making map for --track-renames
2024/11/27 04:49:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:49:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for renames to finish
2024/11/27 04:49:48 INFO  : sub/yam: Moved (server-side) to: yam
2024/11/27 04:49:48 INFO  : yam: Renamed from "sub/yam"
2024/11/27 04:49:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:49:48 DEBUG : Waiting for deletions to finish
2024/11/27 04:49:48 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (10.30s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:49:52 DEBUG : Creating backend with remote "/tmp/rclone3356454917/dir1"
2024/11/27 04:49:52 DEBUG : Creating backend with remote "/tmp/rclone3356454917/dir2"
2024/11/27 04:49:52 DEBUG : Local file system at /tmp/rclone3356454917/dir2: Using server-side directory move
2024/11/27 04:49:52 INFO  : Local file system at /tmp/rclone3356454917/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/27 04:49:52 DEBUG : file1.txt: Need to transfer - File not found at Destination
2024/11/27 04:49:52 INFO  : file1.txt: Moved (server-side)
2024/11/27 04:49:52 DEBUG : Local file system at /tmp/rclone3356454917/dir2: Waiting for checks to finish
2024/11/27 04:49:52 DEBUG : Local file system at /tmp/rclone3356454917/dir2: Waiting for transfers to finish
--- PASS: TestServerSideMoveLocal (0.46s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:49:53 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/11/27 04:49:53 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/27 04:49:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/27 04:49:53 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/11/27 04:49:53 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/11/27 04:49:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:49:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:49:55 DEBUG : sub dir/hello world: md5 = 57519509a4dfc6a64d0296ed814dd71a OK
2024/11/27 04:49:55 INFO  : sub dir/hello world: Copied (new)
2024/11/27 04:49:55 INFO  : sub dir/hello world: Deleted
2024/11/27 04:49:58 DEBUG : nested/sub dir/file: md5 = 5f942e701ebb6d5b017afea8ae660ef0 OK
2024/11/27 04:49:58 INFO  : nested/sub dir/file: Copied (new)
2024/11/27 04:49:58 INFO  : nested/sub dir/file: Deleted
2024/11/27 04:49:58 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/11/27 04:49:59 INFO  : nested: Set directory modification time (using DirSetModTime)
2024/11/27 04:49:59 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/27 04:49:59 INFO  : sub dir: Removing directory
2024/11/27 04:49:59 INFO  : nested/sub dir: Removing directory
2024/11/27 04:49:59 INFO  : nested: Removing directory
2024/11/27 04:49:59 DEBUG : Local file system at /tmp/rclone3356454917: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:50:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/27 04:50:03 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/11/27 04:50:04 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (12.39s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:50:05 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/11/27 04:50:05 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/27 04:50:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/27 04:50:05 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/11/27 04:50:05 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/11/27 04:50:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:50:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:50:08 DEBUG : sub dir/hello world: md5 = ba8807c315d5a932132418d1c929771f OK
2024/11/27 04:50:08 INFO  : sub dir/hello world: Copied (new)
2024/11/27 04:50:08 INFO  : sub dir/hello world: Deleted
2024/11/27 04:50:10 DEBUG : nested/sub dir/file: md5 = 95baa484c226dd8087e0c6c2b54298bd OK
2024/11/27 04:50:10 INFO  : nested/sub dir/file: Copied (new)
2024/11/27 04:50:10 INFO  : nested/sub dir/file: Deleted
2024/11/27 04:50:11 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/11/27 04:50:11 INFO  : nested: Set directory modification time (using DirSetModTime)
2024/11/27 04:50:11 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:50:14 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/27 04:50:15 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/11/27 04:50:16 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (12.44s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:50:18 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/27 04:50:18 DEBUG : existing-b: Need to transfer - File not found at Destination
2024/11/27 04:50:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:50:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:50:19 DEBUG : existing-b: md5 = 5d170a72ce0deb979c1b26c84112927b OK
2024/11/27 04:50:19 INFO  : existing-b: Copied (new)
2024/11/27 04:50:19 INFO  : existing-b: Deleted
2024/11/27 04:50:19 DEBUG : existing: md5 = 652fd1b81dba50db01b353708be87bfe OK
2024/11/27 04:50:19 INFO  : existing: Copied (new)
2024/11/27 04:50:19 INFO  : existing: Deleted
2024/11/27 04:50:20 DEBUG : existing: Destination exists, skipping
2024/11/27 04:50:20 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2024/11/27 04:50:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:50:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:50:20 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (4.89s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:50:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-namemew1jaxa"
2024/11/27 04:50:22 DEBUG : Creating backend with remote "TestDrive:crypt/fmm2mvmnvuro8vgh4u42rs834lvkuh57trt3pndfj204bavqjmjg"
2024/11/27 04:50:25 DEBUG : potato2: md5 = 8200a9ec75da4520a2d93be5b8885d0f OK
2024/11/27 04:50:27 DEBUG : empty space: md5 = 9aaa16db6453cbccf4bb73f604e068e6 OK
2024/11/27 04:50:28 DEBUG : potato3: md5 = 1435bfe0cb7f8c27454ae696bc8ede77 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji' -> Encrypted drive 'TestCryptDrive:rclone-test-namemew1jaxa'
2024/11/27 04:50:31 DEBUG : empty space: md5 = 3e3ad118c1723b7c4b5f44a1d6e1871f OK
2024/11/27 04:50:33 DEBUG : potato3: md5 = b7fc0ea22dbe2f20ef93ad3cb761c77a OK
2024/11/27 04:50:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-namemew1jaxa': Using server-side directory move
2024/11/27 04:50:33 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-namemew1jaxa': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/27 04:50:34 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/27 04:50:34 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/11/27 04:50:34 DEBUG : empty space: Unchanged skipping
2024/11/27 04:50:34 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/27 04:50:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-namemew1jaxa': Waiting for checks to finish
2024/11/27 04:50:34 INFO  : potato3: Deleted
2024/11/27 04:50:34 INFO  : empty space: Deleted
2024/11/27 04:50:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-namemew1jaxa': Waiting for transfers to finish
2024/11/27 04:50:35 INFO  : potato2: Moved (server-side)
2024/11/27 04:50:35 INFO  : potato3: Moved (server-side)
2024/11/27 04:50:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gogurek0tazu"
2024/11/27 04:50:36 DEBUG : Creating backend with remote "TestDrive:crypt/qbid8cts440jj7mrkkeq255n2dfqbsmj7l4vg3fbmv14k47l490g"
2024/11/27 04:50:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gogurek0tazu': Using server-side directory move
2024/11/27 04:50:37 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gogurek0tazu': Server side directory move succeeded
2024/11/27 04:50:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gogurek0tazu': Purge remote
2024/11/27 04:50:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-namemew1jaxa': Purge remote
2024/11/27 04:50:39 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (17.41s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:50:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kabulaj9sugi"
2024/11/27 04:50:40 DEBUG : Creating backend with remote "TestDrive:crypt/anq00s3rvqjci7pv1lru5268bj9fvrp2gl0ruq8i0kdqsqkqr61g"
2024/11/27 04:50:42 DEBUG : potato2: md5 = fdf889ea490ac1f5602feaf03d328623 OK
2024/11/27 04:50:44 DEBUG : empty space: md5 = 9222fd54aadcb3c5054a30e552bc3b50 OK
2024/11/27 04:50:46 DEBUG : potato3: md5 = c845feea632650b446bc9102ffd934ed OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji' -> Encrypted drive 'TestCryptDrive:rclone-test-kabulaj9sugi'
2024/11/27 04:50:49 DEBUG : empty space: md5 = ae68d9cb483bc217424c2ec4f13f0649 OK
2024/11/27 04:50:50 DEBUG : potato3: md5 = fe97cb033b6f52c6586a33b5aadccb01 OK
2024/11/27 04:50:51 DEBUG : empty space: Excluded (Size Filter)
2024/11/27 04:50:51 DEBUG : empty space: Excluded (Size Filter)
2024/11/27 04:50:51 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/27 04:50:51 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/27 04:50:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kabulaj9sugi': Waiting for checks to finish
2024/11/27 04:50:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kabulaj9sugi': Waiting for transfers to finish
2024/11/27 04:50:52 INFO  : potato3: Deleted
2024/11/27 04:50:52 INFO  : potato2: Moved (server-side)
2024/11/27 04:50:52 INFO  : potato3: Moved (server-side)
2024/11/27 04:50:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jesoval9caha"
2024/11/27 04:50:53 DEBUG : Creating backend with remote "TestDrive:crypt/b8higkousgi3hrs7gtc0jcjs7kvpp0epb3s2gsuqbtf8ghs78vrg"
2024/11/27 04:50:54 DEBUG : empty space: Excluded (Size Filter)
2024/11/27 04:50:54 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/27 04:50:54 DEBUG : potato3: Need to transfer - File not found at Destination
2024/11/27 04:50:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jesoval9caha': Waiting for checks to finish
2024/11/27 04:50:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jesoval9caha': Waiting for transfers to finish
2024/11/27 04:50:56 INFO  : potato2: Moved (server-side)
2024/11/27 04:50:56 INFO  : potato3: Moved (server-side)
2024/11/27 04:50:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jesoval9caha': Purge remote
2024/11/27 04:50:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kabulaj9sugi': Purge remote
--- PASS: TestServerSideMoveWithFilter (19.51s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:50:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zozarer7pavi"
2024/11/27 04:50:59 DEBUG : Creating backend with remote "TestDrive:crypt/6496jgv9f6usplafangmqu2346foaup6pf2o458a1tdd27kf12rg"
2024/11/27 04:51:02 DEBUG : potato2: md5 = c413bd5f2a54b2f381ef9152d19cf919 OK
2024/11/27 04:51:04 DEBUG : empty space: md5 = 988ee5ab5e3e8c8e3c9045a1fcb14eea OK
2024/11/27 04:51:05 DEBUG : potato3: md5 = 52035466355882e053e2bc6a6b082123 OK
2024/11/27 04:51:05 DEBUG : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji' -> Encrypted drive 'TestCryptDrive:rclone-test-zozarer7pavi'
2024/11/27 04:51:10 DEBUG : empty space: md5 = ac144c1cc1d8abb615b9842afca91096 OK
2024/11/27 04:51:11 DEBUG : potato3: md5 = 8f8528b1699d1d500fb3ca15885bf9d5 OK
2024/11/27 04:51:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zozarer7pavi': Using server-side directory move
2024/11/27 04:51:12 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-zozarer7pavi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/27 04:51:12 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/27 04:51:12 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2024/11/27 04:51:12 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/11/27 04:51:12 DEBUG : empty space: Unchanged skipping
2024/11/27 04:51:12 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/27 04:51:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zozarer7pavi': Waiting for checks to finish
2024/11/27 04:51:13 INFO  : empty space: Deleted
2024/11/27 04:51:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zozarer7pavi': Waiting for transfers to finish
2024/11/27 04:51:13 INFO  : potato3: Deleted
2024/11/27 04:51:13 INFO  : potato2: Moved (server-side)
2024/11/27 04:51:14 INFO  : potato3: Moved (server-side)
2024/11/27 04:51:14 INFO  : tomatoDir: Removing directory
2024/11/27 04:51:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': deleted 1 directories
2024/11/27 04:51:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jejeric9zode"
2024/11/27 04:51:15 DEBUG : Creating backend with remote "TestDrive:crypt/lrl7ruvs5i2ebogpireffh5o67rrmobpndana1j4tq30bukktjl0"
2024/11/27 04:51:16 DEBUG : tomatoDir: Making directory
2024/11/27 04:51:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jejeric9zode': Using server-side directory move
2024/11/27 04:51:18 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-jejeric9zode': Server side directory move succeeded
2024/11/27 04:51:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jejeric9zode': Purge remote
2024/11/27 04:51:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zozarer7pavi': Purge remote
2024/11/27 04:51:20 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (21.63s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.43s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:51:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/rclone-sync-test"
2024/11/27 04:51:21 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncOverlap (3.77s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:51:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/rclone-sync-test"
2024/11/27 04:51:25 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2024/11/27 04:51:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/rclone-sync-test-include/layer2"
2024/11/27 04:51:28 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2024/11/27 04:51:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/rclone-sync-test-ignore-file"
2024/11/27 04:51:33 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2024/11/27 04:51:38 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 6a4439e490f096736b5bf866e801d33d OK
2024/11/27 04:51:40 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/27 04:51:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/rclone-sync-test': Waiting for checks to finish
2024/11/27 04:51:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/rclone-sync-test': Waiting for transfers to finish
2024/11/27 04:51:40 DEBUG : Waiting for deletions to finish
2024/11/27 04:51:40 INFO  : There was nothing to transfer
2024/11/27 04:51:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:51:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:51:41 DEBUG : Waiting for deletions to finish
2024/11/27 04:51:41 INFO  : rclone-sync-test-include: Removing directory
2024/11/27 04:51:42 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/27 04:51:42 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/11/27 04:51:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': failed to delete 1 directories
2024/11/27 04:51:42 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:51:43 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/27 04:51:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/rclone-sync-test-include/layer2': Waiting for checks to finish
2024/11/27 04:51:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/rclone-sync-test-include/layer2': Waiting for transfers to finish
2024/11/27 04:51:43 DEBUG : Waiting for deletions to finish
2024/11/27 04:51:43 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:51:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:51:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:51:45 DEBUG : Waiting for deletions to finish
2024/11/27 04:51:45 INFO  : rclone-sync-test-include: Removing directory
2024/11/27 04:51:46 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/27 04:51:46 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/11/27 04:51:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': failed to delete 1 directories
2024/11/27 04:51:46 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:51:48 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/27 04:51:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/rclone-sync-test-ignore-file': Waiting for checks to finish
2024/11/27 04:51:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/rclone-sync-test-ignore-file': Waiting for transfers to finish
2024/11/27 04:51:48 DEBUG : Waiting for deletions to finish
2024/11/27 04:51:48 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:51:50 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/27 04:51:51 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (34.95s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:52:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/dst"
2024/11/27 04:52:00 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/27 04:52:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/CompareDest"
2024/11/27 04:52:01 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/gveqi14airsml4bgu7krj116o8"
2024/11/27 04:52:03 DEBUG : one: Need to transfer - File not found at Destination
2024/11/27 04:52:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:52:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:52:06 DEBUG : one: md5 = e0804014b835eaf6fc15fa4c2310ffb0 OK
2024/11/27 04:52:06 INFO  : one: Copied (new)
2024/11/27 04:52:06 DEBUG : Waiting for deletions to finish
2024/11/27 04:52:07 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/27 04:52:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:52:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:52:09 DEBUG : one: md5 = 5ad2557ea337ace87f3e1cfd9842076d OK
2024/11/27 04:52:09 INFO  : one: Copied (replaced existing)
2024/11/27 04:52:09 DEBUG : Waiting for deletions to finish
2024/11/27 04:52:11 DEBUG : dst/one: md5 = 859204d89ff0c7f83d2e910eb7075f85 OK
2024/11/27 04:52:14 DEBUG : CompareDest/one: md5 = 0d1d1fb5c6667cb93b630512f1d06061 OK
2024/11/27 04:52:14 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/27 04:52:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:52:15 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:52:15 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/27 04:52:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:52:15 DEBUG : Waiting for deletions to finish
2024/11/27 04:52:15 INFO  : There was nothing to transfer
2024/11/27 04:52:17 DEBUG : CompareDest/two: md5 = 6f5e030806833cb62d346e5615a60be7 OK
2024/11/27 04:52:18 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:52:18 DEBUG : two: Destination found in --compare-dest, skipping
2024/11/27 04:52:18 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/27 04:52:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:52:18 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:52:18 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/27 04:52:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:52:18 DEBUG : Waiting for deletions to finish
2024/11/27 04:52:18 INFO  : There was nothing to transfer
2024/11/27 04:52:19 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:52:19 DEBUG : two: Destination found in --compare-dest, skipping
2024/11/27 04:52:19 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/27 04:52:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:52:20 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:52:20 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/27 04:52:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:52:20 DEBUG : Waiting for deletions to finish
2024/11/27 04:52:20 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2024/11/27 04:52:21 DEBUG : two: Sizes differ (src 5 vs dst 3)
2024/11/27 04:52:21 DEBUG : two: Need to transfer - File not found at Destination
2024/11/27 04:52:21 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/27 04:52:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:52:21 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:52:21 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/27 04:52:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:52:23 DEBUG : two: md5 = 330bfe8920f0b758d2a10c2dc2d2cbb7 OK
2024/11/27 04:52:23 INFO  : two: Copied (new)
2024/11/27 04:52:23 DEBUG : Waiting for deletions to finish
2024/11/27 04:52:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/27 04:52:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/27 04:52:27 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/27 04:52:27 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncCompareDest (27.77s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:52:30 DEBUG : pre-dest1/1: md5 = 0a6d5e7acec6b939c221f7bf858799c2 OK
2024/11/27 04:52:33 DEBUG : pre-dest2/2: md5 = aa6d5cbb5511363c6afd802e737d0349 OK
2024/11/27 04:52:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/dest"
2024/11/27 04:52:34 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/rg03c1jvnehrrc617i0lnqjddc"
2024/11/27 04:52:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/pre-dest1"
2024/11/27 04:52:35 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/bbnblvh6k061ssopqrp18kd7gc"
2024/11/27 04:52:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/pre-dest2"
2024/11/27 04:52:36 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/dgicm1h6b5ejvlltm8eeif0bnk"
2024/11/27 04:52:37 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:52:37 DEBUG : 1: Destination found in --compare-dest, skipping
2024/11/27 04:52:38 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:52:38 DEBUG : 2: Destination found in --compare-dest, skipping
2024/11/27 04:52:38 DEBUG : 3: Need to transfer - File not found at Destination
2024/11/27 04:52:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dest': Waiting for checks to finish
2024/11/27 04:52:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dest': Waiting for transfers to finish
2024/11/27 04:52:41 DEBUG : 3: md5 = 4abb668e965a3f68d8802770206f0c02 OK
2024/11/27 04:52:41 INFO  : 3: Copied (new)
2024/11/27 04:52:41 DEBUG : Waiting for deletions to finish
2024/11/27 04:52:44 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2024/11/27 04:52:45 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2024/11/27 04:52:46 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (18.87s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:52:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/dst"
2024/11/27 04:52:47 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/27 04:52:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/CopyDest"
2024/11/27 04:52:48 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/d09o6po3f7bm6ce32vdgs8h9ls"
2024/11/27 04:52:50 DEBUG : one: Need to transfer - File not found at Destination
2024/11/27 04:52:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:52:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:52:52 DEBUG : one: md5 = 7fc856756f9911095ec902a8ab92b20a OK
2024/11/27 04:52:52 INFO  : one: Copied (new)
2024/11/27 04:52:52 DEBUG : Waiting for deletions to finish
2024/11/27 04:52:54 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/27 04:52:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:52:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:52:55 DEBUG : one: md5 = 41e34a4c86a7a3866f72ba4cad4edf9a OK
2024/11/27 04:52:55 INFO  : one: Copied (replaced existing)
2024/11/27 04:52:55 DEBUG : Waiting for deletions to finish
2024/11/27 04:52:57 DEBUG : dst/one: md5 = 4035fa9936bbc7a2eca146cf3175eed1 OK
2024/11/27 04:53:00 DEBUG : CopyDest/one: md5 = 288f8031e4f9914ba9a6562e3154ce4b OK
2024/11/27 04:53:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/BackupDir"
2024/11/27 04:53:01 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/s6dbk3lfi7c9kfvo6j7bla9m0g"
2024/11/27 04:53:02 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/27 04:53:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:53:03 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:53:03 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/27 04:53:05 INFO  : one: Moved (server-side)
2024/11/27 04:53:06 INFO  : one: Copied (server-side copy)
2024/11/27 04:53:06 DEBUG : one: Destination found in --copy-dest, using server-side copy
2024/11/27 04:53:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:53:06 DEBUG : Waiting for deletions to finish
2024/11/27 04:53:09 DEBUG : CopyDest/two: md5 = 71098632d474720aee31d439ec9d9fec OK
2024/11/27 04:53:10 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:53:11 INFO  : two: Copied (server-side copy)
2024/11/27 04:53:11 DEBUG : two: Destination found in --copy-dest, using server-side copy
2024/11/27 04:53:11 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:53:11 DEBUG : one: Unchanged skipping
2024/11/27 04:53:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:53:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:53:11 DEBUG : Waiting for deletions to finish
2024/11/27 04:53:12 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:53:12 DEBUG : one: Unchanged skipping
2024/11/27 04:53:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:53:12 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:53:12 DEBUG : two: Unchanged skipping
2024/11/27 04:53:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:53:12 DEBUG : Waiting for deletions to finish
2024/11/27 04:53:12 INFO  : There was nothing to transfer
2024/11/27 04:53:14 DEBUG : CopyDest/three: md5 = e357059b09299e5e25d128fa59f012f6 OK
2024/11/27 04:53:15 DEBUG : three: Sizes differ (src 7 vs dst 5)
2024/11/27 04:53:15 DEBUG : three: Destination not found in --copy-dest
2024/11/27 04:53:15 DEBUG : three: Need to transfer - File not found at Destination
2024/11/27 04:53:15 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:53:15 DEBUG : one: Unchanged skipping
2024/11/27 04:53:15 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/27 04:53:15 DEBUG : two: Unchanged skipping
2024/11/27 04:53:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:53:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:53:16 DEBUG : three: md5 = 553429b4f02fcb2741b969f8a039a44d OK
2024/11/27 04:53:16 INFO  : three: Copied (new)
2024/11/27 04:53:16 DEBUG : Waiting for deletions to finish
2024/11/27 04:53:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/11/27 04:53:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/27 04:53:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/27 04:53:22 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/27 04:53:22 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/11/27 04:53:22 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/27 04:53:23 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (37.26s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:53:27 DEBUG : dst/one: md5 = 136beafbd9b1376d44912abd69b26adf OK
2024/11/27 04:53:28 DEBUG : dst/two: md5 = 442e2f2758b68518962610896f453a96 OK
2024/11/27 04:53:30 DEBUG : dst/three.txt: md5 = 3061132d62602dfed66c3ed55dea5ed1 OK
2024/11/27 04:53:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/dst"
2024/11/27 04:53:31 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/27 04:53:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/backup"
2024/11/27 04:53:31 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/1nrff024r7pq65ecp72fc28jb0"
2024/11/27 04:53:33 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/27 04:53:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:53:33 DEBUG : two: Unchanged skipping
2024/11/27 04:53:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:53:36 INFO  : one: Moved (server-side)
2024/11/27 04:53:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:53:38 DEBUG : one: md5 = 08de1ac71b0c35b3c08dafd60ac3ecd3 OK
2024/11/27 04:53:38 INFO  : one: Copied (new)
2024/11/27 04:53:38 DEBUG : Waiting for deletions to finish
2024/11/27 04:53:39 INFO  : three.txt: Moved (server-side)
2024/11/27 04:53:39 INFO  : three.txt: Moved into backup dir
2024/11/27 04:53:41 DEBUG : dst/three.txt: md5 = dd9ab6ed41e8d034faeba69efe12575a OK
2024/11/27 04:53:42 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/27 04:53:42 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:53:42 DEBUG : two: Unchanged skipping
2024/11/27 04:53:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:53:42 INFO  : one: Deleted
2024/11/27 04:53:43 INFO  : one: Moved (server-side)
2024/11/27 04:53:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:53:45 DEBUG : one: md5 = ff5055be0680eb8ffbededd078f2df47 OK
2024/11/27 04:53:45 INFO  : one: Copied (new)
2024/11/27 04:53:45 DEBUG : Waiting for deletions to finish
2024/11/27 04:53:46 INFO  : three.txt: Deleted
2024/11/27 04:53:47 INFO  : three.txt: Moved (server-side)
2024/11/27 04:53:47 INFO  : three.txt: Moved into backup dir
2024/11/27 04:53:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/27 04:53:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/27 04:53:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/27 04:53:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/27 04:53:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/27 04:53:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncBackupDir (28.29s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:53:55 DEBUG : dst/one: md5 = aecc689be9150a5110e51f4ee0831140 OK
2024/11/27 04:53:57 DEBUG : dst/two: md5 = 3adf93be5a32bdfd9bdab79698307eb0 OK
2024/11/27 04:53:58 DEBUG : dst/three.txt: md5 = d4bc26b77800f45817015d1d4560a22c OK
2024/11/27 04:53:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/dst"
2024/11/27 04:53:59 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/27 04:53:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/backup"
2024/11/27 04:54:00 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/1nrff024r7pq65ecp72fc28jb0"
2024/11/27 04:54:01 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/27 04:54:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:54:01 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:54:01 DEBUG : two: Unchanged skipping
2024/11/27 04:54:03 INFO  : one: Moved (server-side) to: one.bak
2024/11/27 04:54:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:54:05 DEBUG : one: md5 = 90952271d1e0458afbf28a7c9813f239 OK
2024/11/27 04:54:05 INFO  : one: Copied (new)
2024/11/27 04:54:05 DEBUG : Waiting for deletions to finish
2024/11/27 04:54:06 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/27 04:54:06 INFO  : three.txt: Moved into backup dir
2024/11/27 04:54:08 DEBUG : dst/three.txt: md5 = 17dc8b4980f61615a1b119928dbcbcbb OK
2024/11/27 04:54:09 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/27 04:54:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:54:09 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:54:09 DEBUG : two: Unchanged skipping
2024/11/27 04:54:10 INFO  : one.bak: Deleted
2024/11/27 04:54:11 INFO  : one: Moved (server-side) to: one.bak
2024/11/27 04:54:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:54:13 DEBUG : one: md5 = 24027326438a4f56eb94c14eaa6d4931 OK
2024/11/27 04:54:13 INFO  : one: Copied (new)
2024/11/27 04:54:13 DEBUG : Waiting for deletions to finish
2024/11/27 04:54:14 INFO  : three.txt.bak: Deleted
2024/11/27 04:54:15 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/27 04:54:15 INFO  : three.txt: Moved into backup dir
2024/11/27 04:54:18 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/27 04:54:18 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/27 04:54:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/27 04:54:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/27 04:54:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/27 04:54:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirWithSuffix (27.53s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:54:23 DEBUG : dst/one: md5 = 848146b7faf6ef018de27284d13a2a87 OK
2024/11/27 04:54:24 DEBUG : dst/two: md5 = 256da58d3578efa0225befbb440210ed OK
2024/11/27 04:54:26 DEBUG : dst/three.txt: md5 = d2980f38484bcd8bcfda60fdb98e6361 OK
2024/11/27 04:54:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/dst"
2024/11/27 04:54:27 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/27 04:54:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/backup"
2024/11/27 04:54:27 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/1nrff024r7pq65ecp72fc28jb0"
2024/11/27 04:54:29 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/27 04:54:29 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:54:29 DEBUG : two: Unchanged skipping
2024/11/27 04:54:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:54:31 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/27 04:54:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:54:33 DEBUG : one: md5 = e6e74d42ac4893a04ca796955fa47887 OK
2024/11/27 04:54:33 INFO  : one: Copied (new)
2024/11/27 04:54:33 DEBUG : Waiting for deletions to finish
2024/11/27 04:54:34 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/27 04:54:34 INFO  : three.txt: Moved into backup dir
2024/11/27 04:54:36 DEBUG : dst/three.txt: md5 = 671604554f761019112286a7be48f94d OK
2024/11/27 04:54:37 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/27 04:54:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:54:37 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:54:37 DEBUG : two: Unchanged skipping
2024/11/27 04:54:38 INFO  : one-2019-01-01: Deleted
2024/11/27 04:54:39 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/27 04:54:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:54:40 DEBUG : one: md5 = 529c0c01219cfbfaa4e113f3b048d241 OK
2024/11/27 04:54:40 INFO  : one: Copied (new)
2024/11/27 04:54:40 DEBUG : Waiting for deletions to finish
2024/11/27 04:54:41 INFO  : three-2019-01-01.txt: Deleted
2024/11/27 04:54:42 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/27 04:54:42 INFO  : three.txt: Moved into backup dir
2024/11/27 04:54:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/27 04:54:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/27 04:54:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/27 04:54:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/27 04:54:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/27 04:54:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (27.57s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:54:50 DEBUG : dst/one: md5 = 2b147cd4026e209b615088e9ceca6704 OK
2024/11/27 04:54:52 DEBUG : dst/two: md5 = 306c1562ec28de7b25dd115e62f74cab OK
2024/11/27 04:54:53 DEBUG : dst/three.txt: md5 = c3af78b9085aea9c2c51ab832a53a3ec OK
2024/11/27 04:54:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/dst"
2024/11/27 04:54:54 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/27 04:54:55 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/27 04:54:55 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:54:55 DEBUG : two: Unchanged skipping
2024/11/27 04:54:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:54:56 INFO  : one: Moved (server-side) to: one.bak
2024/11/27 04:54:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:54:58 DEBUG : one: md5 = 4870a65b19f3e3a41eacc1174d693458 OK
2024/11/27 04:54:58 INFO  : one: Copied (new)
2024/11/27 04:54:58 DEBUG : Waiting for deletions to finish
2024/11/27 04:54:58 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/27 04:54:58 INFO  : three.txt: Moved into backup dir
2024/11/27 04:55:00 DEBUG : dst/three.txt: md5 = 7e4e51f03dbc6b7e294df46e28e63dbb OK
2024/11/27 04:55:01 DEBUG : three.txt.bak: Excluded (Path Filter)
2024/11/27 04:55:01 DEBUG : one.bak: Excluded (Path Filter)
2024/11/27 04:55:01 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/27 04:55:01 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:55:01 DEBUG : two: Unchanged skipping
2024/11/27 04:55:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for checks to finish
2024/11/27 04:55:02 INFO  : one.bak: Deleted
2024/11/27 04:55:03 INFO  : one: Moved (server-side) to: one.bak
2024/11/27 04:55:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji/dst': Waiting for transfers to finish
2024/11/27 04:55:05 DEBUG : one: md5 = f9609a2f59188a28f7924771774e2684 OK
2024/11/27 04:55:05 INFO  : one: Copied (new)
2024/11/27 04:55:05 DEBUG : Waiting for deletions to finish
2024/11/27 04:55:05 INFO  : three.txt.bak: Deleted
2024/11/27 04:55:06 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/27 04:55:06 INFO  : three.txt: Moved into backup dir
2024/11/27 04:55:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/27 04:55:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/27 04:55:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/27 04:55:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/27 04:55:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/27 04:55:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirSuffixOnly (23.28s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:55:13 DEBUG : dst/one: md5 = 4cad041cda6dbae74c61005d04f9b77a OK
2024/11/27 04:55:15 DEBUG : dst/two: md5 = cdd415162085fe5776cc0b36de1857d6 OK
2024/11/27 04:55:16 DEBUG : dst/three.txt: md5 = d35105dfb7c913f7de9cf49929962781 OK
2024/11/27 04:55:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/dst"
2024/11/27 04:55:17 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/27 04:55:18 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/27 04:55:19 INFO  : one: Moved (server-side) to: one.bak
2024/11/27 04:55:20 DEBUG : one: md5 = bebe60b552fcd9a13661d65572b4b5d9 OK
2024/11/27 04:55:20 INFO  : one: Copied (new)
2024/11/27 04:55:21 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:55:21 DEBUG : two: Unchanged skipping
2024/11/27 04:55:21 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/11/27 04:55:22 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/27 04:55:23 DEBUG : three.txt: md5 = ebb271a856195c8535fb725a8ba539a8 OK
2024/11/27 04:55:23 INFO  : three.txt: Copied (new)
2024/11/27 04:55:25 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/27 04:55:26 INFO  : one.bak: Deleted
2024/11/27 04:55:26 INFO  : one: Moved (server-side) to: one.bak
2024/11/27 04:55:28 DEBUG : one: md5 = 2f87e28bfa588120572320af70f50d8d OK
2024/11/27 04:55:28 INFO  : one: Copied (new)
2024/11/27 04:55:28 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:55:28 DEBUG : two: Unchanged skipping
2024/11/27 04:55:28 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/11/27 04:55:29 INFO  : three.txt.bak: Deleted
2024/11/27 04:55:30 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/27 04:55:31 DEBUG : three.txt: md5 = a0023959609e05860ad43e57f433a242 OK
2024/11/27 04:55:31 INFO  : three.txt: Copied (new)
2024/11/27 04:55:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/27 04:55:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/27 04:55:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/27 04:55:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/27 04:55:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/27 04:55:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/27 04:55:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncSuffix (25.73s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:55:39 DEBUG : dst/one: md5 = 4c7e72404221d51c003d40f5dc923d4f OK
2024/11/27 04:55:41 DEBUG : dst/two: md5 = cec1e0a3ca63d938491faec3c9c86847 OK
2024/11/27 04:55:42 DEBUG : dst/three.txt: md5 = 46a3810d6b83131e1fcb41560e513cdb OK
2024/11/27 04:55:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mikoduj6wiji/dst"
2024/11/27 04:55:43 DEBUG : Creating backend with remote "TestDrive:crypt/n7371nfia0ahqo5a6gb70v5hasevej6jlp9dphv3feqc2kvfp1hg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/27 04:55:44 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/27 04:55:45 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/27 04:55:46 DEBUG : one: md5 = 17f394297fe76808d18062d128ded567 OK
2024/11/27 04:55:46 INFO  : one: Copied (new)
2024/11/27 04:55:47 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:55:47 DEBUG : two: Unchanged skipping
2024/11/27 04:55:47 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/11/27 04:55:48 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/27 04:55:49 DEBUG : three.txt: md5 = b5f0378fbb206b66a904db82cf616433 OK
2024/11/27 04:55:49 INFO  : three.txt: Copied (new)
2024/11/27 04:55:51 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/27 04:55:51 INFO  : one-2019-01-01: Deleted
2024/11/27 04:55:52 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/27 04:55:54 DEBUG : one: md5 = 6aeb01a8bcc836edd7f302f1a2e5b29d OK
2024/11/27 04:55:54 INFO  : one: Copied (new)
2024/11/27 04:55:54 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:55:54 DEBUG : two: Unchanged skipping
2024/11/27 04:55:54 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/11/27 04:55:55 INFO  : three-2019-01-01.txt: Deleted
2024/11/27 04:55:56 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/27 04:55:57 DEBUG : three.txt: md5 = 0e56f78169ff93914e1bf14acd0a2ea6 OK
2024/11/27 04:55:57 INFO  : three.txt: Copied (new)
2024/11/27 04:56:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/27 04:56:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/27 04:56:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/27 04:56:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/27 04:56:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/27 04:56:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/27 04:56:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncSuffixKeepExtension (25.97s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:56:04 DEBUG : Testêé: md5 = 9ea0d091ecff9befba866df35f94ba59 OK
2024/11/27 04:56:04 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2024/11/27 04:56:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:56:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:56:06 DEBUG : Testêé: md5 = 290e8e8474cb326cf64426032d4967b6 OK
2024/11/27 04:56:06 INFO  : Testêé: Copied (replaced existing) to: Testêé
2024/11/27 04:56:06 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (4.77s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:56:07 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/27 04:56:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:56:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:56:10 DEBUG : existing: md5 = f916d07ca799e4d63e886688106ac0cd OK
2024/11/27 04:56:10 INFO  : existing: Copied (new)
2024/11/27 04:56:10 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:56:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:56:10 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2024/11/27 04:56:10 ERROR : existing: Source and destination exist but do not match: immutable file modified
2024/11/27 04:56:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:56:10 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': not deleting files as there were IO errors
2024/11/27 04:56:10 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncImmutable (5.60s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:56:14 DEBUG : EXISTING: md5 = f680007e623be7ff491a0e44a3f2c179 OK
2024/11/27 04:56:15 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:56:15 DEBUG : existing: Unchanged skipping
2024/11/27 04:56:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:56:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:56:15 DEBUG : Waiting for deletions to finish
2024/11/27 04:56:15 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (3.99s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.46s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", 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-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", 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-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.40s)
    --- SKIP: TestMaxTransfer/Hard (0.47s)
    --- SKIP: TestMaxTransfer/Soft (0.42s)
    --- SKIP: TestMaxTransfer/Cautious (0.51s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:56:20 DEBUG : both0: md5 = 41ce13d63a1ac30c7268aaf76cbfc160 OK
2024/11/27 04:56:22 DEBUG : only0: md5 = 2a45300fbfb4f3162c24d08914625e36 OK
2024/11/27 04:56:23 DEBUG : both1: md5 = b1fdbed54daecf76783c63d2d3d5508c OK
2024/11/27 04:56:25 DEBUG : only1: md5 = c56a93e1e35eb491d6606550234daefa OK
2024/11/27 04:56:27 DEBUG : both2: md5 = 1921de8541a3f5a0c9024f72e34d034b OK
2024/11/27 04:56:29 DEBUG : only2: md5 = d115f309f1fed1b8dd3e439b7c40020a OK
2024/11/27 04:56:30 DEBUG : both3: md5 = 74d1d409295aee80f6d464d50b4708e9 OK
2024/11/27 04:56:32 DEBUG : only3: md5 = ba066a3929db69fad3f3b33658b1f65e OK
2024/11/27 04:56:34 DEBUG : both4: md5 = 442bc97e76eb4f2ba623891913cac960 OK
2024/11/27 04:56:35 DEBUG : only4: md5 = 3014e0026ac02f60a307cc89efa2b94a OK
2024/11/27 04:56:37 DEBUG : both5: md5 = e6b094416ee6fa1506772402455521d8 OK
2024/11/27 04:56:39 DEBUG : only5: md5 = 1f9613e566f83d1e559dd2d9da181094 OK
2024/11/27 04:56:41 DEBUG : both6: md5 = 8740bf1bffad59bd83ef9da34603165a OK
2024/11/27 04:56:42 DEBUG : only6: md5 = 14683eeed3e44e96efdb9eaa3169c4b3 OK
2024/11/27 04:56:44 DEBUG : both7: md5 = dc387f7ac995e3b64335a551f2613181 OK
2024/11/27 04:56:45 DEBUG : only7: md5 = 5eebdd91abda5f1522bbea4723d12de7 OK
2024/11/27 04:56:47 DEBUG : both8: md5 = 17a97963525099689b7a25c36c2f99bc OK
2024/11/27 04:56:50 DEBUG : only8: md5 = c2a9301c16f2a708188ea15a96729d48 OK
2024/11/27 04:56:51 DEBUG : both9: md5 = dbdb451598dbebca9dff3a6d1355b0ee OK
2024/11/27 04:56:53 DEBUG : only9: md5 = 465e4542f805b6b52962cd33e3f21323 OK
2024/11/27 04:56:55 DEBUG : both10: md5 = 7b588742cf51185e53f665180376e245 OK
2024/11/27 04:56:56 DEBUG : only10: md5 = c693bb0268f1fb52ac0a89eae4d2b673 OK
2024/11/27 04:56:58 DEBUG : both11: md5 = 5037067b7c1a29cc197b6a446bbe5c16 OK
2024/11/27 04:56:59 DEBUG : only11: md5 = 2de9bbdebb51b0cc38ece021265d63aa OK
2024/11/27 04:57:01 DEBUG : both12: md5 = 33643c3a984462253ae5daecf6736b62 OK
2024/11/27 04:57:03 DEBUG : only12: md5 = d9a74efe74acec1c1f7be764f5915b7c OK
2024/11/27 04:57:04 DEBUG : both13: md5 = 6e693d148f0bb3aa6dc2a3640a87b0a7 OK
2024/11/27 04:57:06 DEBUG : only13: md5 = b6bcb476b31d91d5d3168a9c3ac60d4f OK
2024/11/27 04:57:08 DEBUG : both14: md5 = 4c0142d3561cc05d897521dc67a9278d OK
2024/11/27 04:57:09 DEBUG : only14: md5 = 143f54c9e55b00d81b6f0518bb3108af OK
2024/11/27 04:57:11 DEBUG : both15: md5 = 063d17aaf4c556f58410c8716bd512f4 OK
2024/11/27 04:57:13 DEBUG : only15: md5 = 91afc6fd16ecbce3a5979e56d2990ebb OK
2024/11/27 04:57:14 DEBUG : both16: md5 = a7fb81a0ef076340fbe77d2018379f45 OK
2024/11/27 04:57:16 DEBUG : only16: md5 = 5733fe1e85bc1b8349578a3018eb3dfa OK
2024/11/27 04:57:18 DEBUG : both17: md5 = 65d4db2ecfdeb726204bb472321b2da8 OK
2024/11/27 04:57:19 DEBUG : only17: md5 = 03806b6fcbddb72caaebc2215e7f2b33 OK
2024/11/27 04:57:21 DEBUG : both18: md5 = e41a1cf75ed924630509d2f631aad297 OK
2024/11/27 04:57:23 DEBUG : only18: md5 = b5aa1175566da5419dad88bd4cf7f491 OK
2024/11/27 04:57:24 DEBUG : both19: md5 = 9458efc15f0c0aca26037f5762ea5106 OK
2024/11/27 04:57:26 DEBUG : only19: md5 = 45d07611e5c3f18590a666151cd33351 OK
2024/11/27 04:57:27 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both0: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both1: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both10: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both11: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both12: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both13: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both14: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both15: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both16: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both17: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both18: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both19: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both2: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both3: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both4: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both5: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:57:27 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:57:27 DEBUG : both6: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both7: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both8: Unchanged skipping
2024/11/27 04:57:27 DEBUG : both9: Unchanged skipping
2024/11/27 04:57:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:57:27 DEBUG : Waiting for deletions to finish
2024/11/27 04:57:27 INFO  : only10: Deleted
2024/11/27 04:57:27 INFO  : only17: Deleted
2024/11/27 04:57:27 INFO  : only1: Deleted
2024/11/27 04:57:27 INFO  : only15: Deleted
2024/11/27 04:57:28 INFO  : only18: Deleted
2024/11/27 04:57:28 INFO  : only12: Deleted
2024/11/27 04:57:28 INFO  : only2: Deleted
2024/11/27 04:57:28 INFO  : only13: Deleted
2024/11/27 04:57:28 INFO  : only9: Deleted
2024/11/27 04:57:28 INFO  : only16: Deleted
2024/11/27 04:57:28 INFO  : only3: Deleted
2024/11/27 04:57:28 INFO  : only19: Deleted
2024/11/27 04:57:29 INFO  : only5: Deleted
2024/11/27 04:57:29 INFO  : only6: Deleted
2024/11/27 04:57:29 INFO  : only0: Deleted
2024/11/27 04:57:29 INFO  : only8: Deleted
2024/11/27 04:57:29 INFO  : only11: Deleted
2024/11/27 04:57:29 INFO  : only14: Deleted
2024/11/27 04:57:30 INFO  : only4: Deleted
2024/11/27 04:57:30 INFO  : only7: Deleted
2024/11/27 04:57:30 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (83.38s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:57:44 DEBUG : both0: md5 = 7fbbbf068fab732a93d9860ba3ec2bdc OK
2024/11/27 04:57:45 DEBUG : only0: md5 = dce9699b70c82c5cb8f82816c9d81551 OK
2024/11/27 04:57:47 DEBUG : both1: md5 = 376f73909439c65cb801d0e41e0a2334 OK
2024/11/27 04:57:48 DEBUG : only1: md5 = a912e52aa131f1f0721505f1a5cc5e09 OK
2024/11/27 04:57:50 DEBUG : both2: md5 = ad0edd0ab39cf44a18248bc1c0e593ad OK
2024/11/27 04:57:52 DEBUG : only2: md5 = 43de21a3e2b05392085490e9a38f1dad OK
2024/11/27 04:57:54 DEBUG : both3: md5 = 9980bfeb0c35fbd190f2935a6e0c3cc0 OK
2024/11/27 04:57:55 DEBUG : only3: md5 = 37c08b7fc763037bdd9510547cda358c OK
2024/11/27 04:57:57 DEBUG : both4: md5 = 9ba8e8083621658827e70faabb7cd688 OK
2024/11/27 04:57:58 DEBUG : only4: md5 = da223c921b1e3b0b00357d8ca7d3a7a7 OK
2024/11/27 04:58:00 DEBUG : both5: md5 = be12188bdc3312746a8a02b9c67b040b OK
2024/11/27 04:58:02 DEBUG : only5: md5 = 21e3cc03af887d46692f5f3de0d6ab94 OK
2024/11/27 04:58:04 DEBUG : both6: md5 = 1d434e6eed9fc4db01a5d2061a30dac6 OK
2024/11/27 04:58:06 DEBUG : only6: md5 = 80e10aaf06e803ac400ba6c79dcc027f OK
2024/11/27 04:58:07 DEBUG : both7: md5 = c26f0aa9cb0d089cf7524132c5def40c OK
2024/11/27 04:58:09 DEBUG : only7: md5 = 2bc8715614f491b8dc133d7fc9c5444d OK
2024/11/27 04:58:11 DEBUG : both8: md5 = 2fec7b4499112a35503ce9f0cd17c74f OK
2024/11/27 04:58:12 DEBUG : only8: md5 = a59877a2d4e0df72146752a010705302 OK
2024/11/27 04:58:14 DEBUG : both9: md5 = 8b613ad922b86d2c032c9e2d84161214 OK
2024/11/27 04:58:16 DEBUG : only9: md5 = e49552d31412efd9506d87f8034c30ab OK
2024/11/27 04:58:18 DEBUG : both10: md5 = b0698ecd64a9ca6a3bc3fcf78c82d643 OK
2024/11/27 04:58:19 DEBUG : only10: md5 = 1e98b5fce1fa6e5f29d0e7fd86bd1600 OK
2024/11/27 04:58:21 DEBUG : both11: md5 = 164578627335da2ee363c8a281180292 OK
2024/11/27 04:58:23 DEBUG : only11: md5 = 99b137af0bb5a83154a8e52e4e54f384 OK
2024/11/27 04:58:24 DEBUG : both12: md5 = 45556ef2dbba789f8a2f9cd796240f6d OK
2024/11/27 04:58:26 DEBUG : only12: md5 = 332894365b912c26a73b2773c3f2c210 OK
2024/11/27 04:58:28 DEBUG : both13: md5 = e530154cdcd36861d94f9dfa24d658dc OK
2024/11/27 04:58:30 DEBUG : only13: md5 = d19969b03c4975e9037357c447967d70 OK
2024/11/27 04:58:32 DEBUG : both14: md5 = e977f729cea70c97db17eba8c420a111 OK
2024/11/27 04:58:33 DEBUG : only14: md5 = ea95b0afe6b13b1866849f1c08ee4c92 OK
2024/11/27 04:58:35 DEBUG : both15: md5 = 502e2a878c0cd99fb6e75536fb17b649 OK
2024/11/27 04:58:37 DEBUG : only15: md5 = 2c0db830750746dcfc36f6ff9fc5c396 OK
2024/11/27 04:58:39 DEBUG : both16: md5 = af48181626d66928d4e56afdcbd22dac OK
2024/11/27 04:58:40 DEBUG : only16: md5 = 87294a43b2500299a45d2201210e1547 OK
2024/11/27 04:58:42 DEBUG : both17: md5 = b93b5e8c3d2de07698c644192bbdc1c3 OK
2024/11/27 04:58:44 DEBUG : only17: md5 = 269f77c0a599948314562d7e2f121e38 OK
2024/11/27 04:58:46 DEBUG : both18: md5 = cbc74280689e7e5707e474718f286e5c OK
2024/11/27 04:58:47 DEBUG : only18: md5 = c22ad1daa073d506a92470143c296f84 OK
2024/11/27 04:58:50 DEBUG : both19: md5 = b74dfe381c62d2f9270ed63faf466e85 OK
2024/11/27 04:58:51 DEBUG : only19: md5 = ec550ab56f8c16b8cfa1c95dddd500c7 OK
2024/11/27 04:58:52 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for checks to finish
2024/11/27 04:58:52 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both10: Unchanged skipping
2024/11/27 04:58:52 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both12: Unchanged skipping
2024/11/27 04:58:52 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both1: Unchanged skipping
2024/11/27 04:58:52 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both11: Unchanged skipping
2024/11/27 04:58:52 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both0: Unchanged skipping
2024/11/27 04:58:52 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both16: Unchanged skipping
2024/11/27 04:58:52 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both17: Unchanged skipping
2024/11/27 04:58:52 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both18: Unchanged skipping
2024/11/27 04:58:52 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both19: Unchanged skipping
2024/11/27 04:58:52 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both2: Unchanged skipping
2024/11/27 04:58:52 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both13: Unchanged skipping
2024/11/27 04:58:52 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both14: Unchanged skipping
2024/11/27 04:58:52 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both15: Unchanged skipping
2024/11/27 04:58:52 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both6: Unchanged skipping
2024/11/27 04:58:52 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both3: Unchanged skipping
2024/11/27 04:58:52 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both8: Unchanged skipping
2024/11/27 04:58:52 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/27 04:58:52 DEBUG : both4: Unchanged skipping
2024/11/27 04:58:52 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : both5: Unchanged skipping
2024/11/27 04:58:52 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : both7: Unchanged skipping
2024/11/27 04:58:52 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : both9: Unchanged skipping
2024/11/27 04:58:52 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2024/11/27 04:58:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Waiting for transfers to finish
2024/11/27 04:58:53 DEBUG : only10: md5 = c13d080e2871564ff4ad9f4c90a38c6a OK
2024/11/27 04:58:53 INFO  : only10: Copied (replaced existing)
2024/11/27 04:58:53 DEBUG : only1: md5 = 7e6973929b388ee1c5d77c01f802b542 OK
2024/11/27 04:58:53 INFO  : only1: Copied (replaced existing)
2024/11/27 04:58:53 DEBUG : only12: md5 = 30fe21d7d8c417c6626a59c5071a3cda OK
2024/11/27 04:58:53 INFO  : only12: Copied (replaced existing)
2024/11/27 04:58:53 DEBUG : only0: md5 = 2faef985d2d2a10541bb849b058713a7 OK
2024/11/27 04:58:53 INFO  : only0: Copied (replaced existing)
2024/11/27 04:58:54 DEBUG : only15: md5 = 8fde887812f40022d03a53d3c858c850 OK
2024/11/27 04:58:54 INFO  : only15: Copied (replaced existing)
2024/11/27 04:58:55 DEBUG : only17: md5 = 252c4680b993bd0c7b0fe63ba3633e59 OK
2024/11/27 04:58:55 INFO  : only17: Copied (replaced existing)
2024/11/27 04:58:55 DEBUG : only18: md5 = 10779630be5ca19fc7f52143dcba7a73 OK
2024/11/27 04:58:55 INFO  : only18: Copied (replaced existing)
2024/11/27 04:58:55 DEBUG : only16: md5 = 4efa57b9889125017d69cf513ca6c273 OK
2024/11/27 04:58:55 INFO  : only16: Copied (replaced existing)
2024/11/27 04:58:56 DEBUG : only19: md5 = 2d8f93463cec9ed0f16df0fdb7104281 OK
2024/11/27 04:58:56 INFO  : only19: Copied (replaced existing)
2024/11/27 04:58:56 DEBUG : only2: md5 = 626855a22312bbee79c9b28f964f87dc OK
2024/11/27 04:58:56 INFO  : only2: Copied (replaced existing)
2024/11/27 04:58:56 DEBUG : only3: md5 = 847edc4e01c7e77c8be9c9e195b47567 OK
2024/11/27 04:58:56 INFO  : only3: Copied (replaced existing)
2024/11/27 04:58:56 DEBUG : only4: md5 = eadbc3d9b8e4b80125aea1aea76c5026 OK
2024/11/27 04:58:56 INFO  : only4: Copied (replaced existing)
2024/11/27 04:58:57 DEBUG : only6: md5 = 10af1acda6a409748cb90bedf43d369e OK
2024/11/27 04:58:57 INFO  : only6: Copied (replaced existing)
2024/11/27 04:58:57 DEBUG : only5: md5 = 4ee7fa9c34a93f0fa2a30f12fa48ef79 OK
2024/11/27 04:58:57 INFO  : only5: Copied (replaced existing)
2024/11/27 04:58:57 DEBUG : only13: md5 = 7b1765246418c337bdec37c335f78b66 OK
2024/11/27 04:58:57 INFO  : only13: Copied (replaced existing)
2024/11/27 04:58:57 DEBUG : only8: md5 = bae4ce151136f2f2d3b1a2705877f3b0 OK
2024/11/27 04:58:57 INFO  : only8: Copied (replaced existing)
2024/11/27 04:58:58 DEBUG : only9: md5 = c36bf5bd60feb8923acf9030e7f8cdef OK
2024/11/27 04:58:58 INFO  : only9: Copied (replaced existing)
2024/11/27 04:58:58 DEBUG : only11: md5 = 01199d67df3e5e4e58750d4c45c27dc0 OK
2024/11/27 04:58:58 INFO  : only11: Copied (replaced existing)
2024/11/27 04:58:59 DEBUG : only14: md5 = 78048ead940319f370a0e36d06685454 OK
2024/11/27 04:58:59 INFO  : only14: Copied (replaced existing)
2024/11/27 04:58:59 DEBUG : only7: md5 = 7f6e14990873b89a6f3f04444a50d485 OK
2024/11/27 04:58:59 INFO  : only7: Copied (replaced existing)
2024/11/27 04:58:59 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (102.89s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:59:25 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/27 04:59:25 DEBUG : sub dir: Making directory with metadata
2024/11/27 04:59:26 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 04:59:47 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/27 04:59:48 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/27 04:59:48 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/27 04:59:48 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 05:00:03 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2024/11/27 05:00:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/27 05:00:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/11/27 05:00:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/11/27 05:00:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/27 05:00:08 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/27 05:00:09 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/27 05:00:10 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/27 05:00:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/27 05:00:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/11/27 05:00:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/27 05:00:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (50.10s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 05:00:15 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/27 05:00:15 DEBUG : sub dir: Making directory with metadata
2024/11/27 05:00:16 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 05:00:42 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/27 05:00:42 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/27 05:00:42 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/27 05:00:42 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji'", Local "Local file system at /tmp/rclone3356454917", Modify Window "1ms"
2024/11/27 05:00:56 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/27 05:00:57 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/11/27 05:00:58 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/11/27 05:00:59 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/27 05:01:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/27 05:01:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/27 05:01:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/27 05:01:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/27 05:01:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/11/27 05:01:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/27 05:01:04 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (51.55s)
PASS
2024/11/27 05:01:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mikoduj6wiji': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 17m59.203713374s (try 1/5)