"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5)
2024/11/29 02:00:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso"
2024/11/29 02:00:19 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/11/29 02:00:19 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g"
2024/11/29 02:00:20 DEBUG : Creating backend with remote "/tmp/rclone2006451156"
=== 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-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:00:22 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:00:22 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:00:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:00:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:00:22 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2024/11/29 02:00:22 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.61s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:00:23 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:00:23 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:00:23 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:00:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:00:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:00:26 DEBUG : sub dir/hello world: md5 = f7859f6b50387dd63855386ec7b495b8 OK
2024/11/29 02:00:26 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:00:27 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:00:29 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (7.54s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:00:30 DEBUG : metadata sub dir: Making directory with metadata
2024/11/29 02:00:30 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:00:30 DEBUG : empty metadata sub dir: Making directory with metadata
2024/11/29 02:00:30 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:00:30 DEBUG : Local file system at /tmp/rclone2006451156: File to upload is small (21 bytes), uploading instead of streaming
2024/11/29 02:00:30 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/11/29 02:00:30 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/11/29 02:00:30 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:00:31 DEBUG : Google drive root 'crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g': Skipping btime metadata as can't update it on an existing file: 2024-11-29T02:00:30.800411547Z
2024/11/29 02:00:32 INFO  : empty metadata sub dir: Updated directory metadata
2024/11/29 02:00:32 DEBUG : Google drive root 'crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g': Skipping btime metadata as can't update it on an existing file: 2024-11-29T02:00:30.800411547Z
2024/11/29 02:00:33 INFO  : metadata sub dir: Updated directory metadata
2024/11/29 02:00:33 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/11/29 02:00:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:00:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:00:35 DEBUG : metadata sub dir/hello metadata world: md5 = 7609655c94bbfdc69294d54226b2968e OK
2024/11/29 02:00:35 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:00:38 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (9.57s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:00:40 DEBUG : metadata sub dir: Making directory with metadata
2024/11/29 02:00:40 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:00:40 DEBUG : empty metadata sub dir: Making directory with metadata
2024/11/29 02:00:40 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:00:40 DEBUG : Local file system at /tmp/rclone2006451156: File to upload is small (21 bytes), uploading instead of streaming
2024/11/29 02:00:40 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/11/29 02:00:40 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/11/29 02:00:40 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:00:40 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2024/11/29 02:00:40 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2024/11/29 02:00:40 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/11/29 02:00:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:00:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:00:43 DEBUG : metadata sub dir/hello metadata world: md5 = 5ba18539b0ffa1d68cd1fd6592e077bd OK
2024/11/29 02:00:43 INFO  : metadata sub dir/hello metadata world: Copied (new)
2024/11/29 02:00:43 DEBUG : Google drive root 'crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g': Skipping btime metadata as can't update it on an existing file: 2024-11-29T02:00:40.372340322Z
2024/11/29 02:00:44 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:00:47 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (8.23s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:00:48 DEBUG : Creating backend with remote "/non-existing"
2024/11/29 02:00:48 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2024/11/29 02:00:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:00:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.15s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:00:49 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:00:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:00:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:00:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:00:52 DEBUG : sub dir/hello world: md5 = 8204a9976597798d7c196f663d75e670 OK
2024/11/29 02:00:52 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:00:53 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:00:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (7.01s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:00:56 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Running all checks before starting transfers
2024/11/29 02:00:56 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:00:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:00:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:00:56 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Checks finished, now starting transfers
2024/11/29 02:00:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:00:59 DEBUG : sub dir/hello world: md5 = 98b12e79797b52685d9b025c97ab456e OK
2024/11/29 02:00:59 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:01:00 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:01:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (7.00s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:01:03 ERROR : Ignoring --no-traverse with sync
2024/11/29 02:01:04 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:01:04 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:01:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:01:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:01:07 DEBUG : sub dir/hello world: md5 = 3953c44d510350ff1ad3e6b6d1ba190d OK
2024/11/29 02:01:07 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:01:07 DEBUG : Waiting for deletions to finish
2024/11/29 02:01:08 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:01:10 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (7.65s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:01:11 DEBUG : hello world2: Need to transfer - File not found at Destination
2024/11/29 02:01:11 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:01:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:01:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:01:13 DEBUG : hello world2: md5 = 05c712eff7606dd7c46a8b93219da3dc OK
2024/11/29 02:01:13 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestCopyWithDepth (3.94s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:01:15 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:01:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:01:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:01:17 DEBUG : potato2: md5 = 012241f8abcbf6008593b489022852b7 OK
2024/11/29 02:01:17 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.90s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:01:19 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:01:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:01:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:01:21 DEBUG : potato2: md5 = 7aa27dc229908687023dd438e95c2115 OK
2024/11/29 02:01:21 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (4.13s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:01:23 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/29 02:01:23 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:01:23 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/29 02:01:23 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:01:23 DEBUG : sub dir: Making directory with metadata
2024/11/29 02:01:24 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/29 02:01:24 DEBUG : sub dir2: Making directory with metadata
2024/11/29 02:01:25 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:01:25 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/29 02:01:25 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:01:26 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:01:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:01:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:01:27 DEBUG : sub dir/hello world: md5 = fd40602c97adcd3890282e888185fcd7 OK
2024/11/29 02:01:27 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:01:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2024/11/29 02:01:32 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (10.73s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:01:34 DEBUG : sub dir2: Making directory
2024/11/29 02:01:34 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/29 02:01:34 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:01:34 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:01:34 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/29 02:01:34 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2024/11/29 02:01:34 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:01:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:01:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:01:37 DEBUG : sub dir/hello world: md5 = 4e3938b8a0ebd4a26dd663ec3d36f812 OK
2024/11/29 02:01:37 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:01:38 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:01:40 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (7.03s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:01:41 DEBUG : sub dir2: Making directory with metadata
2024/11/29 02:01:41 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:01:41 DEBUG : sub dir: Making directory with metadata
2024/11/29 02:01:42 INFO  : sub dir: Made directory with metadata (mtime=2024-11-29T02:01:41.135889877Z)
2024/11/29 02:01:42 DEBUG : sub dir2: Making directory with metadata
2024/11/29 02:01:43 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:01:43 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:01:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:01:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:01:45 DEBUG : sub dir/hello world: md5 = 9b977b69e3873876f48fb0bb55acc1f0 OK
2024/11/29 02:01:45 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:01:45 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:01:49 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (9.29s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:01:50 DEBUG : sub dir no update dir modtime: Making directory with metadata
2024/11/29 02:01:50 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/29 02:01:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:01:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:01:52 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (4.61s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:01:55 DEBUG : sub dir2: Making directory
2024/11/29 02:01:55 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:01:55 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/29 02:01:55 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:01:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:01:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:01:58 DEBUG : sub dir/hello world: md5 = 0ae830ff9aaf027057f73cff272276ec OK
2024/11/29 02:01:58 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:01:58 INFO  : sub dir/hello world: Deleted
2024/11/29 02:01:58 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:02:00 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (6.73s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:02:01 DEBUG : sub dir2: Making directory with metadata
2024/11/29 02:02:01 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:02:01 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:02:02 DEBUG : sub dir: Making directory with metadata
2024/11/29 02:02:03 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/29 02:02:03 DEBUG : sub dir2: Making directory with metadata
2024/11/29 02:02:04 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:02:04 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:02:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:02:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:02:05 DEBUG : sub dir/hello world: md5 = 1a28da0bae9a287122dc02e17f05c785 OK
2024/11/29 02:02:05 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:02:05 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:02:09 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (9.44s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.45s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:02:11 DEBUG : sub dir2: Making directory
2024/11/29 02:02:11 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:02:11 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/29 02:02:11 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:02:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:02:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:02:14 DEBUG : sub dir/hello world: md5 = ab708c4afa12efb02eee98dd0ff23513 OK
2024/11/29 02:02:14 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:02:14 DEBUG : Waiting for deletions to finish
2024/11/29 02:02:15 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:02:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (6.56s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:02:20 DEBUG : sub dir/hello world: md5 = eb5a89109e79f987dd4f25bbbd2f2327 OK
2024/11/29 02:02:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yetizok3kiya"
2024/11/29 02:02:21 DEBUG : Creating backend with remote "TestDrive:crypt/m92msfait8dhd3oq8jluorbu095qcsofvae67oudd3k1abeo07j0"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso' -> Encrypted drive 'TestCryptDrive:rclone-test-yetizok3kiya'
2024/11/29 02:02:22 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:02:23 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:02:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yetizok3kiya': Waiting for checks to finish
2024/11/29 02:02:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yetizok3kiya': Waiting for transfers to finish
2024/11/29 02:02:26 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/29 02:02:26 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:02:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yetizok3kiya': Purge remote
2024/11/29 02:02:29 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (12.55s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:02:33 DEBUG : sub dir/hello world: md5 = 9830a5398155928540ffc9f78cee0df8 OK
2024/11/29 02:02:34 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/29 02:02:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:02:34 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/29 02:02:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:02:36 DEBUG : sub dir/hello world: md5 = 10ad051a4ccbb56bc3c5ed167d596aef OK
2024/11/29 02:02:36 INFO  : sub dir/hello world: Copied (replaced existing)
2024/11/29 02:02:36 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:02:38 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (9.34s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:02:42 DEBUG : sub dir/hello world: md5 = 899442dd1b5a2e61aa8c96ca33c428dc OK
2024/11/29 02:02:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-behibag6cuwe"
2024/11/29 02:02:43 DEBUG : Creating backend with remote "TestDrive:crypt/1kb7a639fu69vhjmucb49iarrk8v8pp4qut3im7c60rga1etlf40"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso' -> Encrypted drive 'TestCryptDrive:rclone-test-behibag6cuwe'
2024/11/29 02:02:44 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:02:44 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:02:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-behibag6cuwe': Waiting for checks to finish
2024/11/29 02:02:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-behibag6cuwe': Waiting for transfers to finish
2024/11/29 02:02:48 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/29 02:02:48 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:02:50 DEBUG : sub dir/hello world: md5 = aeb28147294ea82c7b9f722744e232de OK
2024/11/29 02:02:51 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/29 02:02:51 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/29 02:02:51 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/29 02:02:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-behibag6cuwe': Waiting for checks to finish
2024/11/29 02:02:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-behibag6cuwe': Waiting for transfers to finish
2024/11/29 02:02:53 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/29 02:02:54 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:02:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-behibag6cuwe': Purge remote
2024/11/29 02:02:56 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (18.68s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:03:02 DEBUG : sub dir/hello world: md5 = e1116301b50b7f22029e04c1deb47fdb OK
2024/11/29 02:03:02 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/29 02:03:03 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/29 02:03:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:03:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:03:04 DEBUG : sub dir/hello world: md5 = d96d8cbc69168de60e3f494b3e94f5f5 OK
2024/11/29 02:03:04 INFO  : sub dir/hello world: Copied (replaced existing)
2024/11/29 02:03:04 INFO  : sub dir/hello world: Deleted
2024/11/29 02:03:05 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:03:07 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (9.79s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:03:11 DEBUG : sub dir/hello world: md5 = d7756a2eaff72328097ed9b87001bd7a OK
2024/11/29 02:03:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-konetam3butu"
2024/11/29 02:03:12 DEBUG : Creating backend with remote "TestDrive:crypt/7c1vvipjsnm2u4u6ifsm73b98atl14qe8p6cetpk66h9e3hqlin0"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso' -> Encrypted drive 'TestCryptDrive:rclone-test-konetam3butu'
2024/11/29 02:03:13 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:03:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:03:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-konetam3butu': Waiting for checks to finish
2024/11/29 02:03:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-konetam3butu': Waiting for transfers to finish
2024/11/29 02:03:17 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/29 02:03:17 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:03:20 DEBUG : sub dir/hello world: md5 = b3e74f53962b8f3c403442c538c00d5e OK
2024/11/29 02:03:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-konetam3butu': Using server-side directory move
2024/11/29 02:03:20 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-konetam3butu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/29 02:03:20 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/29 02:03:20 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/29 02:03:21 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/29 02:03:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-konetam3butu': Waiting for checks to finish
2024/11/29 02:03:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-konetam3butu': Waiting for transfers to finish
2024/11/29 02:03:21 INFO  : sub dir/hello world: Deleted
2024/11/29 02:03:22 INFO  : sub dir/hello world: Moved (server-side)
2024/11/29 02:03:23 INFO  : sub dir: Set directory modification time (using SetModTime)
2024/11/29 02:03:26 DEBUG : sub dir/hello world: md5 = a69ce01a2ce79efba3690cb46740e85d OK
2024/11/29 02:03:27 DEBUG : testing file moves
2024/11/29 02:03:27 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/29 02:03:27 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/29 02:03:28 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2024/11/29 02:03:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-konetam3butu': Waiting for checks to finish
2024/11/29 02:03:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-konetam3butu': Waiting for transfers to finish
2024/11/29 02:03:28 INFO  : sub dir/hello world: Deleted
2024/11/29 02:03:29 INFO  : sub dir/hello world: Moved (server-side)
2024/11/29 02:03:30 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:03:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-konetam3butu': Purge remote
--- PASS: TestServerSideMoveOverSelf (25.81s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:03:37 DEBUG : sub dir/hello world: md5 = de67a1be0314c5945623737105e36d12 OK
2024/11/29 02:03:37 ERROR : : error listing: directory not found
2024/11/29 02:03:37 DEBUG : Local file system at /tmp/rclone2006451156: Making directory
2024/11/29 02:03:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:03:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:03:40 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (7.33s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:03:44 DEBUG : sub dir/hello world: md5 = 06ebbc3cdd1bb5d4f675d32770cfba1f OK
2024/11/29 02:03:45 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:03:45 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:03:45 DEBUG : Local file system at /tmp/rclone2006451156: Waiting for checks to finish
2024/11/29 02:03:45 DEBUG : Local file system at /tmp/rclone2006451156: Waiting for transfers to finish
2024/11/29 02:03:46 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2024/11/29 02:03:46 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:03:46 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:03:47 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (7.23s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:03:49 DEBUG : check sum: Need to transfer - File not found at Destination
2024/11/29 02:03:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:03:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:03:50 DEBUG : check sum: md5 = 43989a409dae7d92216b125c75418beb OK
2024/11/29 02:03:50 INFO  : check sum: Copied (new)
2024/11/29 02:03:50 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:03:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:03:51 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2024/11/29 02:03:51 DEBUG : check sum: Size of src and dst objects identical
2024/11/29 02:03:51 DEBUG : check sum: Unchanged skipping
2024/11/29 02:03:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:03:51 DEBUG : Waiting for deletions to finish
2024/11/29 02:03:51 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (4.89s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:03:54 DEBUG : sizeonly: Need to transfer - File not found at Destination
2024/11/29 02:03:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:03:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:03:55 DEBUG : sizeonly: md5 = 7bed5fb6fd4819cee030481a7885ac79 OK
2024/11/29 02:03:55 INFO  : sizeonly: Copied (new)
2024/11/29 02:03:55 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:03:56 DEBUG : sizeonly: Sizes identical
2024/11/29 02:03:56 DEBUG : sizeonly: Unchanged skipping
2024/11/29 02:03:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:03:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:03:56 DEBUG : Waiting for deletions to finish
2024/11/29 02:03:56 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (4.75s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:03:58 DEBUG : ignore-size: Need to transfer - File not found at Destination
2024/11/29 02:03:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:03:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:04:00 DEBUG : ignore-size: md5 = 45238ac5bd9dd5735ed6ef7bfe17c288 OK
2024/11/29 02:04:00 INFO  : ignore-size: Copied (new)
2024/11/29 02:04:00 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:04:01 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:04:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:04:01 DEBUG : ignore-size: Unchanged skipping
2024/11/29 02:04:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:04:01 DEBUG : Waiting for deletions to finish
2024/11/29 02:04:01 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (4.77s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:04:04 DEBUG : existing: md5 = 7b44f7ba47115f0eeb03dd2df4ce5f7b OK
2024/11/29 02:04:05 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:04:05 DEBUG : existing: Unchanged skipping
2024/11/29 02:04:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:04:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:04:05 DEBUG : Waiting for deletions to finish
2024/11/29 02:04:05 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:04:05 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2024/11/29 02:04:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:04:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:04:07 DEBUG : existing: md5 = b3c15a1e197ae07c20a7dbe2a5d27543 OK
2024/11/29 02:04:07 INFO  : existing: Copied (replaced existing)
2024/11/29 02:04:07 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (6.29s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:04:09 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/29 02:04:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:04:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:04:11 DEBUG : existing: md5 = a2191a3d7a29f397b048a5300bab6566 OK
2024/11/29 02:04:11 INFO  : existing: Copied (new)
2024/11/29 02:04:11 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:04:12 DEBUG : existing: Destination exists, skipping
2024/11/29 02:04:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:04:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:04:12 DEBUG : Waiting for deletions to finish
2024/11/29 02:04:12 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (4.85s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:04:17 DEBUG : b/potato: md5 = fe12703b3f5eb0b9d95e8771d7119293 OK
2024/11/29 02:04:20 DEBUG : c/non empty space: md5 = ccf1eda9411b4a457da0d8c922248070 OK
2024/11/29 02:04:20 DEBUG : d: Making directory
2024/11/29 02:04:21 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/29 02:04:21 DEBUG : Added delayed dir = "c", newDst=c
2024/11/29 02:04:21 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/29 02:04:22 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:04:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:04:22 DEBUG : c/non empty space: Unchanged skipping
2024/11/29 02:04:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:04:24 DEBUG : a/potato2: md5 = 0414b8176d918846a9c7b24b3c2c6918 OK
2024/11/29 02:04:24 INFO  : a/potato2: Copied (new)
2024/11/29 02:04:24 DEBUG : Waiting for deletions to finish
2024/11/29 02:04:25 INFO  : b/potato: Deleted
2024/11/29 02:04:25 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/29 02:04:25 INFO  : d: Removing directory
2024/11/29 02:04:26 INFO  : b: Removing directory
2024/11/29 02:04:26 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/29 02:04:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:04:30 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/29 02:04:30 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (17.72s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:04:33 DEBUG : empty space: md5 = c32331a49d2a0bb9c3bdca738331f961 OK
2024/11/29 02:04:34 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2024/11/29 02:04:34 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2024/11/29 02:04:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:04:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:04:34 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:04:34 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2024/11/29 02:04:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:04:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:04:36 DEBUG : empty space: md5 = 73ffd73f440c98f91b51e055c2c27b26 OK
2024/11/29 02:04:36 INFO  : empty space: Copied (replaced existing)
2024/11/29 02:04:36 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (6.77s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.44s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:04:41 DEBUG : foo: md5 = 436c6655a56addf1d298e1000ffd0ead OK
2024/11/29 02:04:41 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2024/11/29 02:04:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:04:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:04:42 DEBUG : foo: md5 = 114a8495f6c2706fd2917957dff3531d OK
2024/11/29 02:04:42 INFO  : foo: Copied (replaced existing)
2024/11/29 02:04:42 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (5.49s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:04:46 DEBUG : empty space: md5 = f182af01e2e2623255010fd473531cdd OK
2024/11/29 02:04:47 DEBUG : potato: Need to transfer - File not found at Destination
2024/11/29 02:04:47 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:04:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:04:47 DEBUG : empty space: Unchanged skipping
2024/11/29 02:04:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:04:48 DEBUG : potato: md5 = 4c5409232f7e232b7bd611fa162c3e2e OK
2024/11/29 02:04:48 INFO  : potato: Copied (new)
2024/11/29 02:04:48 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (6.16s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:04:52 DEBUG : potato: md5 = 3444aa5a238f50b147feb4c53f25c3ab OK
2024/11/29 02:04:53 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2024/11/29 02:04:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:04:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:04:54 DEBUG : potato: md5 = a73347dd9efcd0c0b9a1689b71a28970 OK
2024/11/29 02:04:54 INFO  : potato: Copied (replaced existing)
2024/11/29 02:04:54 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (5.43s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:04:58 DEBUG : potato: md5 = d931a23b0fe31697da838e5428b83122 OK
2024/11/29 02:04:58 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC
2024/11/29 02:04:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:04:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:05:00 DEBUG : potato: md5 = 03ff2c40179fdb041b88fb6041f704b3 OK
2024/11/29 02:05:00 INFO  : potato: Copied (replaced existing)
2024/11/29 02:05:00 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (5.34s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:05:03 DEBUG : potato: md5 = 78d037cda038b43f8ac14328482af155 OK
2024/11/29 02:05:05 DEBUG : empty space: md5 = 1227620103106591fd6db56cee8fb2f6 OK
2024/11/29 02:05:05 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:05:05 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2024/11/29 02:05:05 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:05:05 DEBUG : empty space: Unchanged skipping
2024/11/29 02:05:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:05:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:05:05 DEBUG : Waiting for deletions to finish
2024/11/29 02:05:05 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (7.00s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:05:10 DEBUG : potato: md5 = 4102a0657f6324744cf9bc0db3b70d21 OK
2024/11/29 02:05:12 DEBUG : empty space: md5 = 6169d2cf568593ef4f12f29f4e7d058e OK
2024/11/29 02:05:12 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:05:12 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:05:12 DEBUG : empty space: Unchanged skipping
2024/11/29 02:05:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:05:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:05:14 DEBUG : potato2: md5 = e3cd9e1bc016962d5d5644ef1413426b OK
2024/11/29 02:05:14 INFO  : potato2: Copied (new)
2024/11/29 02:05:14 DEBUG : Waiting for deletions to finish
2024/11/29 02:05:15 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.77s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:05:20 DEBUG : b/potato: md5 = afa23fd80baa7b423d3edc49cf5390a8 OK
2024/11/29 02:05:22 DEBUG : c/non empty space: md5 = 7a3e716967005369805bd71e39a0a680 OK
2024/11/29 02:05:22 DEBUG : d: Making directory
2024/11/29 02:05:23 DEBUG : d/e: Making directory
2024/11/29 02:05:26 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/29 02:05:26 DEBUG : Added delayed dir = "c", newDst=c
2024/11/29 02:05:26 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/29 02:05:26 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:05:26 DEBUG : c/non empty space: Unchanged skipping
2024/11/29 02:05:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:05:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:05:29 DEBUG : a/potato2: md5 = 2f8b9e4568e18559a76bc1b5f3b446d7 OK
2024/11/29 02:05:29 INFO  : a/potato2: Copied (new)
2024/11/29 02:05:29 DEBUG : Waiting for deletions to finish
2024/11/29 02:05:29 INFO  : b/potato: Deleted
2024/11/29 02:05:30 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/29 02:05:30 INFO  : d/e: Removing directory
2024/11/29 02:05:31 INFO  : d: Removing directory
2024/11/29 02:05:31 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2024/11/29 02:05:32 INFO  : b: Removing directory
2024/11/29 02:05:32 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/29 02:05:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:05:35 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/29 02:05:36 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (20.39s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:05:40 DEBUG : b/potato: md5 = d34f11a0fa0ef366f977ce9c10f9c9e9 OK
2024/11/29 02:05:43 DEBUG : c/non empty space: md5 = b631a707abbac31b44372340b1ac9a6f OK
2024/11/29 02:05:43 DEBUG : d: Making directory
2024/11/29 02:05:45 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/29 02:05:45 DEBUG : Added delayed dir = "c", newDst=c
2024/11/29 02:05:45 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/29 02:05:45 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:05:45 DEBUG : c/non empty space: Unchanged skipping
2024/11/29 02:05:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:05:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:05:48 DEBUG : a/potato2: md5 = d1dc2d8e5774c450a81ec334a05442fa OK
2024/11/29 02:05:48 INFO  : a/potato2: Copied (new)
2024/11/29 02:05:48 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': not deleting files as there were IO errors
2024/11/29 02:05:48 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/29 02:05:48 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:05:52 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/29 02:05:53 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/29 02:05:54 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (17.97s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:05:57 DEBUG : potato: md5 = 64108d3cdf44ab98ad6eb6d667d329c6 OK
2024/11/29 02:05:59 DEBUG : empty space: md5 = 3ddf6d48cac249ef33e28e3e631d7849 OK
2024/11/29 02:05:59 DEBUG : Waiting for deletions to finish
2024/11/29 02:05:59 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:05:59 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:05:59 DEBUG : empty space: Unchanged skipping
2024/11/29 02:05:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:05:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:06:00 INFO  : potato: Deleted
2024/11/29 02:06:01 DEBUG : potato2: md5 = 35261f6b2b82f2f501a147983b185e98 OK
2024/11/29 02:06:01 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (8.25s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:06:06 DEBUG : potato: md5 = 84ad65920e0d06df1228e2934501f628 OK
2024/11/29 02:06:07 DEBUG : empty space: md5 = 0c6ca04e1e528fcd2ea10165af67b1e0 OK
2024/11/29 02:06:08 DEBUG : Waiting for deletions to finish
2024/11/29 02:06:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:06:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:06:09 INFO  : potato: Deleted
2024/11/29 02:06:09 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:06:09 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:06:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:06:09 DEBUG : empty space: Unchanged skipping
2024/11/29 02:06:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:06:10 DEBUG : potato2: md5 = 62e579d404d7896cb1b4b55755b41f2a OK
2024/11/29 02:06:10 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (9.12s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:06:15 DEBUG : potato: md5 = 827059bda5c3dd86f7cbf640fc24c4fb OK
2024/11/29 02:06:15 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:06:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:06:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:06:17 DEBUG : potato2: md5 = 5e0edbbdff6073cad2da995c8c7d85e2 OK
2024/11/29 02:06:17 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (6.47s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:06:21 DEBUG : potato2: md5 = d65fac66643142c938f1588c4a7b05c5 OK
2024/11/29 02:06:23 DEBUG : empty space: md5 = 8effb76567c2c9995eb4d934ad8a1ab1 OK
2024/11/29 02:06:23 DEBUG : enormous: Excluded (Size Filter)
2024/11/29 02:06:23 DEBUG : enormous: Excluded
2024/11/29 02:06:23 DEBUG : potato2: Excluded (Size Filter)
2024/11/29 02:06:23 DEBUG : potato2: Excluded
2024/11/29 02:06:23 DEBUG : potato2: Excluded (Size Filter)
2024/11/29 02:06:23 DEBUG : potato2: Excluded
2024/11/29 02:06:23 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:06:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:06:23 DEBUG : empty space: Unchanged skipping
2024/11/29 02:06:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:06:23 DEBUG : Waiting for deletions to finish
2024/11/29 02:06:23 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:06:24 DEBUG : enormous: Excluded (Size Filter)
2024/11/29 02:06:24 DEBUG : enormous: Excluded
2024/11/29 02:06:24 DEBUG : potato2: Excluded (Size Filter)
2024/11/29 02:06:24 DEBUG : potato2: Excluded
2024/11/29 02:06:24 DEBUG : potato2: Excluded (Size Filter)
2024/11/29 02:06:24 DEBUG : potato2: Excluded
2024/11/29 02:06:24 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/11/29 02:06:24 DEBUG : empty space: Unchanged skipping
2024/11/29 02:06:24 DEBUG : Local file system at /tmp/rclone2006451156: Waiting for checks to finish
2024/11/29 02:06:24 DEBUG : Local file system at /tmp/rclone2006451156: Waiting for transfers to finish
2024/11/29 02:06:24 DEBUG : Waiting for deletions to finish
2024/11/29 02:06:24 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncWithExclude (7.11s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:06:28 DEBUG : potato2: md5 = 5624b495fc2c29f48db0914758ce7535 OK
2024/11/29 02:06:30 DEBUG : empty space: md5 = d57e4b8f9219aac1c80d3eaa74c3357c OK
2024/11/29 02:06:31 DEBUG : enormous: md5 = 07ac79db3daccb324b07325d7408a871 OK
2024/11/29 02:06:32 DEBUG : enormous: Excluded (Size Filter)
2024/11/29 02:06:32 DEBUG : enormous: Excluded
2024/11/29 02:06:32 DEBUG : potato2: Excluded (Size Filter)
2024/11/29 02:06:32 DEBUG : potato2: Excluded
2024/11/29 02:06:32 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:06:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:06:32 DEBUG : empty space: Unchanged skipping
2024/11/29 02:06:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:06:32 DEBUG : Waiting for deletions to finish
2024/11/29 02:06:33 INFO  : enormous: Deleted
2024/11/29 02:06:33 INFO  : potato2: Deleted
2024/11/29 02:06:33 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:06:33 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/11/29 02:06:33 DEBUG : empty space: Unchanged skipping
2024/11/29 02:06:33 DEBUG : Local file system at /tmp/rclone2006451156: Waiting for checks to finish
2024/11/29 02:06:33 DEBUG : Local file system at /tmp/rclone2006451156: Waiting for transfers to finish
2024/11/29 02:06:33 DEBUG : Waiting for deletions to finish
2024/11/29 02:06:33 INFO  : enormous: Deleted
2024/11/29 02:06:33 INFO  : potato2: Deleted
2024/11/29 02:06:33 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (8.85s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:06:37 DEBUG : one: md5 = bacdd6cbabc455656ad67222e8364617 OK
2024/11/29 02:06:39 DEBUG : two: md5 = 6b590330112e0e6c487eb50c2d73f0df OK
2024/11/29 02:06:41 DEBUG : three: md5 = 5e45db81c28eb1222b664af0b00b946b OK
2024/11/29 02:06:42 DEBUG : four: md5 = cd87d490f329901771585fee007a973c OK
2024/11/29 02:06:43 DEBUG : five: Need to transfer - File not found at Destination
2024/11/29 02:06:43 DEBUG : four: Sizes differ (src 4 vs dst 8)
2024/11/29 02:06:43 DEBUG : one: Destination is newer than source, skipping
2024/11/29 02:06:43 DEBUG : three: Sizes identical
2024/11/29 02:06:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:06:43 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2024/11/29 02:06:43 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2024/11/29 02:06:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:06:44 DEBUG : two: md5 = 5a07c5e55abddac6adb309e9f94ad2d0 OK
2024/11/29 02:06:44 INFO  : two: Copied (replaced existing)
2024/11/29 02:06:44 DEBUG : four: md5 = cf4feb5e2b74a12c9d74b34fd5823f39 OK
2024/11/29 02:06:44 INFO  : four: Copied (replaced existing)
2024/11/29 02:06:45 DEBUG : five: md5 = 3c69c908c64459c18d9fcb5ccfc683e6 OK
2024/11/29 02:06:45 INFO  : five: Copied (new)
2024/11/29 02:06:45 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (13.01s)
=== 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-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2024/11/29 02:06:48 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Ignoring --track-renames as the source and destination do not have a common hash
2024/11/29 02:06:49 DEBUG : potato: Need to transfer - File not found at Destination
2024/11/29 02:06:49 DEBUG : yam: Need to transfer - File not found at Destination
2024/11/29 02:06:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:06:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:06:50 DEBUG : potato: md5 = 69e80a55b76c2928aaa5d5493773d5fd OK
2024/11/29 02:06:50 INFO  : potato: Copied (new)
2024/11/29 02:06:50 DEBUG : yam: md5 = dfdee71aac19485f7a464307730aefdc OK
2024/11/29 02:06:50 INFO  : yam: Copied (new)
2024/11/29 02:06:50 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:06:51 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Ignoring --track-renames as the source and destination do not have a common hash
2024/11/29 02:06:51 DEBUG : yaml: Need to transfer - File not found at Destination
2024/11/29 02:06:51 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:06:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:06:51 DEBUG : potato: Unchanged skipping
2024/11/29 02:06:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:06:53 DEBUG : yaml: md5 = 032479e5b733a1e03c71f178e27b9076 OK
2024/11/29 02:06:53 INFO  : yaml: Copied (new)
2024/11/29 02:06:53 DEBUG : Waiting for deletions to finish
2024/11/29 02:06:54 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (8.40s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2024/11/29 02:06:57 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Making map for --track-renames
2024/11/29 02:06:57 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Finished making map for --track-renames
2024/11/29 02:06:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:06:57 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/11/29 02:06:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for renames to finish
2024/11/29 02:06:57 DEBUG : yam: Need to transfer - No matching file found at Destination
2024/11/29 02:06:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:06:59 DEBUG : yam: md5 = 343118c2f0ecb4434b7ca57aa4a1a13e OK
2024/11/29 02:06:59 INFO  : yam: Copied (new)
2024/11/29 02:06:59 DEBUG : potato: md5 = 94cb788b8c13be835950225db378746a OK
2024/11/29 02:06:59 INFO  : potato: Copied (new)
2024/11/29 02:06:59 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:06:59 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:06:59 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Making map for --track-renames
2024/11/29 02:06:59 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Finished making map for --track-renames
2024/11/29 02:06:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:06:59 DEBUG : potato: Unchanged skipping
2024/11/29 02:06:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for renames to finish
2024/11/29 02:07:00 INFO  : yam: Moved (server-side) to: yaml
2024/11/29 02:07:00 INFO  : yaml: Renamed from "yam"
2024/11/29 02:07:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:07:00 DEBUG : Waiting for deletions to finish
2024/11/29 02:07:00 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (6.31s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2024/11/29 02:07:03 DEBUG : Added delayed dir = "sub", newDst=<nil>
2024/11/29 02:07:03 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Making map for --track-renames
2024/11/29 02:07:03 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Finished making map for --track-renames
2024/11/29 02:07:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:07:03 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/11/29 02:07:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for renames to finish
2024/11/29 02:07:03 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2024/11/29 02:07:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:07:06 DEBUG : sub/yam: md5 = eadf55fc58bc5f4ff150d4745ca2ac85 OK
2024/11/29 02:07:06 INFO  : sub/yam: Copied (new)
2024/11/29 02:07:06 DEBUG : potato: md5 = 0ddd8d54ab4f56aef70bc81dc3e4941a OK
2024/11/29 02:07:06 INFO  : potato: Copied (new)
2024/11/29 02:07:06 DEBUG : Waiting for deletions to finish
2024/11/29 02:07:06 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:07:07 DEBUG : Added delayed dir = "sub", newDst=sub
2024/11/29 02:07:07 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:07:07 DEBUG : potato: Unchanged skipping
2024/11/29 02:07:08 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Making map for --track-renames
2024/11/29 02:07:08 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Finished making map for --track-renames
2024/11/29 02:07:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:07:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for renames to finish
2024/11/29 02:07:09 INFO  : sub/yam: Moved (server-side) to: yam
2024/11/29 02:07:09 INFO  : yam: Renamed from "sub/yam"
2024/11/29 02:07:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:07:09 DEBUG : Waiting for deletions to finish
2024/11/29 02:07:09 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.90s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:07:13 DEBUG : Creating backend with remote "/tmp/rclone2006451156/dir1"
2024/11/29 02:07:13 DEBUG : Creating backend with remote "/tmp/rclone2006451156/dir2"
2024/11/29 02:07:13 DEBUG : Local file system at /tmp/rclone2006451156/dir2: Using server-side directory move
2024/11/29 02:07:13 INFO  : Local file system at /tmp/rclone2006451156/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/29 02:07:13 DEBUG : file1.txt: Need to transfer - File not found at Destination
2024/11/29 02:07:13 INFO  : file1.txt: Moved (server-side)
2024/11/29 02:07:13 DEBUG : Local file system at /tmp/rclone2006451156/dir2: Waiting for checks to finish
2024/11/29 02:07:13 DEBUG : Local file system at /tmp/rclone2006451156/dir2: Waiting for transfers to finish
--- PASS: TestServerSideMoveLocal (0.49s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:07:14 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/11/29 02:07:14 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:07:14 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:07:14 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/11/29 02:07:14 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/11/29 02:07:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:07:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:07:16 DEBUG : sub dir/hello world: md5 = 0f4ce1eba11985f328546fd50a4ac8ad OK
2024/11/29 02:07:16 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:07:16 INFO  : sub dir/hello world: Deleted
2024/11/29 02:07:19 DEBUG : nested/sub dir/file: md5 = bdbee1d8414f38d0844bc7c9bb93c6ec OK
2024/11/29 02:07:19 INFO  : nested/sub dir/file: Copied (new)
2024/11/29 02:07:19 INFO  : nested/sub dir/file: Deleted
2024/11/29 02:07:19 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:07:20 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:07:20 INFO  : nested: Set directory modification time (using DirSetModTime)
2024/11/29 02:07:20 INFO  : sub dir: Removing directory
2024/11/29 02:07:20 INFO  : nested/sub dir: Removing directory
2024/11/29 02:07:20 INFO  : nested: Removing directory
2024/11/29 02:07:20 DEBUG : Local file system at /tmp/rclone2006451156: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:07:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/29 02:07:24 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/11/29 02:07:25 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (12.51s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:07:26 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/11/29 02:07:26 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/29 02:07:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/29 02:07:26 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/11/29 02:07:26 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/11/29 02:07:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:07:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:07:29 DEBUG : sub dir/hello world: md5 = 04239b82c1931251484a0b763a9439e9 OK
2024/11/29 02:07:29 INFO  : sub dir/hello world: Copied (new)
2024/11/29 02:07:29 INFO  : sub dir/hello world: Deleted
2024/11/29 02:07:31 DEBUG : nested/sub dir/file: md5 = 0acfca8735a38ce762ac3fce1b8ebe31 OK
2024/11/29 02:07:31 INFO  : nested/sub dir/file: Copied (new)
2024/11/29 02:07:31 INFO  : nested/sub dir/file: Deleted
2024/11/29 02:07:32 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:07:33 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:07:33 INFO  : nested: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:07:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/29 02:07:36 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/11/29 02:07:37 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (13.14s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:07:39 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/29 02:07:39 DEBUG : existing-b: Need to transfer - File not found at Destination
2024/11/29 02:07:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:07:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:07:41 DEBUG : existing: md5 = d3ea417dc742945fc62becb590d76673 OK
2024/11/29 02:07:41 INFO  : existing: Copied (new)
2024/11/29 02:07:41 INFO  : existing: Deleted
2024/11/29 02:07:41 DEBUG : existing-b: md5 = da745f6f2c37be4e7e81a3af9bf98b9a OK
2024/11/29 02:07:41 INFO  : existing-b: Copied (new)
2024/11/29 02:07:41 INFO  : existing-b: Deleted
2024/11/29 02:07:41 DEBUG : existing: Destination exists, skipping
2024/11/29 02:07:41 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2024/11/29 02:07:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:07:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:07:41 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (5.99s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:07:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-togegob1guru"
2024/11/29 02:07:45 DEBUG : Creating backend with remote "TestDrive:crypt/m03cc9qsmqq3n8ouvqjjbp8ptih9lu25g7bv1nimttuvq17nhnug"
2024/11/29 02:07:48 DEBUG : potato2: md5 = 318f47034836db7a2cf434e73acb5170 OK
2024/11/29 02:07:50 DEBUG : empty space: md5 = 6afdc783441eccf141de1e06bdc96dee OK
2024/11/29 02:07:51 DEBUG : potato3: md5 = 1cad05c6187afe33cba8611a3e23b864 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso' -> Encrypted drive 'TestCryptDrive:rclone-test-togegob1guru'
2024/11/29 02:07:54 DEBUG : empty space: md5 = 195346e25a8521e5bb01cfecf787ea52 OK
2024/11/29 02:07:56 DEBUG : potato3: md5 = a145d82d6e6ef3f175011dd1e25154fa OK
2024/11/29 02:07:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-togegob1guru': Using server-side directory move
2024/11/29 02:07:56 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-togegob1guru': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/29 02:07:56 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:07:56 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/11/29 02:07:56 DEBUG : empty space: Unchanged skipping
2024/11/29 02:07:56 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/29 02:07:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-togegob1guru': Waiting for checks to finish
2024/11/29 02:07:57 INFO  : empty space: Deleted
2024/11/29 02:07:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-togegob1guru': Waiting for transfers to finish
2024/11/29 02:07:57 INFO  : potato3: Deleted
2024/11/29 02:07:57 INFO  : potato2: Moved (server-side)
2024/11/29 02:07:58 INFO  : potato3: Moved (server-side)
2024/11/29 02:07:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tejemaj4nidi"
2024/11/29 02:07:59 DEBUG : Creating backend with remote "TestDrive:crypt/ft5jpvr7aiq3ss6jnf8j38ei7uojej5h25cmrsh58sih3hon29vg"
2024/11/29 02:08:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tejemaj4nidi': Using server-side directory move
2024/11/29 02:08:01 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tejemaj4nidi': Server side directory move succeeded
2024/11/29 02:08:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tejemaj4nidi': Purge remote
2024/11/29 02:08:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-togegob1guru': Purge remote
2024/11/29 02:08:02 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (17.86s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:08:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-ferovuq2vaki"
2024/11/29 02:08:03 DEBUG : Creating backend with remote "TestDrive:crypt/qtagmqkad3u47dfcqjv7a1mn517tk4a147jqj26415mtmuqshr6g"
2024/11/29 02:08:06 DEBUG : potato2: md5 = 08e72c86d93a026fc5d2e8a9fde4647a OK
2024/11/29 02:08:07 DEBUG : empty space: md5 = ce60fa814b36d6058c360be6d19efb31 OK
2024/11/29 02:08:09 DEBUG : potato3: md5 = 49a36d6e030d5159718f1c0d02eb82f6 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso' -> Encrypted drive 'TestCryptDrive:rclone-test-ferovuq2vaki'
2024/11/29 02:08:12 DEBUG : empty space: md5 = 1ff6f3969f6b7ecec25da808b1f6f849 OK
2024/11/29 02:08:14 DEBUG : potato3: md5 = a98b9f28b30c72575faa7a32025c9ccd OK
2024/11/29 02:08:14 DEBUG : empty space: Excluded (Size Filter)
2024/11/29 02:08:14 DEBUG : empty space: Excluded
2024/11/29 02:08:14 DEBUG : empty space: Excluded (Size Filter)
2024/11/29 02:08:14 DEBUG : empty space: Excluded
2024/11/29 02:08:14 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:08:14 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/29 02:08:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ferovuq2vaki': Waiting for checks to finish
2024/11/29 02:08:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ferovuq2vaki': Waiting for transfers to finish
2024/11/29 02:08:15 INFO  : potato3: Deleted
2024/11/29 02:08:15 INFO  : potato2: Moved (server-side)
2024/11/29 02:08:16 INFO  : potato3: Moved (server-side)
2024/11/29 02:08:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kolediv5tuja"
2024/11/29 02:08:16 DEBUG : Creating backend with remote "TestDrive:crypt/r9q84k8ribehuvqvu822tg21a6bsfjurq0omchlc383ae75rs05g"
2024/11/29 02:08:18 DEBUG : empty space: Excluded (Size Filter)
2024/11/29 02:08:18 DEBUG : empty space: Excluded
2024/11/29 02:08:18 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:08:18 DEBUG : potato3: Need to transfer - File not found at Destination
2024/11/29 02:08:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kolediv5tuja': Waiting for checks to finish
2024/11/29 02:08:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kolediv5tuja': Waiting for transfers to finish
2024/11/29 02:08:20 INFO  : potato3: Moved (server-side)
2024/11/29 02:08:20 INFO  : potato2: Moved (server-side)
2024/11/29 02:08:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kolediv5tuja': Purge remote
2024/11/29 02:08:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ferovuq2vaki': Purge remote
--- PASS: TestServerSideMoveWithFilter (20.01s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:08:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fahujeg4rica"
2024/11/29 02:08:23 DEBUG : Creating backend with remote "TestDrive:crypt/qpk7hok4iitdhacc3256a8lmfursti17qf0nkcb7mq4e76mrjb2g"
2024/11/29 02:08:26 DEBUG : potato2: md5 = 3352a5169404ca3ecd5331751ac8c060 OK
2024/11/29 02:08:28 DEBUG : empty space: md5 = fb1c53abbd433b91964de283761e811f OK
2024/11/29 02:08:29 DEBUG : potato3: md5 = b13b2642f871a57eb432e168b4bd9772 OK
2024/11/29 02:08:29 DEBUG : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso' -> Encrypted drive 'TestCryptDrive:rclone-test-fahujeg4rica'
2024/11/29 02:08:34 DEBUG : empty space: md5 = 235d3548b40a4e7329e0b5ebff022dbd OK
2024/11/29 02:08:35 DEBUG : potato3: md5 = c5e8b18979cd6aba32b966fd035567b1 OK
2024/11/29 02:08:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fahujeg4rica': Using server-side directory move
2024/11/29 02:08:35 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-fahujeg4rica': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/29 02:08:36 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/29 02:08:36 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2024/11/29 02:08:36 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/11/29 02:08:36 DEBUG : empty space: Unchanged skipping
2024/11/29 02:08:36 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/29 02:08:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fahujeg4rica': Waiting for checks to finish
2024/11/29 02:08:36 INFO  : empty space: Deleted
2024/11/29 02:08:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fahujeg4rica': Waiting for transfers to finish
2024/11/29 02:08:36 INFO  : potato3: Deleted
2024/11/29 02:08:37 INFO  : potato2: Moved (server-side)
2024/11/29 02:08:37 INFO  : potato3: Moved (server-side)
2024/11/29 02:08:37 INFO  : tomatoDir: Removing directory
2024/11/29 02:08:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': deleted 1 directories
2024/11/29 02:08:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lawabas2wuzu"
2024/11/29 02:08:39 DEBUG : Creating backend with remote "TestDrive:crypt/vu3t9iclcabaollp3jgd10jq3sf3mp0prf1itc16pq6ui09vjm80"
2024/11/29 02:08:40 DEBUG : tomatoDir: Making directory
2024/11/29 02:08:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lawabas2wuzu': Using server-side directory move
2024/11/29 02:08:42 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-lawabas2wuzu': Server side directory move succeeded
2024/11/29 02:08:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lawabas2wuzu': Purge remote
2024/11/29 02:08:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fahujeg4rica': Purge remote
2024/11/29 02:08:45 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (22.52s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.51s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:08:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/rclone-sync-test"
2024/11/29 02:08:46 DEBUG : Config file has changed externally - reloading
2024/11/29 02:08:46 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncOverlap (4.48s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:08:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/rclone-sync-test"
2024/11/29 02:08:50 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2024/11/29 02:08:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/rclone-sync-test-include/layer2"
2024/11/29 02:08:53 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2024/11/29 02:08:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/rclone-sync-test-ignore-file"
2024/11/29 02:08:57 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2024/11/29 02:09:01 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 8588ce906fd08569cf82060e9a73aa37 OK
2024/11/29 02:09:02 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/29 02:09:03 DEBUG : rclone-sync-test: Excluded
2024/11/29 02:09:03 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/29 02:09:03 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/29 02:09:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/rclone-sync-test': Waiting for checks to finish
2024/11/29 02:09:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/rclone-sync-test': Waiting for transfers to finish
2024/11/29 02:09:03 DEBUG : Waiting for deletions to finish
2024/11/29 02:09:03 INFO  : There was nothing to transfer
2024/11/29 02:09:04 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/29 02:09:05 DEBUG : rclone-sync-test: Excluded
2024/11/29 02:09:05 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/29 02:09:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:09:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:09:05 DEBUG : Waiting for deletions to finish
2024/11/29 02:09:05 INFO  : rclone-sync-test-include: Removing directory
2024/11/29 02:09:05 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/29 02:09:05 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/11/29 02:09:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': failed to delete 1 directories
2024/11/29 02:09:05 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:09:06 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/29 02:09:07 DEBUG : rclone-sync-test: Excluded
2024/11/29 02:09:07 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/29 02:09:07 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/29 02:09:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/rclone-sync-test-include/layer2': Waiting for checks to finish
2024/11/29 02:09:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/rclone-sync-test-include/layer2': Waiting for transfers to finish
2024/11/29 02:09:07 DEBUG : Waiting for deletions to finish
2024/11/29 02:09:07 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:09:08 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/29 02:09:08 DEBUG : rclone-sync-test: Excluded
2024/11/29 02:09:09 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/29 02:09:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:09:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:09:09 DEBUG : Waiting for deletions to finish
2024/11/29 02:09:09 INFO  : rclone-sync-test-include: Removing directory
2024/11/29 02:09:09 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/29 02:09:09 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/11/29 02:09:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': failed to delete 1 directories
2024/11/29 02:09:09 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:09:10 DEBUG : : Excluded
2024/11/29 02:09:10 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/29 02:09:11 DEBUG : rclone-sync-test: Excluded
2024/11/29 02:09:11 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/29 02:09:11 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/29 02:09:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/rclone-sync-test-ignore-file': Waiting for checks to finish
2024/11/29 02:09:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/rclone-sync-test-ignore-file': Waiting for transfers to finish
2024/11/29 02:09:11 DEBUG : Waiting for deletions to finish
2024/11/29 02:09:11 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:09:14 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/29 02:09:15 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (34.85s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:09:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/dst"
2024/11/29 02:09:25 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/29 02:09:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/CompareDest"
2024/11/29 02:09:27 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/gveqi14airsml4bgu7krj116o8"
2024/11/29 02:09:29 DEBUG : one: Need to transfer - File not found at Destination
2024/11/29 02:09:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:09:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:09:32 DEBUG : one: md5 = bec812724b2b0dc2eed928c9b1d9d627 OK
2024/11/29 02:09:32 INFO  : one: Copied (new)
2024/11/29 02:09:32 DEBUG : Waiting for deletions to finish
2024/11/29 02:09:33 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/29 02:09:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:09:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:09:35 DEBUG : one: md5 = bd7956ff424766b73d93cae4516a3717 OK
2024/11/29 02:09:35 INFO  : one: Copied (replaced existing)
2024/11/29 02:09:35 DEBUG : Waiting for deletions to finish
2024/11/29 02:09:37 DEBUG : dst/one: md5 = 681f8f091ab9614665e1be36b99c6fea OK
2024/11/29 02:09:39 DEBUG : CompareDest/one: md5 = 7dd3100bdf0108fdc098e8569306cd31 OK
2024/11/29 02:09:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:09:40 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/29 02:09:41 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:09:41 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/29 02:09:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:09:41 DEBUG : Waiting for deletions to finish
2024/11/29 02:09:41 INFO  : There was nothing to transfer
2024/11/29 02:09:43 DEBUG : CompareDest/two: md5 = ff0777be4564e5d4f6237d6a611843e7 OK
2024/11/29 02:09:44 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:09:44 DEBUG : two: Destination found in --compare-dest, skipping
2024/11/29 02:09:44 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/29 02:09:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:09:44 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:09:44 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/29 02:09:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:09:44 DEBUG : Waiting for deletions to finish
2024/11/29 02:09:44 INFO  : There was nothing to transfer
2024/11/29 02:09:45 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:09:45 DEBUG : two: Destination found in --compare-dest, skipping
2024/11/29 02:09:45 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/29 02:09:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:09:45 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:09:45 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/29 02:09:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:09:45 DEBUG : Waiting for deletions to finish
2024/11/29 02:09:45 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2024/11/29 02:09:47 DEBUG : two: Sizes differ (src 5 vs dst 3)
2024/11/29 02:09:47 DEBUG : two: Need to transfer - File not found at Destination
2024/11/29 02:09:47 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/29 02:09:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:09:47 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:09:47 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/29 02:09:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:09:49 DEBUG : two: md5 = 87bb340a352bd90f693dab1b36da1160 OK
2024/11/29 02:09:49 INFO  : two: Copied (new)
2024/11/29 02:09:49 DEBUG : Waiting for deletions to finish
2024/11/29 02:09:53 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:09:53 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:09:53 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:09:53 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCompareDest (29.04s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:09:57 DEBUG : pre-dest1/1: md5 = 8e4f3eabb9c47111d14ea2a999350243 OK
2024/11/29 02:10:00 DEBUG : pre-dest2/2: md5 = 45fbe8094b023cfba98fcdb060b1393f OK
2024/11/29 02:10:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/dest"
2024/11/29 02:10:00 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/rg03c1jvnehrrc617i0lnqjddc"
2024/11/29 02:10:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/pre-dest1"
2024/11/29 02:10:02 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/bbnblvh6k061ssopqrp18kd7gc"
2024/11/29 02:10:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/pre-dest2"
2024/11/29 02:10:03 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/dgicm1h6b5ejvlltm8eeif0bnk"
2024/11/29 02:10:04 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:10:04 DEBUG : 1: Destination found in --compare-dest, skipping
2024/11/29 02:10:04 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:10:04 DEBUG : 2: Destination found in --compare-dest, skipping
2024/11/29 02:10:05 DEBUG : 3: Need to transfer - File not found at Destination
2024/11/29 02:10:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dest': Waiting for checks to finish
2024/11/29 02:10:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dest': Waiting for transfers to finish
2024/11/29 02:10:08 DEBUG : 3: md5 = 4f3994b5b2a521d9e6abf2265a10b562 OK
2024/11/29 02:10:08 INFO  : 3: Copied (new)
2024/11/29 02:10:08 DEBUG : Waiting for deletions to finish
2024/11/29 02:10:11 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2024/11/29 02:10:12 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2024/11/29 02:10:13 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (19.36s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:10:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/dst"
2024/11/29 02:10:14 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/29 02:10:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/CopyDest"
2024/11/29 02:10:15 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/d09o6po3f7bm6ce32vdgs8h9ls"
2024/11/29 02:10:17 DEBUG : one: Need to transfer - File not found at Destination
2024/11/29 02:10:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:10:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:10:20 DEBUG : one: md5 = 49581244de01bf7ad7451461884d7fcf OK
2024/11/29 02:10:20 INFO  : one: Copied (new)
2024/11/29 02:10:20 DEBUG : Waiting for deletions to finish
2024/11/29 02:10:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:10:21 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/29 02:10:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:10:23 DEBUG : one: md5 = 0365024d6aacb3eb3202120da99cd4f1 OK
2024/11/29 02:10:23 INFO  : one: Copied (replaced existing)
2024/11/29 02:10:23 DEBUG : Waiting for deletions to finish
2024/11/29 02:10:25 DEBUG : dst/one: md5 = 6f353455cfb326e01ce13462a463ce6a OK
2024/11/29 02:10:28 DEBUG : CopyDest/one: md5 = 65cfb0b1a2bb8597512fcd30be11e90e OK
2024/11/29 02:10:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/BackupDir"
2024/11/29 02:10:29 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/s6dbk3lfi7c9kfvo6j7bla9m0g"
2024/11/29 02:10:30 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/29 02:10:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:10:31 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:10:31 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/29 02:10:33 INFO  : one: Moved (server-side)
2024/11/29 02:10:34 INFO  : one: Copied (server-side copy)
2024/11/29 02:10:34 DEBUG : one: Destination found in --copy-dest, using server-side copy
2024/11/29 02:10:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:10:34 DEBUG : Waiting for deletions to finish
2024/11/29 02:10:37 DEBUG : CopyDest/two: md5 = 2860945a44b8d3ff9f2375d79bdc98f1 OK
2024/11/29 02:10:38 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:10:39 INFO  : two: Copied (server-side copy)
2024/11/29 02:10:39 DEBUG : two: Destination found in --copy-dest, using server-side copy
2024/11/29 02:10:39 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:10:39 DEBUG : one: Unchanged skipping
2024/11/29 02:10:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:10:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:10:39 DEBUG : Waiting for deletions to finish
2024/11/29 02:10:40 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:10:40 DEBUG : one: Unchanged skipping
2024/11/29 02:10:40 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:10:40 DEBUG : two: Unchanged skipping
2024/11/29 02:10:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:10:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:10:40 DEBUG : Waiting for deletions to finish
2024/11/29 02:10:40 INFO  : There was nothing to transfer
2024/11/29 02:10:42 DEBUG : CopyDest/three: md5 = 4b19ddec301f7e82193620f72b654603 OK
2024/11/29 02:10:44 DEBUG : three: Sizes differ (src 7 vs dst 5)
2024/11/29 02:10:44 DEBUG : three: Destination not found in --copy-dest
2024/11/29 02:10:44 DEBUG : three: Need to transfer - File not found at Destination
2024/11/29 02:10:44 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:10:44 DEBUG : one: Unchanged skipping
2024/11/29 02:10:44 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/29 02:10:44 DEBUG : two: Unchanged skipping
2024/11/29 02:10:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:10:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:10:45 DEBUG : three: md5 = f3a646448e3970fa3759ecf8989481d3 OK
2024/11/29 02:10:45 INFO  : three: Copied (new)
2024/11/29 02:10:45 DEBUG : Waiting for deletions to finish
2024/11/29 02:10:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/11/29 02:10:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:10:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:10:52 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:10:52 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:10:52 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/11/29 02:10:53 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (39.91s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:10:56 DEBUG : dst/one: md5 = 2634d69799977089b9cb84a946e98d96 OK
2024/11/29 02:10:58 DEBUG : dst/two: md5 = 4c1b95f6b5b4a5fdf9a886d295a068c2 OK
2024/11/29 02:11:00 DEBUG : dst/three.txt: md5 = 375e3ce9dd811c068774c8d5978cd47f OK
2024/11/29 02:11:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/dst"
2024/11/29 02:11:00 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/29 02:11:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/backup"
2024/11/29 02:11:01 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/1nrff024r7pq65ecp72fc28jb0"
2024/11/29 02:11:03 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/29 02:11:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:11:03 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:11:03 DEBUG : two: Unchanged skipping
2024/11/29 02:11:05 INFO  : one: Moved (server-side)
2024/11/29 02:11:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:11:07 DEBUG : one: md5 = 95889e1dbb177a16810c06e8e514c412 OK
2024/11/29 02:11:07 INFO  : one: Copied (new)
2024/11/29 02:11:07 DEBUG : Waiting for deletions to finish
2024/11/29 02:11:08 INFO  : three.txt: Moved (server-side)
2024/11/29 02:11:08 INFO  : three.txt: Moved into backup dir
2024/11/29 02:11:10 DEBUG : dst/three.txt: md5 = 6921eae4109c0cfaa5f6dd9725894935 OK
2024/11/29 02:11:11 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/29 02:11:11 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:11:11 DEBUG : two: Unchanged skipping
2024/11/29 02:11:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:11:12 INFO  : one: Deleted
2024/11/29 02:11:13 INFO  : one: Moved (server-side)
2024/11/29 02:11:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:11:15 DEBUG : one: md5 = c76cb657bd37aaecc9691fadb3aa1022 OK
2024/11/29 02:11:15 INFO  : one: Copied (new)
2024/11/29 02:11:15 DEBUG : Waiting for deletions to finish
2024/11/29 02:11:16 INFO  : three.txt: Deleted
2024/11/29 02:11:16 INFO  : three.txt: Moved (server-side)
2024/11/29 02:11:16 INFO  : three.txt: Moved into backup dir
2024/11/29 02:11:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:11:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:11:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:11:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/29 02:11:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/29 02:11:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncBackupDir (28.15s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:11:24 DEBUG : dst/one: md5 = 607baa23eff7d63548c4818801599f42 OK
2024/11/29 02:11:26 DEBUG : dst/two: md5 = 323d4e542e855c6a27ce9ddf7762b17f OK
2024/11/29 02:11:28 DEBUG : dst/three.txt: md5 = 26c09cca3dd159e482ef662c9ad17127 OK
2024/11/29 02:11:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/dst"
2024/11/29 02:11:28 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/29 02:11:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/backup"
2024/11/29 02:11:29 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/1nrff024r7pq65ecp72fc28jb0"
2024/11/29 02:11:31 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/29 02:11:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:11:31 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:11:31 DEBUG : two: Unchanged skipping
2024/11/29 02:11:33 INFO  : one: Moved (server-side) to: one.bak
2024/11/29 02:11:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:11:35 DEBUG : one: md5 = 0abf1d391d8ad6e2813e92203a389567 OK
2024/11/29 02:11:35 INFO  : one: Copied (new)
2024/11/29 02:11:35 DEBUG : Waiting for deletions to finish
2024/11/29 02:11:36 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/29 02:11:36 INFO  : three.txt: Moved into backup dir
2024/11/29 02:11:38 DEBUG : dst/three.txt: md5 = 231b853739f41c7fff2038fa16f48719 OK
2024/11/29 02:11:39 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/29 02:11:39 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:11:39 DEBUG : two: Unchanged skipping
2024/11/29 02:11:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:11:39 INFO  : one.bak: Deleted
2024/11/29 02:11:40 INFO  : one: Moved (server-side) to: one.bak
2024/11/29 02:11:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:11:42 DEBUG : one: md5 = 615ce5145f1abf26252144896daf936f OK
2024/11/29 02:11:42 INFO  : one: Copied (new)
2024/11/29 02:11:42 DEBUG : Waiting for deletions to finish
2024/11/29 02:11:43 INFO  : three.txt.bak: Deleted
2024/11/29 02:11:44 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/29 02:11:44 INFO  : three.txt: Moved into backup dir
2024/11/29 02:11:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:11:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:11:48 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/29 02:11:48 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/29 02:11:48 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/29 02:11:48 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirWithSuffix (27.56s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:11:52 DEBUG : dst/one: md5 = ddb08cba36081a6fc35df38396097c7e OK
2024/11/29 02:11:54 DEBUG : dst/two: md5 = b369e6fb5440928ed5fd2432cc5d2908 OK
2024/11/29 02:11:57 DEBUG : dst/three.txt: md5 = 9c55255e1b86f2314f7344958ef06939 OK
2024/11/29 02:11:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/dst"
2024/11/29 02:11:57 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/29 02:11:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/backup"
2024/11/29 02:11:58 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/1nrff024r7pq65ecp72fc28jb0"
2024/11/29 02:12:00 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/29 02:12:00 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:12:00 DEBUG : two: Unchanged skipping
2024/11/29 02:12:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:12:02 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/29 02:12:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:12:04 DEBUG : one: md5 = 34fbd6db4c90d9e0b79c0eface182a0f OK
2024/11/29 02:12:04 INFO  : one: Copied (new)
2024/11/29 02:12:04 DEBUG : Waiting for deletions to finish
2024/11/29 02:12:05 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/29 02:12:05 INFO  : three.txt: Moved into backup dir
2024/11/29 02:12:08 DEBUG : dst/three.txt: md5 = db7ec44830d6fb8805b3c3ad0d975bf6 OK
2024/11/29 02:12:08 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/29 02:12:08 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:12:08 DEBUG : two: Unchanged skipping
2024/11/29 02:12:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:12:09 INFO  : one-2019-01-01: Deleted
2024/11/29 02:12:10 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/29 02:12:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:12:12 DEBUG : one: md5 = 80617877cf762456a8c4016a5aa816d2 OK
2024/11/29 02:12:12 INFO  : one: Copied (new)
2024/11/29 02:12:12 DEBUG : Waiting for deletions to finish
2024/11/29 02:12:13 INFO  : three-2019-01-01.txt: Deleted
2024/11/29 02:12:14 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/29 02:12:14 INFO  : three.txt: Moved into backup dir
2024/11/29 02:12:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:12:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:12:18 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/29 02:12:18 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/29 02:12:18 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/29 02:12:18 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (29.81s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:12:22 DEBUG : dst/one: md5 = 223876bdbbb810f6e8a580cfeeb00180 OK
2024/11/29 02:12:24 DEBUG : dst/two: md5 = f0a3efe9925bb89b821efba6e23e22ab OK
2024/11/29 02:12:25 DEBUG : dst/three.txt: md5 = 7b1e759ccbb6c4cd3c888085734586a1 OK
2024/11/29 02:12:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/dst"
2024/11/29 02:12:26 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/29 02:12:27 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/29 02:12:27 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:12:27 DEBUG : two: Unchanged skipping
2024/11/29 02:12:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:12:28 INFO  : one: Moved (server-side) to: one.bak
2024/11/29 02:12:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:12:30 DEBUG : one: md5 = cd5f4c7ebcf895d9aa06c34aa4d4edb1 OK
2024/11/29 02:12:30 INFO  : one: Copied (new)
2024/11/29 02:12:30 DEBUG : Waiting for deletions to finish
2024/11/29 02:12:30 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/29 02:12:30 INFO  : three.txt: Moved into backup dir
2024/11/29 02:12:33 DEBUG : dst/three.txt: md5 = 0f39b0ee810ec1729bd857d1304d81d4 OK
2024/11/29 02:12:34 DEBUG : three.txt.bak: Excluded (Path Filter)
2024/11/29 02:12:34 DEBUG : three.txt.bak: Excluded
2024/11/29 02:12:34 DEBUG : one.bak: Excluded (Path Filter)
2024/11/29 02:12:34 DEBUG : one.bak: Excluded
2024/11/29 02:12:34 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/29 02:12:34 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:12:34 DEBUG : two: Unchanged skipping
2024/11/29 02:12:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for checks to finish
2024/11/29 02:12:34 INFO  : one.bak: Deleted
2024/11/29 02:12:35 INFO  : one: Moved (server-side) to: one.bak
2024/11/29 02:12:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso/dst': Waiting for transfers to finish
2024/11/29 02:12:37 DEBUG : one: md5 = f8311a880fe5f0750652e4ea881b329d OK
2024/11/29 02:12:37 INFO  : one: Copied (new)
2024/11/29 02:12:37 DEBUG : Waiting for deletions to finish
2024/11/29 02:12:38 INFO  : three.txt.bak: Deleted
2024/11/29 02:12:38 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/29 02:12:38 INFO  : three.txt: Moved into backup dir
2024/11/29 02:12:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:12:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/29 02:12:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/29 02:12:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:12:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/29 02:12:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirSuffixOnly (23.58s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:12:46 DEBUG : dst/one: md5 = 0706e1faa701c3d71169ffd0175c345b OK
2024/11/29 02:12:47 DEBUG : dst/two: md5 = c245bf5741a36c0e8ba35df8b61f9720 OK
2024/11/29 02:12:49 DEBUG : dst/three.txt: md5 = ca00be25170e11b3892775e648d9b763 OK
2024/11/29 02:12:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/dst"
2024/11/29 02:12:49 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/29 02:12:50 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/29 02:12:51 INFO  : one: Moved (server-side) to: one.bak
2024/11/29 02:12:53 DEBUG : one: md5 = 4876a47e20b5268068a3b6fad421f5b7 OK
2024/11/29 02:12:53 INFO  : one: Copied (new)
2024/11/29 02:12:53 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:12:53 DEBUG : two: Unchanged skipping
2024/11/29 02:12:54 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/11/29 02:12:54 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/29 02:12:56 DEBUG : three.txt: md5 = 7da3d5d1b43f3df422482684bdf0e74d OK
2024/11/29 02:12:56 INFO  : three.txt: Copied (new)
2024/11/29 02:12:57 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/29 02:12:58 INFO  : one.bak: Deleted
2024/11/29 02:12:59 INFO  : one: Moved (server-side) to: one.bak
2024/11/29 02:13:01 DEBUG : one: md5 = 5aa5f7a5fe57af22fd9c80919d2c1855 OK
2024/11/29 02:13:01 INFO  : one: Copied (new)
2024/11/29 02:13:01 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:13:01 DEBUG : two: Unchanged skipping
2024/11/29 02:13:01 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/11/29 02:13:02 INFO  : three.txt.bak: Deleted
2024/11/29 02:13:03 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/29 02:13:05 DEBUG : three.txt: md5 = 320338cd082c9602b20a84778a659db9 OK
2024/11/29 02:13:05 INFO  : three.txt: Copied (new)
2024/11/29 02:13:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/29 02:13:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:13:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/29 02:13:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:13:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/29 02:13:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/29 02:13:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncSuffix (27.17s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:13:13 DEBUG : dst/one: md5 = 8e1956865061ea1893bf2d8f742b021a OK
2024/11/29 02:13:14 DEBUG : dst/two: md5 = bb8cb72576a458c6549643137e2fddf5 OK
2024/11/29 02:13:16 DEBUG : dst/three.txt: md5 = aad44c90f560a1ee4d2b88b36488502f OK
2024/11/29 02:13:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moriqar3woso/dst"
2024/11/29 02:13:17 DEBUG : Creating backend with remote "TestDrive:crypt/keno1got1rgl14l7bsp85h8ef5crnfot14vqdjot92unm48rmr3g/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/29 02:13:18 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/29 02:13:19 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/29 02:13:20 DEBUG : one: md5 = cab550938e5cf6e58f55918a28f98ce1 OK
2024/11/29 02:13:20 INFO  : one: Copied (new)
2024/11/29 02:13:21 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:13:21 DEBUG : two: Unchanged skipping
2024/11/29 02:13:21 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/11/29 02:13:22 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/29 02:13:23 DEBUG : three.txt: md5 = d4b8ca9f07cb035f2ffec8213e35a1b0 OK
2024/11/29 02:13:23 INFO  : three.txt: Copied (new)
2024/11/29 02:13:25 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/29 02:13:25 INFO  : one-2019-01-01: Deleted
2024/11/29 02:13:26 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/29 02:13:28 DEBUG : one: md5 = d8e13fb577c5a28026d028ac80fa1d43 OK
2024/11/29 02:13:28 INFO  : one: Copied (new)
2024/11/29 02:13:28 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:13:28 DEBUG : two: Unchanged skipping
2024/11/29 02:13:28 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/11/29 02:13:29 INFO  : three-2019-01-01.txt: Deleted
2024/11/29 02:13:30 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/29 02:13:31 DEBUG : three.txt: md5 = b2a1d8e5c459abcd2de3747731e08ae6 OK
2024/11/29 02:13:31 INFO  : three.txt: Copied (new)
2024/11/29 02:13:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/29 02:13:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/29 02:13:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/29 02:13:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/29 02:13:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/29 02:13:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/29 02:13:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncSuffixKeepExtension (27.42s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:13:39 DEBUG : Testêé: md5 = e8c37d4ddc85a521db34cc7af911921c OK
2024/11/29 02:13:40 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2024/11/29 02:13:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:13:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:13:41 DEBUG : Testêé: md5 = 9726adfb6194735ca201202ca4aa0576 OK
2024/11/29 02:13:41 INFO  : Testêé: Copied (replaced existing) to: Testêé
2024/11/29 02:13:41 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (5.24s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:13:43 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/29 02:13:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:13:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:13:45 DEBUG : existing: md5 = 053d9e43f39045ee42a1b4af3b88776a OK
2024/11/29 02:13:45 INFO  : existing: Copied (new)
2024/11/29 02:13:45 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:13:45 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2024/11/29 02:13:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:13:45 ERROR : existing: Source and destination exist but do not match: immutable file modified
2024/11/29 02:13:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:13:45 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': not deleting files as there were IO errors
2024/11/29 02:13:45 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncImmutable (5.22s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:13:49 DEBUG : EXISTING: md5 = 7d78cbfd3e8165f964555ea57f45aa76 OK
2024/11/29 02:13:50 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:13:50 DEBUG : existing: Unchanged skipping
2024/11/29 02:13:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:13:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:13:50 DEBUG : Waiting for deletions to finish
2024/11/29 02:13:50 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (4.91s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", 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-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", 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-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", 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-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.44s)
    --- SKIP: TestMaxTransfer/Hard (0.46s)
    --- SKIP: TestMaxTransfer/Soft (0.47s)
    --- SKIP: TestMaxTransfer/Cautious (0.51s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:13:56 DEBUG : both0: md5 = 6044c33351012e74aaccef34642d5bbe OK
2024/11/29 02:13:58 DEBUG : only0: md5 = 5ac53c3d6382b9a59dfcc7294f177253 OK
2024/11/29 02:14:00 DEBUG : both1: md5 = 288e0f73bb21d43ba6c28db7e8a4feee OK
2024/11/29 02:14:01 DEBUG : only1: md5 = a92c0f7b2869fd4a742e5858330a5a96 OK
2024/11/29 02:14:03 DEBUG : both2: md5 = ca1e98ceeef66617aae22c538a0e0cb8 OK
2024/11/29 02:14:04 DEBUG : only2: md5 = 8679648c331e2fcfdb25fe5775629dcc OK
2024/11/29 02:14:06 DEBUG : both3: md5 = eccb1c17d601914d0d8d5bb0364e7d20 OK
2024/11/29 02:14:08 DEBUG : only3: md5 = a193a07f08c6456fe62bdaba6e48df76 OK
2024/11/29 02:14:10 DEBUG : both4: md5 = 51edfae95390278c4f75a1cb78e8a990 OK
2024/11/29 02:14:11 DEBUG : only4: md5 = 4fd51a86eefbbcd731a083fc40ac7aff OK
2024/11/29 02:14:13 DEBUG : both5: md5 = fbbd245f5f61a946bb775c645b5fe9a0 OK
2024/11/29 02:14:15 DEBUG : only5: md5 = 260e5d3421319db3dec743609d460953 OK
2024/11/29 02:14:16 DEBUG : both6: md5 = 6f71fef08c6a44e383b3efb4761a73fc OK
2024/11/29 02:14:18 DEBUG : only6: md5 = cb3a27e8a937e65d930e47e12c625760 OK
2024/11/29 02:14:20 DEBUG : both7: md5 = 0f1f8370f19d677fd6befd170eee0066 OK
2024/11/29 02:14:21 DEBUG : only7: md5 = c7b64c834bfb342c272e28f847252f7e OK
2024/11/29 02:14:23 DEBUG : both8: md5 = 60e3736f9758c3d79ddcb33ca438f0f8 OK
2024/11/29 02:14:25 DEBUG : only8: md5 = be729dca43b511618043b31b78f3efd4 OK
2024/11/29 02:14:27 DEBUG : both9: md5 = 2f85b0195511cbbabebd7641e3af0614 OK
2024/11/29 02:14:29 DEBUG : only9: md5 = a5e26cd87809a7adc83fd6b23f24ed8f OK
2024/11/29 02:14:31 DEBUG : both10: md5 = 16fe71f8794b2f53452066a0b119d5eb OK
2024/11/29 02:14:32 DEBUG : only10: md5 = 4a886876ebddd8ffaf059381f7260a37 OK
2024/11/29 02:14:34 DEBUG : both11: md5 = 04dfaca0a886f6441faf9b8848811f36 OK
2024/11/29 02:14:35 DEBUG : only11: md5 = 589429cebe00b461de25a4edd3ad8d34 OK
2024/11/29 02:14:37 DEBUG : both12: md5 = 1f7189e9a79053fa7f1b0b06aae2ffde OK
2024/11/29 02:14:39 DEBUG : only12: md5 = 387561d82ee70f266f8ef499ca25c541 OK
2024/11/29 02:14:41 DEBUG : both13: md5 = f038ff4b27a5d7a6540bd113234aeab4 OK
2024/11/29 02:14:42 DEBUG : only13: md5 = 74ebfbf9ea9cbf12c1610cad7b53c46a OK
2024/11/29 02:14:44 DEBUG : both14: md5 = 32eea4c5a56183ba6ea387028036aadb OK
2024/11/29 02:14:45 DEBUG : only14: md5 = 952376ae4016ed329a40742af7bc3dd6 OK
2024/11/29 02:14:47 DEBUG : both15: md5 = 156116095ec779668204a3856cf95f72 OK
2024/11/29 02:14:49 DEBUG : only15: md5 = 88c860d469a9b3908b4001404b31b170 OK
2024/11/29 02:14:50 DEBUG : both16: md5 = ef6560b5cf7ce8bd05cce805ed9377c6 OK
2024/11/29 02:14:52 DEBUG : only16: md5 = 5696e4c1d90ac01448fe883975c2c0d9 OK
2024/11/29 02:14:54 DEBUG : both17: md5 = 58ea6976f9b70cf17a9d8f118d98ce17 OK
2024/11/29 02:14:55 DEBUG : only17: md5 = b927d4c5016e70dbab85a21a626d50da OK
2024/11/29 02:14:57 DEBUG : both18: md5 = 8f7cc28cf181c259aef8db9fdf8ebe8e OK
2024/11/29 02:14:59 DEBUG : only18: md5 = fdbc6ad8307453082cab25723138341f OK
2024/11/29 02:15:00 DEBUG : both19: md5 = 3fb7e4b637831628bac51c751a7ceab9 OK
2024/11/29 02:15:02 DEBUG : only19: md5 = c6afae17b89995066ae127f53b29d34d OK
2024/11/29 02:15:03 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:15:03 DEBUG : both0: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both12: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both13: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both1: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both10: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both11: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both17: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both18: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both19: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both2: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both3: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both4: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both5: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both6: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both15: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both7: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:15:03 DEBUG : both14: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both8: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both9: Unchanged skipping
2024/11/29 02:15:03 DEBUG : both16: Unchanged skipping
2024/11/29 02:15:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:15:03 DEBUG : Waiting for deletions to finish
2024/11/29 02:15:03 INFO  : only16: Deleted
2024/11/29 02:15:03 INFO  : only5: Deleted
2024/11/29 02:15:03 INFO  : only4: Deleted
2024/11/29 02:15:03 INFO  : only2: Deleted
2024/11/29 02:15:04 INFO  : only0: Deleted
2024/11/29 02:15:04 INFO  : only7: Deleted
2024/11/29 02:15:04 INFO  : only1: Deleted
2024/11/29 02:15:04 INFO  : only12: Deleted
2024/11/29 02:15:04 INFO  : only13: Deleted
2024/11/29 02:15:04 INFO  : only14: Deleted
2024/11/29 02:15:04 INFO  : only17: Deleted
2024/11/29 02:15:04 INFO  : only9: Deleted
2024/11/29 02:15:05 INFO  : only18: Deleted
2024/11/29 02:15:05 INFO  : only19: Deleted
2024/11/29 02:15:05 INFO  : only3: Deleted
2024/11/29 02:15:05 INFO  : only8: Deleted
2024/11/29 02:15:05 INFO  : only6: Deleted
2024/11/29 02:15:06 INFO  : only10: Deleted
2024/11/29 02:15:06 INFO  : only15: Deleted
2024/11/29 02:15:06 INFO  : only11: Deleted
2024/11/29 02:15:06 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (84.72s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:15:21 DEBUG : both0: md5 = f28c89a1b06e2f108ac4e78a086e42bf OK
2024/11/29 02:15:23 DEBUG : only0: md5 = 51734163109a8d4337bb9e5b5e769c5a OK
2024/11/29 02:15:25 DEBUG : both1: md5 = 9b5fe006e6cbd802a6b248c11927e072 OK
2024/11/29 02:15:26 DEBUG : only1: md5 = 6068319a6375484c049b678e3892bd9a OK
2024/11/29 02:15:28 DEBUG : both2: md5 = 85a2dc6750ff58b0e618fb683ab5a330 OK
2024/11/29 02:15:29 DEBUG : only2: md5 = 54d46af25c26849ae98e719673bc75da OK
2024/11/29 02:15:31 DEBUG : both3: md5 = 19fdeb1f0fd9ed795882d2a19bf50638 OK
2024/11/29 02:15:33 DEBUG : only3: md5 = 9838dace2ee2c9e20582e2b970c288b7 OK
2024/11/29 02:15:35 DEBUG : both4: md5 = a9b71aefb420937686b4c65780034043 OK
2024/11/29 02:15:36 DEBUG : only4: md5 = b6ed59f07d9e98d767cf3b7eb97cc4a6 OK
2024/11/29 02:15:38 DEBUG : both5: md5 = 36bd9a11eebc86be68abd0bc243671dd OK
2024/11/29 02:15:40 DEBUG : only5: md5 = a59440a17d272f372454acba3ca18ca4 OK
2024/11/29 02:15:41 DEBUG : both6: md5 = a10c51e3728842ce3fb36613a825905e OK
2024/11/29 02:15:43 DEBUG : only6: md5 = 7fda169e1cb1a5302cc230d01eb67a35 OK
2024/11/29 02:15:45 DEBUG : both7: md5 = 62c3e362d08c0d142e9350340f2b33eb OK
2024/11/29 02:15:47 DEBUG : only7: md5 = 8c6d7bea1beb3bb489e12cfe14812c86 OK
2024/11/29 02:15:48 DEBUG : both8: md5 = 36c9fdef8f79773c795650d28625c858 OK
2024/11/29 02:15:50 DEBUG : only8: md5 = 2e7dcaeb7af39b69a0869a84defbd7c9 OK
2024/11/29 02:15:51 DEBUG : both9: md5 = 9cf2e3308927b54c5da503f3731e8d96 OK
2024/11/29 02:15:53 DEBUG : only9: md5 = 8e45db23515e70f1c662d88256472f32 OK
2024/11/29 02:15:55 DEBUG : both10: md5 = 36da29d1951f0e58ff4a8ed75dbf1117 OK
2024/11/29 02:15:57 DEBUG : only10: md5 = a46e4b44b7d934a113a0a7deb09f1959 OK
2024/11/29 02:15:59 DEBUG : both11: md5 = f44702312f72c6508b8c76718e2b09bd OK
2024/11/29 02:16:00 DEBUG : only11: md5 = 09682a1550fbd3e80e2b6a010f411563 OK
2024/11/29 02:16:02 DEBUG : both12: md5 = d5d7c07e5db150a211f63152e1e8e249 OK
2024/11/29 02:16:04 DEBUG : only12: md5 = 95fdd460f925c35e63ceeb332aa45b40 OK
2024/11/29 02:16:05 DEBUG : both13: md5 = 9d071365e59d30c2f1ebe2018cf06058 OK
2024/11/29 02:16:07 DEBUG : only13: md5 = 344743b0d7a0f047a1f9d5fd2d6b3e0f OK
2024/11/29 02:16:09 DEBUG : both14: md5 = 8fce966647d35e1ebf6b1f55368b68b7 OK
2024/11/29 02:16:10 DEBUG : only14: md5 = 87d5142004d89fb655fc0e5952c3aa38 OK
2024/11/29 02:16:12 DEBUG : both15: md5 = 1db67f6af7440ae90df16d08bceff264 OK
2024/11/29 02:16:14 DEBUG : only15: md5 = ee0fb8427447cbf5ea792acbff40c25f OK
2024/11/29 02:16:16 DEBUG : both16: md5 = a7e734eba388afd3a6f860f6388d0b1f OK
2024/11/29 02:16:17 DEBUG : only16: md5 = 9b6fb8a0de5da1226df26e9ec4edc7ac OK
2024/11/29 02:16:19 DEBUG : both17: md5 = 7cd35b5b4c7135b54904bafa3fec8288 OK
2024/11/29 02:16:21 DEBUG : only17: md5 = e5a07603d7486a5d80a012802df43add OK
2024/11/29 02:16:22 DEBUG : both18: md5 = 15d0ec5e1088e5a0a089be9e8e2470a9 OK
2024/11/29 02:16:24 DEBUG : only18: md5 = 3141d064bbf38b4a581a5157ecf5940f OK
2024/11/29 02:16:26 DEBUG : both19: md5 = 3079c1a034188ad1ff4084c405f68a9d OK
2024/11/29 02:16:27 DEBUG : only19: md5 = b58778c4b7eca3a93b65fcc5a0e34fe3 OK
2024/11/29 02:16:28 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both0: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both1: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both10: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both11: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both12: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both13: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both14: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both15: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both16: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both17: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both18: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both19: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both2: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both3: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both4: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both5: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both6: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both7: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both8: Unchanged skipping
2024/11/29 02:16:28 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/29 02:16:28 DEBUG : both9: Unchanged skipping
2024/11/29 02:16:28 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for checks to finish
2024/11/29 02:16:28 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2024/11/29 02:16:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Waiting for transfers to finish
2024/11/29 02:16:29 DEBUG : only11: md5 = 406725e8cb39156e9b1d17fe9efbe14d OK
2024/11/29 02:16:29 INFO  : only11: Copied (replaced existing)
2024/11/29 02:16:29 DEBUG : only10: md5 = 0ce3238e47fbd53861e26bc51147c9d5 OK
2024/11/29 02:16:29 INFO  : only10: Copied (replaced existing)
2024/11/29 02:16:29 DEBUG : only1: md5 = de7f7e18321d73e42b7997f788e0cb0f OK
2024/11/29 02:16:29 INFO  : only1: Copied (replaced existing)
2024/11/29 02:16:29 DEBUG : only0: md5 = 12b8ac9f436807b7422f7bfdab99de68 OK
2024/11/29 02:16:29 INFO  : only0: Copied (replaced existing)
2024/11/29 02:16:30 DEBUG : only13: md5 = 979240679c7fa2a3d1658faf1a747296 OK
2024/11/29 02:16:30 INFO  : only13: Copied (replaced existing)
2024/11/29 02:16:30 DEBUG : only12: md5 = cb0af232a40ead089b16fcaf252138d9 OK
2024/11/29 02:16:30 INFO  : only12: Copied (replaced existing)
2024/11/29 02:16:31 DEBUG : only14: md5 = 2de686837134739e7ee11e9134377a7e OK
2024/11/29 02:16:31 INFO  : only14: Copied (replaced existing)
2024/11/29 02:16:31 DEBUG : only15: md5 = 9b0b4584eeff3c99d702420907b4dc20 OK
2024/11/29 02:16:31 INFO  : only15: Copied (replaced existing)
2024/11/29 02:16:32 DEBUG : only16: md5 = 33c49652583e37d2017f7e3764d6f5e1 OK
2024/11/29 02:16:32 INFO  : only16: Copied (replaced existing)
2024/11/29 02:16:32 DEBUG : only17: md5 = d7a3d491a7279f5237d558e3182dfd3e OK
2024/11/29 02:16:32 INFO  : only17: Copied (replaced existing)
2024/11/29 02:16:32 DEBUG : only18: md5 = eac5b13b7eb611d4e251cdbb5d7d3333 OK
2024/11/29 02:16:32 INFO  : only18: Copied (replaced existing)
2024/11/29 02:16:32 DEBUG : only19: md5 = f7affde19daee13bd453dbe1e8c0b58e OK
2024/11/29 02:16:32 INFO  : only19: Copied (replaced existing)
2024/11/29 02:16:33 DEBUG : only2: md5 = bda3a2c0a34088413bfb6e0d1f643b63 OK
2024/11/29 02:16:33 INFO  : only2: Copied (replaced existing)
2024/11/29 02:16:33 DEBUG : only6: md5 = be97521aca67d1a79e0da20f33444dd1 OK
2024/11/29 02:16:33 INFO  : only6: Copied (replaced existing)
2024/11/29 02:16:33 DEBUG : only8: md5 = 955140818d965222ae387bbf16b14ca1 OK
2024/11/29 02:16:33 INFO  : only8: Copied (replaced existing)
2024/11/29 02:16:33 DEBUG : only3: md5 = 1ee615c2014553dfc146219c065aa791 OK
2024/11/29 02:16:33 INFO  : only3: Copied (replaced existing)
2024/11/29 02:16:34 DEBUG : only9: md5 = 099736553abe79540ceb03a1f70687a3 OK
2024/11/29 02:16:34 INFO  : only9: Copied (replaced existing)
2024/11/29 02:16:34 DEBUG : only7: md5 = 7058604823710549305c33c4cd9b0c30 OK
2024/11/29 02:16:34 INFO  : only7: Copied (replaced existing)
2024/11/29 02:16:34 DEBUG : only5: md5 = 3916d560f05fc28807326cd62f2f898a OK
2024/11/29 02:16:34 INFO  : only5: Copied (replaced existing)
2024/11/29 02:16:35 DEBUG : only4: md5 = 592ae44d44bc6d9e5822cf32fb6004f0 OK
2024/11/29 02:16:35 INFO  : only4: Copied (replaced existing)
2024/11/29 02:16:35 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (101.04s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:17:00 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:17:00 DEBUG : sub dir: Making directory with metadata
2024/11/29 02:17:01 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:17:22 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/29 02:17:23 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/29 02:17:23 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:17:23 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:17:37 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2024/11/29 02:17:38 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/29 02:17:39 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/11/29 02:17:39 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/11/29 02:17:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:17:41 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:17:42 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:17:43 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:17:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/29 02:17:45 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/11/29 02:17:45 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:17:45 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (47.41s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:17:48 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/29 02:17:48 DEBUG : sub dir: Making directory with metadata
2024/11/29 02:17:49 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:18:14 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/29 02:18:14 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/29 02:18:14 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/29 02:18:14 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso'", Local "Local file system at /tmp/rclone2006451156", Modify Window "1ms"
2024/11/29 02:18:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/29 02:18:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/11/29 02:18:29 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/11/29 02:18:30 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:18:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:18:32 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:18:32 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:18:33 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/29 02:18:34 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/11/29 02:18:34 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/29 02:18:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (49.47s)
PASS
2024/11/29 02:18:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moriqar3woso': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 18m18.861601999s (try 1/5)