"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5)
2024/12/07 03:36:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha"
2024/12/07 03:36:41 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/12/07 03:36:41 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg"
2024/12/07 03:36:42 DEBUG : Creating backend with remote "/tmp/rclone2861789748"
=== 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-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:36:43 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/07 03:36:43 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/07 03:36:43 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2024/12/07 03:36:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:36:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:36:43 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.55s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:36:44 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/07 03:36:44 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/07 03:36:44 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/07 03:36:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:36:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:36:47 DEBUG : sub dir/hello world: md5 = ee5673746878a50a68fb3e7bd814b4d6 OK
2024/12/07 03:36:47 INFO  : sub dir/hello world: Copied (new)
2024/12/07 03:36:48 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:36:50 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (7.37s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:36:51 DEBUG : metadata sub dir: Making directory with metadata
2024/12/07 03:36:51 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/07 03:36:51 DEBUG : empty metadata sub dir: Making directory with metadata
2024/12/07 03:36:51 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/07 03:36:51 DEBUG : Local file system at /tmp/rclone2861789748: File to upload is small (21 bytes), uploading instead of streaming
2024/12/07 03:36:51 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/12/07 03:36:51 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/12/07 03:36:51 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/12/07 03:36:52 DEBUG : Google drive root 'crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg': Skipping btime metadata as can't update it on an existing file: 2024-12-07T03:36:51.989586571Z
2024/12/07 03:36:53 INFO  : empty metadata sub dir: Updated directory metadata
2024/12/07 03:36:53 DEBUG : Google drive root 'crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg': Skipping btime metadata as can't update it on an existing file: 2024-12-07T03:36:51.989586571Z
2024/12/07 03:36:54 INFO  : metadata sub dir: Updated directory metadata
2024/12/07 03:36:54 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/12/07 03:36:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:36:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:36:56 DEBUG : metadata sub dir/hello metadata world: md5 = a2510bc304299396e72d2c3ade0a91e2 OK
2024/12/07 03:36:56 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:36:59 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (9.47s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:37:01 DEBUG : metadata sub dir: Making directory with metadata
2024/12/07 03:37:01 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/07 03:37:01 DEBUG : empty metadata sub dir: Making directory with metadata
2024/12/07 03:37:01 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/07 03:37:01 DEBUG : Local file system at /tmp/rclone2861789748: File to upload is small (21 bytes), uploading instead of streaming
2024/12/07 03:37:01 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/12/07 03:37:01 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/12/07 03:37:01 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/12/07 03:37:01 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2024/12/07 03:37:01 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2024/12/07 03:37:01 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/12/07 03:37:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:37:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:37:04 DEBUG : metadata sub dir/hello metadata world: md5 = 572b077f9f9e53ee51c94b17eb17623e OK
2024/12/07 03:37:04 INFO  : metadata sub dir/hello metadata world: Copied (new)
2024/12/07 03:37:04 DEBUG : Google drive root 'crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg': Skipping btime metadata as can't update it on an existing file: 2024-12-07T03:37:01.453507788Z
2024/12/07 03:37:05 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:37:07 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (7.84s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:37:09 DEBUG : Creating backend with remote "/non-existing"
2024/12/07 03:37:09 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2024/12/07 03:37:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:37:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.23s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:37:10 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/07 03:37:10 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/07 03:37:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:37:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:37:13 DEBUG : sub dir/hello world: md5 = 22eeb8c50b1f0c1db80c763641d77e42 OK
2024/12/07 03:37:13 INFO  : sub dir/hello world: Copied (new)
2024/12/07 03:37:14 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:37:16 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (7.05s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:37:17 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Running all checks before starting transfers
2024/12/07 03:37:17 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/07 03:37:17 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/07 03:37:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:37:17 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Checks finished, now starting transfers
2024/12/07 03:37:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:37:20 DEBUG : sub dir/hello world: md5 = e7f239038bd197f374c42bcd6f72fa5e OK
2024/12/07 03:37:20 INFO  : sub dir/hello world: Copied (new)
2024/12/07 03:37:21 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:37:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (7.06s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:37:24 ERROR : Ignoring --no-traverse with sync
2024/12/07 03:37:24 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/07 03:37:24 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/07 03:37:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:37:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:37:27 DEBUG : sub dir/hello world: md5 = 1eda48d947e44566101a4d5a2c3ff27a OK
2024/12/07 03:37:27 INFO  : sub dir/hello world: Copied (new)
2024/12/07 03:37:27 DEBUG : Waiting for deletions to finish
2024/12/07 03:37:28 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:37:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (7.35s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:37:32 DEBUG : hello world2: Need to transfer - File not found at Destination
2024/12/07 03:37:32 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/07 03:37:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:37:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:37:33 DEBUG : hello world2: md5 = 58707d87490ba4b928d718a51be5d34e OK
2024/12/07 03:37:33 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestCopyWithDepth (3.75s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:37:35 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/07 03:37:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:37:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:37:37 DEBUG : potato2: md5 = 6eaef778dcaa1e379a7b6bd76757e55e OK
2024/12/07 03:37:37 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.82s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:37:39 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/07 03:37:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:37:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:37:41 DEBUG : potato2: md5 = a77a1d0c8a42258228e0d9ab8662ccd4 OK
2024/12/07 03:37:41 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.85s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:37:43 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/12/07 03:37:43 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/07 03:37:43 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/12/07 03:37:43 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/07 03:37:43 DEBUG : sub dir: Making directory with metadata
2024/12/07 03:37:44 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/12/07 03:37:44 DEBUG : sub dir2: Making directory with metadata
2024/12/07 03:37:45 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/07 03:37:45 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/12/07 03:37:45 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/07 03:37:46 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/07 03:37:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:37:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:37:47 DEBUG : sub dir/hello world: md5 = 46189b45f5dd5a47f2b7484d68b15c73 OK
2024/12/07 03:37:47 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:37:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2024/12/07 03:37:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (10.72s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:37:54 DEBUG : sub dir2: Making directory
2024/12/07 03:37:54 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/12/07 03:37:54 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/07 03:37:54 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/07 03:37:54 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/12/07 03:37:54 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2024/12/07 03:37:54 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/07 03:37:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:37:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:37:57 DEBUG : sub dir/hello world: md5 = be5db247c8d438dbab98217625974f63 OK
2024/12/07 03:37:57 INFO  : sub dir/hello world: Copied (new)
2024/12/07 03:37:57 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/07 03:38:00 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (6.82s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:38:00 DEBUG : sub dir2: Making directory with metadata
2024/12/07 03:38:00 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/07 03:38:01 DEBUG : sub dir: Making directory with metadata
2024/12/07 03:38:02 INFO  : sub dir: Made directory with metadata (mtime=2024-12-07T03:38:00.945015912Z)
2024/12/07 03:38:02 DEBUG : sub dir2: Making directory with metadata
2024/12/07 03:38:03 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/07 03:38:03 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/07 03:38:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:38:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:38:04 DEBUG : sub dir/hello world: md5 = 983b128b2299412e52b703ca9413e024 OK
2024/12/07 03:38:04 INFO  : sub dir/hello world: Copied (new)
2024/12/07 03:38:04 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:38:08 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (8.62s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:38:09 DEBUG : sub dir no update dir modtime: Making directory with metadata
2024/12/07 03:38:09 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/12/07 03:38:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:38:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:38:11 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (4.75s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:38:14 DEBUG : sub dir2: Making directory
2024/12/07 03:38:14 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/07 03:38:14 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/12/07 03:38:14 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/07 03:38:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:38:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:38:17 DEBUG : sub dir/hello world: md5 = 3760bfa0dc36ed48426033cf26689244 OK
2024/12/07 03:38:17 INFO  : sub dir/hello world: Copied (new)
2024/12/07 03:38:17 INFO  : sub dir/hello world: Deleted
2024/12/07 03:38:18 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/07 03:38:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (6.45s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:38:20 DEBUG : sub dir2: Making directory with metadata
2024/12/07 03:38:20 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/07 03:38:20 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/07 03:38:21 DEBUG : sub dir: Making directory with metadata
2024/12/07 03:38:22 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/12/07 03:38:22 DEBUG : sub dir2: Making directory with metadata
2024/12/07 03:38:23 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/07 03:38:23 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/07 03:38:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:38:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:38:24 DEBUG : sub dir/hello world: md5 = 75d56a1da913f03de870a6f62fda24af OK
2024/12/07 03:38:24 INFO  : sub dir/hello world: Copied (new)
2024/12/07 03:38:24 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:38:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (8.90s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.49s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:38:30 DEBUG : sub dir2: Making directory
2024/12/07 03:38:30 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/07 03:38:30 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/12/07 03:38:30 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/07 03:38:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:38:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:38:33 DEBUG : sub dir/hello world: md5 = 2c2d9424e3018a11700b84512f274e33 OK
2024/12/07 03:38:33 INFO  : sub dir/hello world: Copied (new)
2024/12/07 03:38:33 DEBUG : Waiting for deletions to finish
2024/12/07 03:38:33 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/07 03:38:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (6.30s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:38:39 DEBUG : sub dir/hello world: md5 = 63e8ad6af1f4113852c279f5063a62c6 OK
2024/12/07 03:38:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-luqarax8dexa"
2024/12/07 03:38:39 DEBUG : Creating backend with remote "TestDrive:crypt/8jbv7rvr8tooo0gcefj5dglllq12etapqt2ipmlsa8egirfvp2tg"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha' -> Encrypted drive 'TestCryptDrive:rclone-test-luqarax8dexa'
2024/12/07 03:38:41 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/07 03:38:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/07 03:38:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-luqarax8dexa': Waiting for checks to finish
2024/12/07 03:38:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-luqarax8dexa': Waiting for transfers to finish
2024/12/07 03:38:44 INFO  : sub dir/hello world: Copied (server-side copy)
2024/12/07 03:38:45 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:38:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-luqarax8dexa': Purge remote
2024/12/07 03:38:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (13.30s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:38:52 DEBUG : sub dir/hello world: md5 = 82f41c5edc5c85d210a12bb4b936d807 OK
2024/12/07 03:38:53 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/12/07 03:38:53 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/12/07 03:38:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:38:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:38:54 DEBUG : sub dir/hello world: md5 = 1c8939b2d0ffa9e7dbe1216a53fd9ea0 OK
2024/12/07 03:38:54 INFO  : sub dir/hello world: Copied (replaced existing)
2024/12/07 03:38:55 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:38:57 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (8.87s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:39:01 DEBUG : sub dir/hello world: md5 = 2a5c8aff7408113f3b9823612fa0ac48 OK
2024/12/07 03:39:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nereceq6zuma"
2024/12/07 03:39:01 DEBUG : Creating backend with remote "TestDrive:crypt/o7qie587o6l2m6h4h21cmuq3uo6467te7f97ipfpci9jdlruascg"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha' -> Encrypted drive 'TestCryptDrive:rclone-test-nereceq6zuma'
2024/12/07 03:39:03 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/07 03:39:03 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/07 03:39:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nereceq6zuma': Waiting for checks to finish
2024/12/07 03:39:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nereceq6zuma': Waiting for transfers to finish
2024/12/07 03:39:07 INFO  : sub dir/hello world: Copied (server-side copy)
2024/12/07 03:39:07 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:39:10 DEBUG : sub dir/hello world: md5 = 48de3038ad3a40606bb54d0f1cdae728 OK
2024/12/07 03:39:11 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/12/07 03:39:11 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/12/07 03:39:11 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/12/07 03:39:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nereceq6zuma': Waiting for checks to finish
2024/12/07 03:39:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nereceq6zuma': Waiting for transfers to finish
2024/12/07 03:39:13 INFO  : sub dir/hello world: Copied (server-side copy)
2024/12/07 03:39:13 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:39:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nereceq6zuma': Purge remote
2024/12/07 03:39:16 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (19.61s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:39:21 DEBUG : sub dir/hello world: md5 = 79407d27e775e78183102202c1b5e8ac OK
2024/12/07 03:39:22 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/12/07 03:39:22 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/12/07 03:39:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:39:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:39:23 DEBUG : sub dir/hello world: md5 = e75de1c9de77f5f508bae225cfbc2c36 OK
2024/12/07 03:39:23 INFO  : sub dir/hello world: Copied (replaced existing)
2024/12/07 03:39:23 INFO  : sub dir/hello world: Deleted
2024/12/07 03:39:24 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:39:26 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (9.44s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:39:30 DEBUG : sub dir/hello world: md5 = 6e19f21f99552f95261dd5a92c0f2607 OK
2024/12/07 03:39:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qarunus3mari"
2024/12/07 03:39:30 DEBUG : Creating backend with remote "TestDrive:crypt/4l28gatl5ma8bkigip85v1sfs3hcq9fq8e8v46i43a3um04looqg"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha' -> Encrypted drive 'TestCryptDrive:rclone-test-qarunus3mari'
2024/12/07 03:39:32 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/07 03:39:32 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/07 03:39:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qarunus3mari': Waiting for checks to finish
2024/12/07 03:39:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qarunus3mari': Waiting for transfers to finish
2024/12/07 03:39:36 INFO  : sub dir/hello world: Copied (server-side copy)
2024/12/07 03:39:36 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:39:39 DEBUG : sub dir/hello world: md5 = 642f7312e3d6bcbcc6eca1a979c3be67 OK
2024/12/07 03:39:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qarunus3mari': Using server-side directory move
2024/12/07 03:39:39 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-qarunus3mari': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/12/07 03:39:40 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/12/07 03:39:40 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/12/07 03:39:40 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/12/07 03:39:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qarunus3mari': Waiting for checks to finish
2024/12/07 03:39:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qarunus3mari': Waiting for transfers to finish
2024/12/07 03:39:40 INFO  : sub dir/hello world: Deleted
2024/12/07 03:39:41 INFO  : sub dir/hello world: Moved (server-side)
2024/12/07 03:39:42 INFO  : sub dir: Set directory modification time (using SetModTime)
2024/12/07 03:39:45 DEBUG : sub dir/hello world: md5 = 284cd680741935b8818021a23ba111ef OK
2024/12/07 03:39:45 DEBUG : testing file moves
2024/12/07 03:39:46 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/12/07 03:39:46 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/12/07 03:39:46 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2024/12/07 03:39:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qarunus3mari': Waiting for checks to finish
2024/12/07 03:39:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qarunus3mari': Waiting for transfers to finish
2024/12/07 03:39:46 INFO  : sub dir/hello world: Deleted
2024/12/07 03:39:47 INFO  : sub dir/hello world: Moved (server-side)
2024/12/07 03:39:48 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:39:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qarunus3mari': Purge remote
--- PASS: TestServerSideMoveOverSelf (24.85s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:39:55 DEBUG : sub dir/hello world: md5 = d9f61f761a12ca41cc2aed1656fcf5dd OK
2024/12/07 03:39:55 ERROR : : error listing: directory not found
2024/12/07 03:39:55 DEBUG : Local file system at /tmp/rclone2861789748: Making directory
2024/12/07 03:39:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:39:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:39:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (6.96s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:40:02 DEBUG : sub dir/hello world: md5 = ac19e148d4d32bd7678d7c21aaad1d07 OK
2024/12/07 03:40:03 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/07 03:40:03 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/07 03:40:03 DEBUG : Local file system at /tmp/rclone2861789748: Waiting for checks to finish
2024/12/07 03:40:03 DEBUG : Local file system at /tmp/rclone2861789748: Waiting for transfers to finish
2024/12/07 03:40:04 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2024/12/07 03:40:04 INFO  : sub dir/hello world: Copied (new)
2024/12/07 03:40:04 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:40:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (7.89s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:40:07 DEBUG : check sum: Need to transfer - File not found at Destination
2024/12/07 03:40:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:40:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:40:09 DEBUG : check sum: md5 = 804af7f7f2c2aec481854e3bde3d1a0b OK
2024/12/07 03:40:09 INFO  : check sum: Copied (new)
2024/12/07 03:40:09 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:40:09 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2024/12/07 03:40:09 DEBUG : check sum: Size of src and dst objects identical
2024/12/07 03:40:09 DEBUG : check sum: Unchanged skipping
2024/12/07 03:40:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:40:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:40:09 DEBUG : Waiting for deletions to finish
2024/12/07 03:40:09 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (5.89s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:40:13 DEBUG : sizeonly: Need to transfer - File not found at Destination
2024/12/07 03:40:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:40:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:40:15 DEBUG : sizeonly: md5 = d15f847338895c3111b57015d53d008e OK
2024/12/07 03:40:15 INFO  : sizeonly: Copied (new)
2024/12/07 03:40:15 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:40:15 DEBUG : sizeonly: Sizes identical
2024/12/07 03:40:15 DEBUG : sizeonly: Unchanged skipping
2024/12/07 03:40:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:40:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:40:15 DEBUG : Waiting for deletions to finish
2024/12/07 03:40:15 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (5.02s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:40:18 DEBUG : ignore-size: Need to transfer - File not found at Destination
2024/12/07 03:40:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:40:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:40:20 DEBUG : ignore-size: md5 = 75c21c01d6b831c3e073bcb49d31c955 OK
2024/12/07 03:40:20 INFO  : ignore-size: Copied (new)
2024/12/07 03:40:20 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:40:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:40:20 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:40:20 DEBUG : ignore-size: Unchanged skipping
2024/12/07 03:40:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:40:20 DEBUG : Waiting for deletions to finish
2024/12/07 03:40:20 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (4.77s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:40:24 DEBUG : existing: md5 = 9d60fe8a9a512167dc6fcf17bfdf39d4 OK
2024/12/07 03:40:25 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:40:25 DEBUG : existing: Unchanged skipping
2024/12/07 03:40:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:40:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:40:25 DEBUG : Waiting for deletions to finish
2024/12/07 03:40:25 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:40:25 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2024/12/07 03:40:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:40:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:40:26 DEBUG : existing: md5 = e9532ae2317d6635201a99dcfe15182c OK
2024/12/07 03:40:26 INFO  : existing: Copied (replaced existing)
2024/12/07 03:40:26 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (6.21s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:40:29 DEBUG : existing: Need to transfer - File not found at Destination
2024/12/07 03:40:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:40:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:40:31 DEBUG : existing: md5 = cdd322a671204053e176c8ae319cd852 OK
2024/12/07 03:40:31 INFO  : existing: Copied (new)
2024/12/07 03:40:31 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:40:31 DEBUG : existing: Destination exists, skipping
2024/12/07 03:40:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:40:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:40:31 DEBUG : Waiting for deletions to finish
2024/12/07 03:40:31 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (4.84s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:40:36 DEBUG : b/potato: md5 = 6718f444383657e3862804ab96af7536 OK
2024/12/07 03:40:39 DEBUG : c/non empty space: md5 = 351940b3381bfc4c0495291ab342e299 OK
2024/12/07 03:40:39 DEBUG : d: Making directory
2024/12/07 03:40:41 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/12/07 03:40:41 DEBUG : Added delayed dir = "c", newDst=c
2024/12/07 03:40:41 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:40:41 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/12/07 03:40:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:40:41 DEBUG : c/non empty space: Unchanged skipping
2024/12/07 03:40:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:40:44 DEBUG : a/potato2: md5 = 29df4ae35b291c7a8dcbe0ac9b7f16b7 OK
2024/12/07 03:40:44 INFO  : a/potato2: Copied (new)
2024/12/07 03:40:44 DEBUG : Waiting for deletions to finish
2024/12/07 03:40:45 INFO  : b/potato: Deleted
2024/12/07 03:40:46 INFO  : a: Set directory modification time (using DirSetModTime)
2024/12/07 03:40:46 INFO  : d: Removing directory
2024/12/07 03:40:46 INFO  : b: Removing directory
2024/12/07 03:40:47 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/12/07 03:40:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:40:50 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/12/07 03:40:50 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (18.20s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:40:53 DEBUG : empty space: md5 = 8bb6f3e3d1f8311733788bfb28e5229d OK
2024/12/07 03:40:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:40:54 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2024/12/07 03:40:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:40:54 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2024/12/07 03:40:54 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:40:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:40:55 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2024/12/07 03:40:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:40:56 DEBUG : empty space: md5 = dd0a74b0de3b7346327a1c956a8428ce OK
2024/12/07 03:40:56 INFO  : empty space: Copied (replaced existing)
2024/12/07 03:40:56 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (6.40s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.46s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:41:01 DEBUG : foo: md5 = aeab52690877b87a5d4ef63971b4619f OK
2024/12/07 03:41:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:41:01 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2024/12/07 03:41:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:41:03 DEBUG : foo: md5 = 99cb4c8ef25f54fe5c79b26efb7b221e OK
2024/12/07 03:41:03 INFO  : foo: Copied (replaced existing)
2024/12/07 03:41:03 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (5.74s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:41:06 DEBUG : empty space: md5 = b7849a417119e79680c1a9bab6381488 OK
2024/12/07 03:41:07 DEBUG : potato: Need to transfer - File not found at Destination
2024/12/07 03:41:07 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:41:07 DEBUG : empty space: Unchanged skipping
2024/12/07 03:41:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:41:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:41:08 DEBUG : potato: md5 = 50818a9a8b270190d94d9996f5b939ff OK
2024/12/07 03:41:08 INFO  : potato: Copied (new)
2024/12/07 03:41:08 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (6.49s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:41:13 DEBUG : potato: md5 = 25f43107499266fb6be326f54c8cd8bc OK
2024/12/07 03:41:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:41:13 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2024/12/07 03:41:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:41:14 DEBUG : potato: md5 = eeac80aad71787482c7efae4c4f4d02e OK
2024/12/07 03:41:14 INFO  : potato: Copied (replaced existing)
2024/12/07 03:41:14 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (5.26s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:41:18 DEBUG : potato: md5 = 0797c5ca642a92cfbaead22dbb8d00a0 OK
2024/12/07 03:41:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:41:19 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC
2024/12/07 03:41:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:41:20 DEBUG : potato: md5 = 952fd466b8f2d926eeb5fb8a15e0c9af OK
2024/12/07 03:41:20 INFO  : potato: Copied (replaced existing)
2024/12/07 03:41:20 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (5.69s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:41:23 DEBUG : potato: md5 = 8f1e65bd86b8884858972695869a7dd8 OK
2024/12/07 03:41:25 DEBUG : empty space: md5 = 1e070bc9a398768a1ef19d3073988da1 OK
2024/12/07 03:41:25 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/07 03:41:25 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2024/12/07 03:41:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:41:25 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:41:25 DEBUG : empty space: Unchanged skipping
2024/12/07 03:41:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:41:25 DEBUG : Waiting for deletions to finish
2024/12/07 03:41:25 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.97s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:41:29 DEBUG : potato: md5 = d508912d31e279afe9394077746ad468 OK
2024/12/07 03:41:31 DEBUG : empty space: md5 = cddbe9886d950d57e741a441015ea072 OK
2024/12/07 03:41:32 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/07 03:41:32 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:41:32 DEBUG : empty space: Unchanged skipping
2024/12/07 03:41:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:41:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:41:33 DEBUG : potato2: md5 = abee86fe4b623355622d83b12e8a0212 OK
2024/12/07 03:41:33 INFO  : potato2: Copied (new)
2024/12/07 03:41:33 DEBUG : Waiting for deletions to finish
2024/12/07 03:41:34 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.38s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:41:39 DEBUG : b/potato: md5 = bed4e3164dae0beb72d528ba14eddcab OK
2024/12/07 03:41:42 DEBUG : c/non empty space: md5 = ff254a50121ab45efb100ce6aa01ad5b OK
2024/12/07 03:41:42 DEBUG : d: Making directory
2024/12/07 03:41:43 DEBUG : d/e: Making directory
2024/12/07 03:41:45 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/12/07 03:41:45 DEBUG : Added delayed dir = "c", newDst=c
2024/12/07 03:41:45 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:41:45 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/12/07 03:41:45 DEBUG : c/non empty space: Unchanged skipping
2024/12/07 03:41:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:41:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:41:48 DEBUG : a/potato2: md5 = cb5e8c5a5b2a8b52f4cf831662c2c990 OK
2024/12/07 03:41:48 INFO  : a/potato2: Copied (new)
2024/12/07 03:41:48 DEBUG : Waiting for deletions to finish
2024/12/07 03:41:49 INFO  : b/potato: Deleted
2024/12/07 03:41:49 INFO  : a: Set directory modification time (using DirSetModTime)
2024/12/07 03:41:49 INFO  : d/e: Removing directory
2024/12/07 03:41:50 INFO  : d: Removing directory
2024/12/07 03:41:50 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2024/12/07 03:41:51 INFO  : b: Removing directory
2024/12/07 03:41:51 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/12/07 03:41:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:41:54 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/12/07 03:41:55 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (20.36s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:41:59 DEBUG : b/potato: md5 = 381e7688335b1cd05db0ad3c5b5d4240 OK
2024/12/07 03:42:02 DEBUG : c/non empty space: md5 = 21a1ba5530b51acc3e0fd279048f9e96 OK
2024/12/07 03:42:02 DEBUG : d: Making directory
2024/12/07 03:42:04 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/12/07 03:42:04 DEBUG : Added delayed dir = "c", newDst=c
2024/12/07 03:42:04 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:42:04 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/12/07 03:42:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:42:04 DEBUG : c/non empty space: Unchanged skipping
2024/12/07 03:42:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:42:06 DEBUG : a/potato2: md5 = 019068da864add548dbc5ff7bc577605 OK
2024/12/07 03:42:06 INFO  : a/potato2: Copied (new)
2024/12/07 03:42:06 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': not deleting files as there were IO errors
2024/12/07 03:42:07 INFO  : a: Set directory modification time (using DirSetModTime)
2024/12/07 03:42:07 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:42:11 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/12/07 03:42:12 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/12/07 03:42:13 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (17.66s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:42:16 DEBUG : potato: md5 = 8449dc7ee85b2f89c23514232f4de8e2 OK
2024/12/07 03:42:17 DEBUG : empty space: md5 = 7e0861381f55ce426f325954e39d0bcf OK
2024/12/07 03:42:18 DEBUG : Waiting for deletions to finish
2024/12/07 03:42:18 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/07 03:42:18 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:42:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:42:18 DEBUG : empty space: Unchanged skipping
2024/12/07 03:42:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:42:18 INFO  : potato: Deleted
2024/12/07 03:42:20 DEBUG : potato2: md5 = c42ebd7361d47b16ce96c25ebf2d8eaa OK
2024/12/07 03:42:20 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (7.95s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:42:24 DEBUG : potato: md5 = df93924b5bfff91b54580baaf098b0c3 OK
2024/12/07 03:42:25 DEBUG : empty space: md5 = 92046cd227fb8ce53c62ada38352701a OK
2024/12/07 03:42:26 DEBUG : Waiting for deletions to finish
2024/12/07 03:42:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:42:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:42:27 INFO  : potato: Deleted
2024/12/07 03:42:27 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/07 03:42:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:42:27 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:42:27 DEBUG : empty space: Unchanged skipping
2024/12/07 03:42:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:42:28 DEBUG : potato2: md5 = b99342b9893aa032a0be87310ecadaf5 OK
2024/12/07 03:42:28 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (9.26s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:42:33 DEBUG : potato: md5 = 41c65604d20ea01b5940dd7baafc4118 OK
2024/12/07 03:42:34 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/07 03:42:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:42:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:42:36 DEBUG : potato2: md5 = 498256fdd5b446364b3a7ad1fa903e0b OK
2024/12/07 03:42:36 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (6.84s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:42:40 DEBUG : potato2: md5 = 8d4f4de8e720ee2ed080b88b471dfcb4 OK
2024/12/07 03:42:42 DEBUG : empty space: md5 = 3573a392f7b007591f16ebfc62b44ae4 OK
2024/12/07 03:42:42 DEBUG : enormous: Excluded (Size Filter)
2024/12/07 03:42:42 DEBUG : enormous: Excluded
2024/12/07 03:42:42 DEBUG : potato2: Excluded (Size Filter)
2024/12/07 03:42:42 DEBUG : potato2: Excluded
2024/12/07 03:42:42 DEBUG : potato2: Excluded (Size Filter)
2024/12/07 03:42:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:42:42 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:42:42 DEBUG : empty space: Unchanged skipping
2024/12/07 03:42:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:42:42 DEBUG : Waiting for deletions to finish
2024/12/07 03:42:42 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:42:42 DEBUG : enormous: Excluded (Size Filter)
2024/12/07 03:42:42 DEBUG : enormous: Excluded
2024/12/07 03:42:42 DEBUG : potato2: Excluded (Size Filter)
2024/12/07 03:42:42 DEBUG : potato2: Excluded
2024/12/07 03:42:43 DEBUG : potato2: Excluded (Size Filter)
2024/12/07 03:42:43 DEBUG : Local file system at /tmp/rclone2861789748: Waiting for checks to finish
2024/12/07 03:42:43 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/12/07 03:42:43 DEBUG : empty space: Unchanged skipping
2024/12/07 03:42:43 DEBUG : Local file system at /tmp/rclone2861789748: Waiting for transfers to finish
2024/12/07 03:42:43 DEBUG : Waiting for deletions to finish
2024/12/07 03:42:43 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncWithExclude (7.19s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:42:47 DEBUG : potato2: md5 = afb406f0e1b78f6d57c718891fa77faa OK
2024/12/07 03:42:49 DEBUG : empty space: md5 = 444ad7b7a6fbe6253c8eda3917e1ed4e OK
2024/12/07 03:42:50 DEBUG : enormous: md5 = 679fbeab161bfdd55467e2f79f65d32f OK
2024/12/07 03:42:51 DEBUG : enormous: Excluded (Size Filter)
2024/12/07 03:42:51 DEBUG : enormous: Excluded
2024/12/07 03:42:51 DEBUG : potato2: Excluded (Size Filter)
2024/12/07 03:42:51 DEBUG : potato2: Excluded
2024/12/07 03:42:51 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:42:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:42:51 DEBUG : empty space: Unchanged skipping
2024/12/07 03:42:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:42:51 DEBUG : Waiting for deletions to finish
2024/12/07 03:42:52 INFO  : enormous: Deleted
2024/12/07 03:42:52 INFO  : potato2: Deleted
2024/12/07 03:42:52 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:42:52 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/12/07 03:42:52 DEBUG : empty space: Unchanged skipping
2024/12/07 03:42:52 DEBUG : Local file system at /tmp/rclone2861789748: Waiting for checks to finish
2024/12/07 03:42:52 DEBUG : Local file system at /tmp/rclone2861789748: Waiting for transfers to finish
2024/12/07 03:42:52 DEBUG : Waiting for deletions to finish
2024/12/07 03:42:52 INFO  : enormous: Deleted
2024/12/07 03:42:52 INFO  : potato2: Deleted
2024/12/07 03:42:52 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (8.71s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:42:56 DEBUG : one: md5 = 09a4d37f7cc535195dc62064c45e0657 OK
2024/12/07 03:42:57 DEBUG : two: md5 = 38b533ef21790f987962f8952ac9ad69 OK
2024/12/07 03:42:59 DEBUG : three: md5 = e7ff154925c062a20b6d5c09f4a55106 OK
2024/12/07 03:43:01 DEBUG : four: md5 = ca27028728b4db1bb74cd48483951873 OK
2024/12/07 03:43:01 DEBUG : five: Need to transfer - File not found at Destination
2024/12/07 03:43:01 DEBUG : four: Sizes differ (src 4 vs dst 8)
2024/12/07 03:43:01 DEBUG : one: Destination is newer than source, skipping
2024/12/07 03:43:01 DEBUG : three: Sizes identical
2024/12/07 03:43:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:43:01 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2024/12/07 03:43:01 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2024/12/07 03:43:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:43:03 DEBUG : four: md5 = 0fdb9a7079af0835ab0596bd1add8809 OK
2024/12/07 03:43:03 INFO  : four: Copied (replaced existing)
2024/12/07 03:43:03 DEBUG : two: md5 = b868d76adb45d12e25c823a54b98c521 OK
2024/12/07 03:43:03 INFO  : two: Copied (replaced existing)
2024/12/07 03:43:03 DEBUG : five: md5 = 23d37c0fe2531d8ed1c36055dce5c259 OK
2024/12/07 03:43:03 INFO  : five: Copied (new)
2024/12/07 03:43:03 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (12.23s)
=== 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-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2024/12/07 03:43:06 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Ignoring --track-renames as the source and destination do not have a common hash
2024/12/07 03:43:07 DEBUG : potato: Need to transfer - File not found at Destination
2024/12/07 03:43:07 DEBUG : yam: Need to transfer - File not found at Destination
2024/12/07 03:43:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:43:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:43:08 DEBUG : yam: md5 = 15c7054eda7734d490f42e0bd4ea42e9 OK
2024/12/07 03:43:08 INFO  : yam: Copied (new)
2024/12/07 03:43:08 DEBUG : potato: md5 = ff273ea5464fe44afd3c6ee0e9ba6275 OK
2024/12/07 03:43:08 INFO  : potato: Copied (new)
2024/12/07 03:43:08 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:43:09 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Ignoring --track-renames as the source and destination do not have a common hash
2024/12/07 03:43:09 DEBUG : yaml: Need to transfer - File not found at Destination
2024/12/07 03:43:09 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:43:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:43:09 DEBUG : potato: Unchanged skipping
2024/12/07 03:43:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:43:11 DEBUG : yaml: md5 = 02b6d4a385aeb1e0d74d34115198f01c OK
2024/12/07 03:43:11 INFO  : yaml: Copied (new)
2024/12/07 03:43:11 DEBUG : Waiting for deletions to finish
2024/12/07 03:43:11 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (7.63s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2024/12/07 03:43:14 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Making map for --track-renames
2024/12/07 03:43:14 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Finished making map for --track-renames
2024/12/07 03:43:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:43:14 DEBUG : yam: Need to transfer - No matching file found at Destination
2024/12/07 03:43:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for renames to finish
2024/12/07 03:43:14 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/12/07 03:43:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:43:16 DEBUG : yam: md5 = f2b5701fd282819a1a43f9128d2f9f43 OK
2024/12/07 03:43:16 INFO  : yam: Copied (new)
2024/12/07 03:43:16 DEBUG : potato: md5 = bd58f1fac00bdc586f3b64e8f639a0ad OK
2024/12/07 03:43:16 INFO  : potato: Copied (new)
2024/12/07 03:43:16 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:43:17 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:43:17 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Making map for --track-renames
2024/12/07 03:43:17 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Finished making map for --track-renames
2024/12/07 03:43:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:43:17 DEBUG : potato: Unchanged skipping
2024/12/07 03:43:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for renames to finish
2024/12/07 03:43:17 INFO  : yam: Moved (server-side) to: yaml
2024/12/07 03:43:17 INFO  : yaml: Renamed from "yam"
2024/12/07 03:43:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:43:17 DEBUG : Waiting for deletions to finish
2024/12/07 03:43:17 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (6.10s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2024/12/07 03:43:20 DEBUG : Added delayed dir = "sub", newDst=<nil>
2024/12/07 03:43:20 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Making map for --track-renames
2024/12/07 03:43:20 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Finished making map for --track-renames
2024/12/07 03:43:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:43:20 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/12/07 03:43:20 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2024/12/07 03:43:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for renames to finish
2024/12/07 03:43:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:43:23 DEBUG : potato: md5 = 9808baaaad4c1d20b64b2e92f48a1a54 OK
2024/12/07 03:43:23 INFO  : potato: Copied (new)
2024/12/07 03:43:23 DEBUG : sub/yam: md5 = dcccaae5972b15355408bc6df4df9f83 OK
2024/12/07 03:43:23 INFO  : sub/yam: Copied (new)
2024/12/07 03:43:23 DEBUG : Waiting for deletions to finish
2024/12/07 03:43:24 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:43:25 DEBUG : Added delayed dir = "sub", newDst=sub
2024/12/07 03:43:25 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:43:25 DEBUG : potato: Unchanged skipping
2024/12/07 03:43:25 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Making map for --track-renames
2024/12/07 03:43:25 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Finished making map for --track-renames
2024/12/07 03:43:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:43:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for renames to finish
2024/12/07 03:43:26 INFO  : sub/yam: Moved (server-side) to: yam
2024/12/07 03:43:26 INFO  : yam: Renamed from "sub/yam"
2024/12/07 03:43:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:43:26 DEBUG : Waiting for deletions to finish
2024/12/07 03:43:26 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (10.29s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:43:30 DEBUG : Creating backend with remote "/tmp/rclone2861789748/dir1"
2024/12/07 03:43:30 DEBUG : Config file has changed externally - reloading
2024/12/07 03:43:30 DEBUG : Creating backend with remote "/tmp/rclone2861789748/dir2"
2024/12/07 03:43:30 DEBUG : Local file system at /tmp/rclone2861789748/dir2: Using server-side directory move
2024/12/07 03:43:30 INFO  : Local file system at /tmp/rclone2861789748/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/12/07 03:43:30 DEBUG : file1.txt: Need to transfer - File not found at Destination
2024/12/07 03:43:30 INFO  : file1.txt: Moved (server-side)
2024/12/07 03:43:30 DEBUG : Local file system at /tmp/rclone2861789748/dir2: Waiting for checks to finish
2024/12/07 03:43:30 DEBUG : Local file system at /tmp/rclone2861789748/dir2: Waiting for transfers to finish
--- PASS: TestServerSideMoveLocal (0.47s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:43:31 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/12/07 03:43:31 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/07 03:43:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/07 03:43:31 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/12/07 03:43:31 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/12/07 03:43:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:43:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:43:34 DEBUG : sub dir/hello world: md5 = e686fed68a379164a48482cc40dfb399 OK
2024/12/07 03:43:34 INFO  : sub dir/hello world: Copied (new)
2024/12/07 03:43:34 INFO  : sub dir/hello world: Deleted
2024/12/07 03:43:37 DEBUG : nested/sub dir/file: md5 = 8d211013e4f0c748fafde0ecdd5b8031 OK
2024/12/07 03:43:37 INFO  : nested/sub dir/file: Copied (new)
2024/12/07 03:43:37 INFO  : nested/sub dir/file: Deleted
2024/12/07 03:43:37 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/12/07 03:43:38 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/07 03:43:38 INFO  : nested: Set directory modification time (using DirSetModTime)
2024/12/07 03:43:38 INFO  : sub dir: Removing directory
2024/12/07 03:43:38 INFO  : nested/sub dir: Removing directory
2024/12/07 03:43:38 INFO  : nested: Removing directory
2024/12/07 03:43:38 DEBUG : Local file system at /tmp/rclone2861789748: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:43:41 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/12/07 03:43:42 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/12/07 03:43:43 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (13.23s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:43:44 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/12/07 03:43:44 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/07 03:43:44 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/07 03:43:44 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/12/07 03:43:44 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/12/07 03:43:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:43:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:43:47 DEBUG : sub dir/hello world: md5 = 4ff8ab6b23ce97de51c987441d2776fd OK
2024/12/07 03:43:47 INFO  : sub dir/hello world: Copied (new)
2024/12/07 03:43:47 INFO  : sub dir/hello world: Deleted
2024/12/07 03:43:49 DEBUG : nested/sub dir/file: md5 = 1a813fd46ba5cdae65b737c5acc6abca OK
2024/12/07 03:43:49 INFO  : nested/sub dir/file: Copied (new)
2024/12/07 03:43:49 INFO  : nested/sub dir/file: Deleted
2024/12/07 03:43:50 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/12/07 03:43:50 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/07 03:43:50 INFO  : nested: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:43:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/12/07 03:43:55 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/12/07 03:43:55 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (12.69s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:43:57 DEBUG : existing: Need to transfer - File not found at Destination
2024/12/07 03:43:57 DEBUG : existing-b: Need to transfer - File not found at Destination
2024/12/07 03:43:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:43:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:43:59 DEBUG : existing: md5 = d9d458ae78ef3b577f48b5b3bd18f40c OK
2024/12/07 03:43:59 INFO  : existing: Copied (new)
2024/12/07 03:43:59 INFO  : existing: Deleted
2024/12/07 03:43:59 DEBUG : existing-b: md5 = 33357b279b002483357cbe259e1f8c38 OK
2024/12/07 03:43:59 INFO  : existing-b: Copied (new)
2024/12/07 03:43:59 INFO  : existing-b: Deleted
2024/12/07 03:43:59 DEBUG : existing: Destination exists, skipping
2024/12/07 03:43:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:43:59 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2024/12/07 03:43:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:43:59 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (4.77s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:44:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tefufip8zugi"
2024/12/07 03:44:02 DEBUG : Creating backend with remote "TestDrive:crypt/f6omt3qp1d1phjjd0k29mfi437cmvr4rqpcaapml0ragafcmftt0"
2024/12/07 03:44:06 DEBUG : potato2: md5 = b4bffe3ede88ea0e149673230de348e5 OK
2024/12/07 03:44:07 DEBUG : empty space: md5 = 2fbc4a6da28043b6497214c189b4ad1d OK
2024/12/07 03:44:09 DEBUG : potato3: md5 = 24d1d639f094cbfd7e312bcc4f8a8bb7 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha' -> Encrypted drive 'TestCryptDrive:rclone-test-tefufip8zugi'
2024/12/07 03:44:12 DEBUG : empty space: md5 = 6a66a2c309562e0d05ce292a21c1edf0 OK
2024/12/07 03:44:13 DEBUG : potato3: md5 = f0350d9273b5d25ed76371e9e5597b79 OK
2024/12/07 03:44:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tefufip8zugi': Using server-side directory move
2024/12/07 03:44:14 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tefufip8zugi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/12/07 03:44:14 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/07 03:44:14 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/12/07 03:44:14 DEBUG : empty space: Unchanged skipping
2024/12/07 03:44:14 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/12/07 03:44:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tefufip8zugi': Waiting for checks to finish
2024/12/07 03:44:14 INFO  : potato3: Deleted
2024/12/07 03:44:14 INFO  : empty space: Deleted
2024/12/07 03:44:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tefufip8zugi': Waiting for transfers to finish
2024/12/07 03:44:15 INFO  : potato2: Moved (server-side)
2024/12/07 03:44:15 INFO  : potato3: Moved (server-side)
2024/12/07 03:44:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suqohow5huba"
2024/12/07 03:44:16 DEBUG : Creating backend with remote "TestDrive:crypt/5iqum7qmuosagm2orjthpu39itr2al9b2cbl4sl0g3e0j1h6g3ng"
2024/12/07 03:44:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suqohow5huba': Using server-side directory move
2024/12/07 03:44:18 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-suqohow5huba': Server side directory move succeeded
2024/12/07 03:44:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suqohow5huba': Purge remote
2024/12/07 03:44:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tefufip8zugi': Purge remote
2024/12/07 03:44:20 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (18.57s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:44:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qihudeh4riku"
2024/12/07 03:44:20 DEBUG : Creating backend with remote "TestDrive:crypt/g0bg5fmaa918om0dv7revkg6n1ip7f6jb67k6f908uih3ipss6p0"
2024/12/07 03:44:23 DEBUG : potato2: md5 = 72b0ba3f795067c575cdb9d943b92478 OK
2024/12/07 03:44:25 DEBUG : empty space: md5 = 3b9dd2854cd060eb9fdb482426054d7b OK
2024/12/07 03:44:27 DEBUG : potato3: md5 = 8f2e61a5bd240e21ea80e2994375ae15 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha' -> Encrypted drive 'TestCryptDrive:rclone-test-qihudeh4riku'
2024/12/07 03:44:30 DEBUG : empty space: md5 = 4fcf1240b88271d4408386bbd7048556 OK
2024/12/07 03:44:32 DEBUG : potato3: md5 = 0a6abad4aa7f0bd078877395468a8748 OK
2024/12/07 03:44:32 DEBUG : empty space: Excluded (Size Filter)
2024/12/07 03:44:32 DEBUG : empty space: Excluded (Size Filter)
2024/12/07 03:44:32 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/07 03:44:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qihudeh4riku': Waiting for checks to finish
2024/12/07 03:44:32 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/12/07 03:44:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qihudeh4riku': Waiting for transfers to finish
2024/12/07 03:44:33 INFO  : potato3: Deleted
2024/12/07 03:44:33 INFO  : potato2: Moved (server-side)
2024/12/07 03:44:34 INFO  : potato3: Moved (server-side)
2024/12/07 03:44:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kawapez2haqo"
2024/12/07 03:44:34 DEBUG : Creating backend with remote "TestDrive:crypt/p0ncqthf9bn7ljo948pjvr5njpmcii47fphak31gcqj6b59dk2p0"
2024/12/07 03:44:36 DEBUG : empty space: Excluded (Size Filter)
2024/12/07 03:44:36 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/07 03:44:36 DEBUG : potato3: Need to transfer - File not found at Destination
2024/12/07 03:44:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kawapez2haqo': Waiting for checks to finish
2024/12/07 03:44:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kawapez2haqo': Waiting for transfers to finish
2024/12/07 03:44:38 INFO  : potato2: Moved (server-side)
2024/12/07 03:44:38 INFO  : potato3: Moved (server-side)
2024/12/07 03:44:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kawapez2haqo': Purge remote
2024/12/07 03:44:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qihudeh4riku': Purge remote
--- PASS: TestServerSideMoveWithFilter (20.62s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:44:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xedavat1boxi"
2024/12/07 03:44:41 DEBUG : Creating backend with remote "TestDrive:crypt/t84e8p200nvlpu1391d99qui7m6svf1jf1bhah56hqgf7eveovu0"
2024/12/07 03:44:43 DEBUG : potato2: md5 = 99ea0b708a13668c40aefebfe314c343 OK
2024/12/07 03:44:45 DEBUG : empty space: md5 = 4de102182a0d69f462888a54cad73910 OK
2024/12/07 03:44:47 DEBUG : potato3: md5 = 1992aaead7ed5b8be59d98fc806e9df3 OK
2024/12/07 03:44:47 DEBUG : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha' -> Encrypted drive 'TestCryptDrive:rclone-test-xedavat1boxi'
2024/12/07 03:44:51 DEBUG : empty space: md5 = 03f2e52ad106b471ae01b8ca31bc7b9e OK
2024/12/07 03:44:53 DEBUG : potato3: md5 = 4d6a0218b4222aa7622180b8e2b7f3f1 OK
2024/12/07 03:44:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xedavat1boxi': Using server-side directory move
2024/12/07 03:44:53 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-xedavat1boxi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/12/07 03:44:54 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/07 03:44:54 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2024/12/07 03:44:54 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/12/07 03:44:54 DEBUG : empty space: Unchanged skipping
2024/12/07 03:44:54 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/12/07 03:44:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xedavat1boxi': Waiting for checks to finish
2024/12/07 03:44:54 INFO  : potato3: Deleted
2024/12/07 03:44:54 INFO  : empty space: Deleted
2024/12/07 03:44:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xedavat1boxi': Waiting for transfers to finish
2024/12/07 03:44:55 INFO  : potato2: Moved (server-side)
2024/12/07 03:44:55 INFO  : potato3: Moved (server-side)
2024/12/07 03:44:55 INFO  : tomatoDir: Removing directory
2024/12/07 03:44:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': deleted 1 directories
2024/12/07 03:44:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-duxakac2yufa"
2024/12/07 03:44:57 DEBUG : Creating backend with remote "TestDrive:crypt/l6e576q1hpsdphul63ejthdv7tlptae0teh123q85he8jh86uidg"
2024/12/07 03:44:58 DEBUG : tomatoDir: Making directory
2024/12/07 03:44:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-duxakac2yufa': Using server-side directory move
2024/12/07 03:45:00 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-duxakac2yufa': Server side directory move succeeded
2024/12/07 03:45:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-duxakac2yufa': Purge remote
2024/12/07 03:45:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xedavat1boxi': Purge remote
2024/12/07 03:45:02 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (21.64s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.45s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:45:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/rclone-sync-test"
2024/12/07 03:45:03 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncOverlap (4.02s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:45:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/rclone-sync-test"
2024/12/07 03:45:07 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2024/12/07 03:45:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/rclone-sync-test-include/layer2"
2024/12/07 03:45:09 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2024/12/07 03:45:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/rclone-sync-test-ignore-file"
2024/12/07 03:45:13 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2024/12/07 03:45:18 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 31574902d215e7086c60ab61434f72b1 OK
2024/12/07 03:45:20 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/12/07 03:45:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/rclone-sync-test': Waiting for checks to finish
2024/12/07 03:45:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/rclone-sync-test': Waiting for transfers to finish
2024/12/07 03:45:20 DEBUG : Waiting for deletions to finish
2024/12/07 03:45:20 INFO  : There was nothing to transfer
2024/12/07 03:45:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:45:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:45:22 DEBUG : Waiting for deletions to finish
2024/12/07 03:45:22 INFO  : rclone-sync-test-include: Removing directory
2024/12/07 03:45:22 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/12/07 03:45:22 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/12/07 03:45:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': failed to delete 1 directories
2024/12/07 03:45:22 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:45:24 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/12/07 03:45:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/rclone-sync-test-include/layer2': Waiting for checks to finish
2024/12/07 03:45:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/rclone-sync-test-include/layer2': Waiting for transfers to finish
2024/12/07 03:45:24 DEBUG : Waiting for deletions to finish
2024/12/07 03:45:24 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:45:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:45:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:45:26 DEBUG : Waiting for deletions to finish
2024/12/07 03:45:26 INFO  : rclone-sync-test-include: Removing directory
2024/12/07 03:45:27 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/12/07 03:45:27 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/12/07 03:45:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': failed to delete 1 directories
2024/12/07 03:45:27 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:45:29 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/12/07 03:45:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/rclone-sync-test-ignore-file': Waiting for checks to finish
2024/12/07 03:45:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/rclone-sync-test-ignore-file': Waiting for transfers to finish
2024/12/07 03:45:29 DEBUG : Waiting for deletions to finish
2024/12/07 03:45:29 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:45:31 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/12/07 03:45:32 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (35.19s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:45:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/dst"
2024/12/07 03:45:42 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/07 03:45:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/CompareDest"
2024/12/07 03:45:44 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/gveqi14airsml4bgu7krj116o8"
2024/12/07 03:45:46 DEBUG : one: Need to transfer - File not found at Destination
2024/12/07 03:45:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:45:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:45:49 DEBUG : one: md5 = ad1432e18699af1480d82f66243c1a79 OK
2024/12/07 03:45:49 INFO  : one: Copied (new)
2024/12/07 03:45:49 DEBUG : Waiting for deletions to finish
2024/12/07 03:45:50 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/07 03:45:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:45:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:45:52 DEBUG : one: md5 = 8ec7ebae08dedd1e85c892fb74a4a221 OK
2024/12/07 03:45:52 INFO  : one: Copied (replaced existing)
2024/12/07 03:45:52 DEBUG : Waiting for deletions to finish
2024/12/07 03:45:54 DEBUG : dst/one: md5 = 05b8391bf57966f031a2914452b63ffa OK
2024/12/07 03:45:56 DEBUG : CompareDest/one: md5 = 3ea757b2377baf148ea8b1353e56f613 OK
2024/12/07 03:45:57 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/07 03:45:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:45:58 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:45:58 DEBUG : one: Destination found in --compare-dest, skipping
2024/12/07 03:45:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:45:58 DEBUG : Waiting for deletions to finish
2024/12/07 03:45:58 INFO  : There was nothing to transfer
2024/12/07 03:46:00 DEBUG : CompareDest/two: md5 = bff57cad8891ef2475b644b55a5bc18d OK
2024/12/07 03:46:01 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:46:01 DEBUG : two: Destination found in --compare-dest, skipping
2024/12/07 03:46:01 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/07 03:46:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:46:01 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:46:01 DEBUG : one: Destination found in --compare-dest, skipping
2024/12/07 03:46:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:46:01 DEBUG : Waiting for deletions to finish
2024/12/07 03:46:01 INFO  : There was nothing to transfer
2024/12/07 03:46:02 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:46:02 DEBUG : two: Destination found in --compare-dest, skipping
2024/12/07 03:46:02 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/07 03:46:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:46:03 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:46:03 DEBUG : one: Destination found in --compare-dest, skipping
2024/12/07 03:46:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:46:03 DEBUG : Waiting for deletions to finish
2024/12/07 03:46:03 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2024/12/07 03:46:04 DEBUG : two: Sizes differ (src 5 vs dst 3)
2024/12/07 03:46:04 DEBUG : two: Need to transfer - File not found at Destination
2024/12/07 03:46:04 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/07 03:46:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:46:05 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:46:05 DEBUG : one: Destination found in --compare-dest, skipping
2024/12/07 03:46:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:46:06 DEBUG : two: md5 = 4ef8706412d4695a4d3e9dbef990c4f9 OK
2024/12/07 03:46:06 INFO  : two: Copied (new)
2024/12/07 03:46:06 DEBUG : Waiting for deletions to finish
2024/12/07 03:46:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/07 03:46:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/07 03:46:11 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/07 03:46:11 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncCompareDest (29.57s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:46:14 DEBUG : pre-dest1/1: md5 = 4bc36bc4f878846a039b782e8d9ed592 OK
2024/12/07 03:46:17 DEBUG : pre-dest2/2: md5 = 65b67333e496858060ac5b4b045d1987 OK
2024/12/07 03:46:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/dest"
2024/12/07 03:46:18 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/rg03c1jvnehrrc617i0lnqjddc"
2024/12/07 03:46:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/pre-dest1"
2024/12/07 03:46:19 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/bbnblvh6k061ssopqrp18kd7gc"
2024/12/07 03:46:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/pre-dest2"
2024/12/07 03:46:20 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/dgicm1h6b5ejvlltm8eeif0bnk"
2024/12/07 03:46:21 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:46:21 DEBUG : 1: Destination found in --compare-dest, skipping
2024/12/07 03:46:22 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:46:22 DEBUG : 2: Destination found in --compare-dest, skipping
2024/12/07 03:46:23 DEBUG : 3: Need to transfer - File not found at Destination
2024/12/07 03:46:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dest': Waiting for checks to finish
2024/12/07 03:46:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dest': Waiting for transfers to finish
2024/12/07 03:46:26 DEBUG : 3: md5 = a806a0c577f975e7f8b1caa35db67d06 OK
2024/12/07 03:46:26 INFO  : 3: Copied (new)
2024/12/07 03:46:26 DEBUG : Waiting for deletions to finish
2024/12/07 03:46:30 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2024/12/07 03:46:31 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2024/12/07 03:46:32 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (21.24s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:46:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/dst"
2024/12/07 03:46:33 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/07 03:46:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/CopyDest"
2024/12/07 03:46:35 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/d09o6po3f7bm6ce32vdgs8h9ls"
2024/12/07 03:46:37 DEBUG : one: Need to transfer - File not found at Destination
2024/12/07 03:46:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:46:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:46:40 DEBUG : one: md5 = 8be6788de594dc1c6176165b9c087ebc OK
2024/12/07 03:46:40 INFO  : one: Copied (new)
2024/12/07 03:46:40 DEBUG : Waiting for deletions to finish
2024/12/07 03:46:41 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/07 03:46:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:46:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:46:43 DEBUG : one: md5 = eb7751a7bf7823c7552e75ee356f128e OK
2024/12/07 03:46:43 INFO  : one: Copied (replaced existing)
2024/12/07 03:46:43 DEBUG : Waiting for deletions to finish
2024/12/07 03:46:45 DEBUG : dst/one: md5 = 500caa271e959e92d6353177ab1a7744 OK
2024/12/07 03:46:48 DEBUG : CopyDest/one: md5 = f867828a861f87f7b5a09565e8701582 OK
2024/12/07 03:46:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/BackupDir"
2024/12/07 03:46:48 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/s6dbk3lfi7c9kfvo6j7bla9m0g"
2024/12/07 03:46:50 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/07 03:46:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:46:51 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:46:51 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/07 03:46:53 INFO  : one: Moved (server-side)
2024/12/07 03:46:54 INFO  : one: Copied (server-side copy)
2024/12/07 03:46:54 DEBUG : one: Destination found in --copy-dest, using server-side copy
2024/12/07 03:46:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:46:54 DEBUG : Waiting for deletions to finish
2024/12/07 03:46:56 DEBUG : CopyDest/two: md5 = 6eef96fa867918bf71d87e8c6d863d0e OK
2024/12/07 03:46:57 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:46:59 INFO  : two: Copied (server-side copy)
2024/12/07 03:46:59 DEBUG : two: Destination found in --copy-dest, using server-side copy
2024/12/07 03:46:59 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:46:59 DEBUG : one: Unchanged skipping
2024/12/07 03:46:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:46:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:46:59 DEBUG : Waiting for deletions to finish
2024/12/07 03:47:00 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:47:00 DEBUG : one: Unchanged skipping
2024/12/07 03:47:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:47:00 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:47:00 DEBUG : two: Unchanged skipping
2024/12/07 03:47:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:47:00 DEBUG : Waiting for deletions to finish
2024/12/07 03:47:00 INFO  : There was nothing to transfer
2024/12/07 03:47:02 DEBUG : CopyDest/three: md5 = 2b58c3323376034294ab91f69cf06b7d OK
2024/12/07 03:47:03 DEBUG : three: Sizes differ (src 7 vs dst 5)
2024/12/07 03:47:03 DEBUG : three: Destination not found in --copy-dest
2024/12/07 03:47:03 DEBUG : three: Need to transfer - File not found at Destination
2024/12/07 03:47:03 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:47:03 DEBUG : one: Unchanged skipping
2024/12/07 03:47:03 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/07 03:47:03 DEBUG : two: Unchanged skipping
2024/12/07 03:47:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:47:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:47:05 DEBUG : three: md5 = bcd3ab4a0c747211aeeab93dfb76d651 OK
2024/12/07 03:47:05 INFO  : three: Copied (new)
2024/12/07 03:47:05 DEBUG : Waiting for deletions to finish
2024/12/07 03:47:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/12/07 03:47:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/07 03:47:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/07 03:47:12 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/07 03:47:12 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/12/07 03:47:12 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/07 03:47:13 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (41.15s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:47:17 DEBUG : dst/one: md5 = 5bac0bf84b144746ed89e2cc47ab9105 OK
2024/12/07 03:47:19 DEBUG : dst/two: md5 = e2349f61abe34d2ea704cb45571d47f4 OK
2024/12/07 03:47:20 DEBUG : dst/three.txt: md5 = b2c10efd815c0ed78796ce343ab32a51 OK
2024/12/07 03:47:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/dst"
2024/12/07 03:47:21 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/07 03:47:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/backup"
2024/12/07 03:47:22 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/1nrff024r7pq65ecp72fc28jb0"
2024/12/07 03:47:24 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:47:24 DEBUG : two: Unchanged skipping
2024/12/07 03:47:24 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/07 03:47:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:47:26 INFO  : one: Moved (server-side)
2024/12/07 03:47:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:47:28 DEBUG : one: md5 = 08ac3728fb6c2c4ad735dac507666b8f OK
2024/12/07 03:47:28 INFO  : one: Copied (new)
2024/12/07 03:47:28 DEBUG : Waiting for deletions to finish
2024/12/07 03:47:29 INFO  : three.txt: Moved (server-side)
2024/12/07 03:47:29 INFO  : three.txt: Moved into backup dir
2024/12/07 03:47:31 DEBUG : dst/three.txt: md5 = 4257aa50c527cbebe76054c95a4e43a9 OK
2024/12/07 03:47:32 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/07 03:47:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:47:32 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:47:32 DEBUG : two: Unchanged skipping
2024/12/07 03:47:33 INFO  : one: Deleted
2024/12/07 03:47:34 INFO  : one: Moved (server-side)
2024/12/07 03:47:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:47:36 DEBUG : one: md5 = 126baf81558adfb6cd652832ccd2adf0 OK
2024/12/07 03:47:36 INFO  : one: Copied (new)
2024/12/07 03:47:36 DEBUG : Waiting for deletions to finish
2024/12/07 03:47:36 INFO  : three.txt: Deleted
2024/12/07 03:47:37 INFO  : three.txt: Moved (server-side)
2024/12/07 03:47:37 INFO  : three.txt: Moved into backup dir
2024/12/07 03:47:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/07 03:47:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/07 03:47:42 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/07 03:47:42 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/12/07 03:47:42 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/07 03:47:42 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
--- PASS: TestSyncBackupDir (28.82s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:47:46 DEBUG : dst/one: md5 = cea05191a14415c5f9cbae4fc5870468 OK
2024/12/07 03:47:47 DEBUG : dst/two: md5 = 868ac9ae98cdc9d902e7b4a4a99cf3aa OK
2024/12/07 03:47:49 DEBUG : dst/three.txt: md5 = d86b4c1143e75089fc34b4fffe93bacf OK
2024/12/07 03:47:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/dst"
2024/12/07 03:47:49 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/07 03:47:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/backup"
2024/12/07 03:47:50 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/1nrff024r7pq65ecp72fc28jb0"
2024/12/07 03:47:52 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/07 03:47:52 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:47:52 DEBUG : two: Unchanged skipping
2024/12/07 03:47:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:47:55 INFO  : one: Moved (server-side) to: one.bak
2024/12/07 03:47:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:47:56 DEBUG : one: md5 = a43b42e5f8828987c92aff41f049a522 OK
2024/12/07 03:47:56 INFO  : one: Copied (new)
2024/12/07 03:47:56 DEBUG : Waiting for deletions to finish
2024/12/07 03:47:57 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/07 03:47:57 INFO  : three.txt: Moved into backup dir
2024/12/07 03:48:00 DEBUG : dst/three.txt: md5 = fbfee5f30b72ca19e533a4ce8f6c717e OK
2024/12/07 03:48:00 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/07 03:48:00 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:48:00 DEBUG : two: Unchanged skipping
2024/12/07 03:48:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:48:01 INFO  : one.bak: Deleted
2024/12/07 03:48:02 INFO  : one: Moved (server-side) to: one.bak
2024/12/07 03:48:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:48:04 DEBUG : one: md5 = 8b1b6f83658a9dbc70dc6d2c90098eb6 OK
2024/12/07 03:48:04 INFO  : one: Copied (new)
2024/12/07 03:48:04 DEBUG : Waiting for deletions to finish
2024/12/07 03:48:05 INFO  : three.txt.bak: Deleted
2024/12/07 03:48:06 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/07 03:48:06 INFO  : three.txt: Moved into backup dir
2024/12/07 03:48:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/07 03:48:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/07 03:48:11 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/12/07 03:48:11 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/12/07 03:48:11 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/12/07 03:48:11 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirWithSuffix (28.68s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:48:14 DEBUG : dst/one: md5 = cb688df5d854e92ecbbc01cc0eb52d2d OK
2024/12/07 03:48:16 DEBUG : dst/two: md5 = 0eeb4fd26c2471ef66479927d26cec92 OK
2024/12/07 03:48:17 DEBUG : dst/three.txt: md5 = 5fbcbd083a4bcdd2ac958633e624c5b7 OK
2024/12/07 03:48:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/dst"
2024/12/07 03:48:18 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/07 03:48:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/backup"
2024/12/07 03:48:19 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/1nrff024r7pq65ecp72fc28jb0"
2024/12/07 03:48:21 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/07 03:48:21 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:48:21 DEBUG : two: Unchanged skipping
2024/12/07 03:48:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:48:23 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/12/07 03:48:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:48:25 DEBUG : one: md5 = 3a9d46dcc43b8896ccf69f9440ba6d6f OK
2024/12/07 03:48:25 INFO  : one: Copied (new)
2024/12/07 03:48:25 DEBUG : Waiting for deletions to finish
2024/12/07 03:48:26 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/12/07 03:48:26 INFO  : three.txt: Moved into backup dir
2024/12/07 03:48:28 DEBUG : dst/three.txt: md5 = 9f1d57597919ae684d0d0a77bd3e77e2 OK
2024/12/07 03:48:29 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/07 03:48:29 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:48:29 DEBUG : two: Unchanged skipping
2024/12/07 03:48:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:48:30 INFO  : one-2019-01-01: Deleted
2024/12/07 03:48:31 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/12/07 03:48:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:48:33 DEBUG : one: md5 = d536df7807761daab175bcfe9e6c216c OK
2024/12/07 03:48:33 INFO  : one: Copied (new)
2024/12/07 03:48:33 DEBUG : Waiting for deletions to finish
2024/12/07 03:48:34 INFO  : three-2019-01-01.txt: Deleted
2024/12/07 03:48:35 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/12/07 03:48:35 INFO  : three.txt: Moved into backup dir
2024/12/07 03:48:38 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/07 03:48:38 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/07 03:48:39 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/12/07 03:48:39 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/12/07 03:48:39 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/12/07 03:48:39 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (28.27s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:48:42 DEBUG : dst/one: md5 = efd71e77b5994247c63d7763734107a6 OK
2024/12/07 03:48:44 DEBUG : dst/two: md5 = ab49aa473c5ea5a86fda91357a44ef2a OK
2024/12/07 03:48:46 DEBUG : dst/three.txt: md5 = 8095a65c8a4ac81199f3214dca72506d OK
2024/12/07 03:48:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/dst"
2024/12/07 03:48:47 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/07 03:48:48 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/07 03:48:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:48:48 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:48:48 DEBUG : two: Unchanged skipping
2024/12/07 03:48:48 INFO  : one: Moved (server-side) to: one.bak
2024/12/07 03:48:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:48:50 DEBUG : one: md5 = afec0b1ebcd53b70ddd99ff3f65d9273 OK
2024/12/07 03:48:50 INFO  : one: Copied (new)
2024/12/07 03:48:50 DEBUG : Waiting for deletions to finish
2024/12/07 03:48:51 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/07 03:48:51 INFO  : three.txt: Moved into backup dir
2024/12/07 03:48:53 DEBUG : dst/three.txt: md5 = fb8a4025d6f18c164c894ee7cc520c6c OK
2024/12/07 03:48:54 DEBUG : one.bak: Excluded (Path Filter)
2024/12/07 03:48:54 DEBUG : three.txt.bak: Excluded (Path Filter)
2024/12/07 03:48:54 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/07 03:48:54 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:48:54 DEBUG : two: Unchanged skipping
2024/12/07 03:48:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for checks to finish
2024/12/07 03:48:55 INFO  : one.bak: Deleted
2024/12/07 03:48:55 INFO  : one: Moved (server-side) to: one.bak
2024/12/07 03:48:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha/dst': Waiting for transfers to finish
2024/12/07 03:48:57 DEBUG : one: md5 = 60848999191d15cad89262aab8f1b026 OK
2024/12/07 03:48:57 INFO  : one: Copied (new)
2024/12/07 03:48:57 DEBUG : Waiting for deletions to finish
2024/12/07 03:48:58 INFO  : three.txt.bak: Deleted
2024/12/07 03:48:59 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/07 03:48:59 INFO  : three.txt: Moved into backup dir
2024/12/07 03:49:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/07 03:49:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/12/07 03:49:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/12/07 03:49:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/07 03:49:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/12/07 03:49:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirSuffixOnly (23.24s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:49:06 DEBUG : dst/one: md5 = 32396e7eea11111d32a957c534e28e4f OK
2024/12/07 03:49:07 DEBUG : dst/two: md5 = cc2352a85b3043e025bf19130501f37e OK
2024/12/07 03:49:09 DEBUG : dst/three.txt: md5 = b60eb1b4fc1bec2206e62be5d5265430 OK
2024/12/07 03:49:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/dst"
2024/12/07 03:49:10 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/07 03:49:11 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/07 03:49:11 INFO  : one: Moved (server-side) to: one.bak
2024/12/07 03:49:13 DEBUG : one: md5 = 7174ed2eba6a2a26851af6c3e67f5dd5 OK
2024/12/07 03:49:13 INFO  : one: Copied (new)
2024/12/07 03:49:14 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:49:14 DEBUG : two: Unchanged skipping
2024/12/07 03:49:14 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/12/07 03:49:15 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/07 03:49:16 DEBUG : three.txt: md5 = 4f427dbd0f8d8c36ca7f38b4bc468941 OK
2024/12/07 03:49:16 INFO  : three.txt: Copied (new)
2024/12/07 03:49:18 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/07 03:49:19 INFO  : one.bak: Deleted
2024/12/07 03:49:19 INFO  : one: Moved (server-side) to: one.bak
2024/12/07 03:49:21 DEBUG : one: md5 = cf58f468a7ecebf5d81875d2f94d7d41 OK
2024/12/07 03:49:21 INFO  : one: Copied (new)
2024/12/07 03:49:21 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:49:21 DEBUG : two: Unchanged skipping
2024/12/07 03:49:22 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/12/07 03:49:22 INFO  : three.txt.bak: Deleted
2024/12/07 03:49:23 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/07 03:49:25 DEBUG : three.txt: md5 = f97127c4712e6ea10429e76a1c11f99f OK
2024/12/07 03:49:25 INFO  : three.txt: Copied (new)
2024/12/07 03:49:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/07 03:49:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/12/07 03:49:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/12/07 03:49:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/07 03:49:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/12/07 03:49:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/12/07 03:49:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncSuffix (27.06s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:49:33 DEBUG : dst/one: md5 = 6ef724947d5e1b9f15d488b8f4fa06f9 OK
2024/12/07 03:49:35 DEBUG : dst/two: md5 = 7758f4df755f9c6fcc6e78530c35bab6 OK
2024/12/07 03:49:36 DEBUG : dst/three.txt: md5 = 0c1ab745936ae9c556eae7c48e0108dd OK
2024/12/07 03:49:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tadisoz1giha/dst"
2024/12/07 03:49:37 DEBUG : Creating backend with remote "TestDrive:crypt/t1hr86661it5756a2ufps8s4uvnmtlgps3o4figc3and3bm59rgg/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/07 03:49:38 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/07 03:49:39 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/12/07 03:49:40 DEBUG : one: md5 = 06f01af4cd6a54342897901f563b5fe4 OK
2024/12/07 03:49:40 INFO  : one: Copied (new)
2024/12/07 03:49:40 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:49:40 DEBUG : two: Unchanged skipping
2024/12/07 03:49:41 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/12/07 03:49:41 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/12/07 03:49:44 DEBUG : three.txt: md5 = 3afbcb5e47529c66b3c67e3e129f1bdf OK
2024/12/07 03:49:44 INFO  : three.txt: Copied (new)
2024/12/07 03:49:45 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/07 03:49:46 INFO  : one-2019-01-01: Deleted
2024/12/07 03:49:46 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/12/07 03:49:48 DEBUG : one: md5 = 69daedab12169196473e5c5321aa4049 OK
2024/12/07 03:49:48 INFO  : one: Copied (new)
2024/12/07 03:49:48 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:49:48 DEBUG : two: Unchanged skipping
2024/12/07 03:49:49 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/12/07 03:49:50 INFO  : three-2019-01-01.txt: Deleted
2024/12/07 03:49:50 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/12/07 03:49:52 DEBUG : three.txt: md5 = 751e1330710d0e416fdce95fdec3a970 OK
2024/12/07 03:49:52 INFO  : three.txt: Copied (new)
2024/12/07 03:49:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/12/07 03:49:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/07 03:49:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/12/07 03:49:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/12/07 03:49:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/12/07 03:49:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/07 03:49:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncSuffixKeepExtension (27.06s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:49:59 DEBUG : Testêé: md5 = 2e76eee54597090c21956fede1ef6a9f OK
2024/12/07 03:49:59 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2024/12/07 03:49:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:49:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:50:00 DEBUG : Testêé: md5 = 58f2f6e24b99fe191d4739b8c65ddcbd OK
2024/12/07 03:50:00 INFO  : Testêé: Copied (replaced existing) to: Testêé
2024/12/07 03:50:00 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (4.72s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:50:02 DEBUG : existing: Need to transfer - File not found at Destination
2024/12/07 03:50:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:50:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:50:04 DEBUG : existing: md5 = 0e013715a8f6a2b15d3d74f30fe136db OK
2024/12/07 03:50:04 INFO  : existing: Copied (new)
2024/12/07 03:50:04 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:50:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:50:05 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2024/12/07 03:50:05 ERROR : existing: Source and destination exist but do not match: immutable file modified
2024/12/07 03:50:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:50:05 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': not deleting files as there were IO errors
2024/12/07 03:50:05 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncImmutable (5.48s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:50:09 DEBUG : EXISTING: md5 = ae6a4a0cf651789fc2137e1860a871df OK
2024/12/07 03:50:10 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:50:10 DEBUG : existing: Unchanged skipping
2024/12/07 03:50:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:50:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:50:10 DEBUG : Waiting for deletions to finish
2024/12/07 03:50:10 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (3.61s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.50s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", 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-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", 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-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.48s)
    --- SKIP: TestMaxTransfer/Hard (0.50s)
    --- SKIP: TestMaxTransfer/Soft (0.52s)
    --- SKIP: TestMaxTransfer/Cautious (0.47s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:50:15 DEBUG : both0: md5 = 50bf3792352427371d5809eb67e787f6 OK
2024/12/07 03:50:16 DEBUG : only0: md5 = 14677707b12e5a0b0f18a435698a4bcb OK
2024/12/07 03:50:18 DEBUG : both1: md5 = 722036ee1d55a326536415aee0211741 OK
2024/12/07 03:50:20 DEBUG : only1: md5 = 363b0ca0e5c02611b9911c3f929430c9 OK
2024/12/07 03:50:22 DEBUG : both2: md5 = 01a3a869a2ff194d71eb1abcb901e2d2 OK
2024/12/07 03:50:23 DEBUG : only2: md5 = 59c69f177aa109c3a5e0eb45162cd7cd OK
2024/12/07 03:50:25 DEBUG : both3: md5 = 4568a9d03e8a94839c15512c970400c7 OK
2024/12/07 03:50:28 DEBUG : only3: md5 = e31055ab77c46d056e4fd8b6d61999f6 OK
2024/12/07 03:50:29 DEBUG : both4: md5 = c07b0b6ee8dee0196290f107ef68215d OK
2024/12/07 03:50:31 DEBUG : only4: md5 = 31f65c7b224523a9886f6769e61be6a7 OK
2024/12/07 03:50:33 DEBUG : both5: md5 = 418f977e206b8c3da81cf0b823498902 OK
2024/12/07 03:50:35 DEBUG : only5: md5 = 563098900467b14da43a9cc8868124b0 OK
2024/12/07 03:50:36 DEBUG : both6: md5 = b88f206b6b57144542dc0b8fc673e3f5 OK
2024/12/07 03:50:38 DEBUG : only6: md5 = 421a299d2b14ff866b473b0cf96fbc80 OK
2024/12/07 03:50:39 DEBUG : both7: md5 = b832345536f6d6102db2aef0b5f315d9 OK
2024/12/07 03:50:41 DEBUG : only7: md5 = 8ce92f6bf19bffe621db2db4d835fac1 OK
2024/12/07 03:50:43 DEBUG : both8: md5 = d81f36aa132f1c50b11fc9e591acb6fb OK
2024/12/07 03:50:45 DEBUG : only8: md5 = 6510a75995223f4fc1cbca6d64611dec OK
2024/12/07 03:50:46 DEBUG : both9: md5 = d0e1bac2976be8fdf021a706215b034c OK
2024/12/07 03:50:48 DEBUG : only9: md5 = e3b3807f8bae3e7acd944fc3000fb3f5 OK
2024/12/07 03:50:50 DEBUG : both10: md5 = be2cd602478fd11f2fb96331047c08d5 OK
2024/12/07 03:50:51 DEBUG : only10: md5 = 7ca199192f5a3f61253c7e3a9b2dfa73 OK
2024/12/07 03:50:53 DEBUG : both11: md5 = ae663f4262b2c4cf6cc91e434b8beef0 OK
2024/12/07 03:50:55 DEBUG : only11: md5 = 61ff76b682127ba1bc7c52fd486f258a OK
2024/12/07 03:50:56 DEBUG : both12: md5 = 8ead1b007c19ffc4c5624f36f9a57bd3 OK
2024/12/07 03:50:58 DEBUG : only12: md5 = 01d1fc1646cff71acb8541e0667c2bc4 OK
2024/12/07 03:51:00 DEBUG : both13: md5 = efd2ba9e41fa97695b0c2204c51c6d02 OK
2024/12/07 03:51:01 DEBUG : only13: md5 = 0bb4206bdfabfa2e46862972aaebd147 OK
2024/12/07 03:51:03 DEBUG : both14: md5 = 0494ac9b0c55e31ca0c216babf21b446 OK
2024/12/07 03:51:05 DEBUG : only14: md5 = 40dd9349728aac1853b42f891449e4f4 OK
2024/12/07 03:51:06 DEBUG : both15: md5 = 50c34496f8d08d2cb8aec48bbddcce68 OK
2024/12/07 03:51:08 DEBUG : only15: md5 = 09a2f5556972b607ebc1291a78cc59ef OK
2024/12/07 03:51:10 DEBUG : both16: md5 = 6eca8d45d327274c92f87178fdc48dcd OK
2024/12/07 03:51:12 DEBUG : only16: md5 = 477626390a42b5a93f5a70ac60fa6f49 OK
2024/12/07 03:51:13 DEBUG : both17: md5 = 412fa49ff3b15779c44b2298fb5adcb3 OK
2024/12/07 03:51:15 DEBUG : only17: md5 = a56c938003e6c39707fa8cd641261f84 OK
2024/12/07 03:51:16 DEBUG : both18: md5 = d14c7d0db37a75f361bd4a165a4234f2 OK
2024/12/07 03:51:18 DEBUG : only18: md5 = 2cfe729f6a48e05f9795235a27a322e9 OK
2024/12/07 03:51:20 DEBUG : both19: md5 = 21a0abe8d24cf34392eaf9aa08cf843f OK
2024/12/07 03:51:21 DEBUG : only19: md5 = 25b21e941da3c1c8d96b735bc9952456 OK
2024/12/07 03:51:22 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:51:22 DEBUG : both0: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both12: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both13: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both14: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both15: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both10: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both17: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both18: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both19: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both2: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both3: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both4: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both5: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both6: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both7: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both8: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:51:22 DEBUG : both9: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both1: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both11: Unchanged skipping
2024/12/07 03:51:22 DEBUG : both16: Unchanged skipping
2024/12/07 03:51:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:51:22 DEBUG : Waiting for deletions to finish
2024/12/07 03:51:22 INFO  : only1: Deleted
2024/12/07 03:51:22 INFO  : only5: Deleted
2024/12/07 03:51:22 INFO  : only17: Deleted
2024/12/07 03:51:22 INFO  : only14: Deleted
2024/12/07 03:51:23 INFO  : only16: Deleted
2024/12/07 03:51:23 INFO  : only0: Deleted
2024/12/07 03:51:23 INFO  : only12: Deleted
2024/12/07 03:51:23 INFO  : only7: Deleted
2024/12/07 03:51:24 INFO  : only18: Deleted
2024/12/07 03:51:24 INFO  : only4: Deleted
2024/12/07 03:51:24 INFO  : only19: Deleted
2024/12/07 03:51:24 INFO  : only6: Deleted
2024/12/07 03:51:24 INFO  : only8: Deleted
2024/12/07 03:51:24 INFO  : only15: Deleted
2024/12/07 03:51:24 INFO  : only11: Deleted
2024/12/07 03:51:24 INFO  : only2: Deleted
2024/12/07 03:51:25 INFO  : only9: Deleted
2024/12/07 03:51:25 INFO  : only3: Deleted
2024/12/07 03:51:25 INFO  : only10: Deleted
2024/12/07 03:51:25 INFO  : only13: Deleted
2024/12/07 03:51:25 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (85.22s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:51:40 DEBUG : both0: md5 = 3f86246008ece450cdd4439926cf62b2 OK
2024/12/07 03:51:41 DEBUG : only0: md5 = 2dcacaff8ca7054119d74eca2a2573ee OK
2024/12/07 03:51:44 DEBUG : both1: md5 = f2dcaf4010b2177b1bd96a6bfa5c8f9f OK
2024/12/07 03:51:45 DEBUG : only1: md5 = 8f8f4fc4e8a78fcc2e0085cac8ba8266 OK
2024/12/07 03:51:47 DEBUG : both2: md5 = ab31adf4da2a0acc5d84e7db63e1311b OK
2024/12/07 03:51:49 DEBUG : only2: md5 = 731d54ec4a6beb36654fdea911ba72ee OK
2024/12/07 03:51:50 DEBUG : both3: md5 = 85cf41c731ee12f899b14419ccd6b32c OK
2024/12/07 03:51:52 DEBUG : only3: md5 = 8a7e7c2e79e815df5531bde58cfe3908 OK
2024/12/07 03:51:54 DEBUG : both4: md5 = df553cc1a07140bce790281a79eed0cd OK
2024/12/07 03:51:56 DEBUG : only4: md5 = 8d993c6ed915feb88b3c0ff869e34c3b OK
2024/12/07 03:51:57 DEBUG : both5: md5 = b5a01ecffe4b561dae633027dbfd6c53 OK
2024/12/07 03:51:59 DEBUG : only5: md5 = 08a2e8dbe65609f156f6802e3c2a379b OK
2024/12/07 03:52:01 DEBUG : both6: md5 = 51511665bd71d3023c35ff981eb8d7c8 OK
2024/12/07 03:52:02 DEBUG : only6: md5 = da1731c2f19545e7e18f2e7b34d5b2c1 OK
2024/12/07 03:52:04 DEBUG : both7: md5 = 87ba69397f21924d5bb2e891cb67792b OK
2024/12/07 03:52:06 DEBUG : only7: md5 = 0cd6f09a2c925b820e96fe64a0fac35b OK
2024/12/07 03:52:08 DEBUG : both8: md5 = 9d57ea7e368eb91032c24e28a24772df OK
2024/12/07 03:52:10 DEBUG : only8: md5 = 9a03d132960992cc1aff86478f50b610 OK
2024/12/07 03:52:11 DEBUG : both9: md5 = 977a9e4acae7586530e7bcc82c51f001 OK
2024/12/07 03:52:13 DEBUG : only9: md5 = 528c7c835746beb3e59569bc8c6f30e5 OK
2024/12/07 03:52:15 DEBUG : both10: md5 = 8376bcadc4c9347dc7ab0b7172232080 OK
2024/12/07 03:52:16 DEBUG : only10: md5 = 9db510ee446004c514d60e82eef61d42 OK
2024/12/07 03:52:18 DEBUG : both11: md5 = ed8523551a2c2fd33d17d9bec09fefa7 OK
2024/12/07 03:52:19 DEBUG : only11: md5 = 4eb3f30225125bf487894e19b4e1e9d2 OK
2024/12/07 03:52:21 DEBUG : both12: md5 = 4fadd71bf5784b45664ef6159d125915 OK
2024/12/07 03:52:23 DEBUG : only12: md5 = 56c0f4fe1eab6aeb8dc9b17aea682a97 OK
2024/12/07 03:52:25 DEBUG : both13: md5 = 304bb8d43bf0d146f646866473f4f2ba OK
2024/12/07 03:52:26 DEBUG : only13: md5 = d3c1c3918318a240dabee51cf1a1b3b9 OK
2024/12/07 03:52:28 DEBUG : both14: md5 = d88c34f783255cf053330a58e26232c7 OK
2024/12/07 03:52:30 DEBUG : only14: md5 = 14e78c6c73260ad46719d4b0c3544103 OK
2024/12/07 03:52:31 DEBUG : both15: md5 = bbb89acb6bd93f74b6e0176add88583b OK
2024/12/07 03:52:33 DEBUG : only15: md5 = 6bfd6c4c1448be01dcc337e4652b1a32 OK
2024/12/07 03:52:35 DEBUG : both16: md5 = a540dc5273a6c24b2692b74562d58ef1 OK
2024/12/07 03:52:35 DEBUG : Config file has changed externally - reloading
2024/12/07 03:52:35 DEBUG : TestDrive: Loaded fresh token from config file
2024/12/07 03:52:36 DEBUG : only16: md5 = 5905575919636b956d903f2f648d8bac OK
2024/12/07 03:52:38 DEBUG : both17: md5 = 42fb84cbd711c6cd5fe9359d503fd020 OK
2024/12/07 03:52:40 DEBUG : only17: md5 = 8a48ca2508ec3e68c37f87b2ef9b49cb OK
2024/12/07 03:52:41 DEBUG : both18: md5 = 633019dc0c32a6b7020e8699ad250296 OK
2024/12/07 03:52:43 DEBUG : only18: md5 = 5aa1eb278c5c5e8074aebc3f284b4353 OK
2024/12/07 03:52:45 DEBUG : both19: md5 = d2cc2357ae551d11c6aa6e4ffbe937ae OK
2024/12/07 03:52:46 DEBUG : only19: md5 = ecb27c9af42271418845034bfa068bad OK
2024/12/07 03:52:47 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for checks to finish
2024/12/07 03:52:47 DEBUG : both10: Unchanged skipping
2024/12/07 03:52:47 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both12: Unchanged skipping
2024/12/07 03:52:47 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both13: Unchanged skipping
2024/12/07 03:52:47 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both14: Unchanged skipping
2024/12/07 03:52:47 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both15: Unchanged skipping
2024/12/07 03:52:47 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both16: Unchanged skipping
2024/12/07 03:52:47 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both17: Unchanged skipping
2024/12/07 03:52:47 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both18: Unchanged skipping
2024/12/07 03:52:47 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both19: Unchanged skipping
2024/12/07 03:52:47 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both2: Unchanged skipping
2024/12/07 03:52:47 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both3: Unchanged skipping
2024/12/07 03:52:47 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both4: Unchanged skipping
2024/12/07 03:52:47 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both5: Unchanged skipping
2024/12/07 03:52:47 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both6: Unchanged skipping
2024/12/07 03:52:47 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both7: Unchanged skipping
2024/12/07 03:52:47 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both8: Unchanged skipping
2024/12/07 03:52:47 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/07 03:52:47 DEBUG : both9: Unchanged skipping
2024/12/07 03:52:47 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2024/12/07 03:52:47 DEBUG : both0: Unchanged skipping
2024/12/07 03:52:47 DEBUG : both1: Unchanged skipping
2024/12/07 03:52:47 DEBUG : both11: Unchanged skipping
2024/12/07 03:52:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Waiting for transfers to finish
2024/12/07 03:52:48 DEBUG : only10: md5 = 6122a4e600e2fd4d778a164a50bc59b4 OK
2024/12/07 03:52:48 INFO  : only10: Copied (replaced existing)
2024/12/07 03:52:48 DEBUG : only1: md5 = ee8c71d1479ef38296cd036a59037261 OK
2024/12/07 03:52:48 INFO  : only1: Copied (replaced existing)
2024/12/07 03:52:48 DEBUG : only0: md5 = acdd91ea47b8ec68878aac87ec1fa341 OK
2024/12/07 03:52:48 INFO  : only0: Copied (replaced existing)
2024/12/07 03:52:48 DEBUG : only11: md5 = c9114043367e9f13c9dd65c3c6b4b0e5 OK
2024/12/07 03:52:48 INFO  : only11: Copied (replaced existing)
2024/12/07 03:52:50 DEBUG : only12: md5 = 7b7e277152bf27785c9d958f0ec3316f OK
2024/12/07 03:52:50 INFO  : only12: Copied (replaced existing)
2024/12/07 03:52:50 DEBUG : only13: md5 = d0fa9f0b20ddbcb4816bdb3807426001 OK
2024/12/07 03:52:50 INFO  : only13: Copied (replaced existing)
2024/12/07 03:52:50 DEBUG : only14: md5 = 007e2219f953c449750f6b57a804e879 OK
2024/12/07 03:52:50 INFO  : only14: Copied (replaced existing)
2024/12/07 03:52:50 DEBUG : only15: md5 = 59447ef20ba0a5c45967c340964e5a19 OK
2024/12/07 03:52:50 INFO  : only15: Copied (replaced existing)
2024/12/07 03:52:51 DEBUG : only16: md5 = d4d980e6a0531e269354f89b3b502de8 OK
2024/12/07 03:52:51 INFO  : only16: Copied (replaced existing)
2024/12/07 03:52:51 DEBUG : only18: md5 = 82707fecf1336be7fff6e1173e1fc54a OK
2024/12/07 03:52:51 INFO  : only18: Copied (replaced existing)
2024/12/07 03:52:51 DEBUG : only17: md5 = fc007bc55f3f7779dc2a7ba863e384a4 OK
2024/12/07 03:52:51 INFO  : only17: Copied (replaced existing)
2024/12/07 03:52:51 DEBUG : only19: md5 = 73e8ae1e25bdbbb5b37a39d0e2764a78 OK
2024/12/07 03:52:51 INFO  : only19: Copied (replaced existing)
2024/12/07 03:52:52 DEBUG : only3: md5 = 2cdacb672230e45b7258211cd47964c1 OK
2024/12/07 03:52:52 INFO  : only3: Copied (replaced existing)
2024/12/07 03:52:52 DEBUG : only2: md5 = 41f42f4d3d4c018d6cc87ce895a61f59 OK
2024/12/07 03:52:52 INFO  : only2: Copied (replaced existing)
2024/12/07 03:52:52 DEBUG : only4: md5 = 91be1db1cb16a547e48414cb41650c36 OK
2024/12/07 03:52:52 INFO  : only4: Copied (replaced existing)
2024/12/07 03:52:52 DEBUG : only5: md5 = 16f2711bd7f88753922209c5d06f79ab OK
2024/12/07 03:52:52 INFO  : only5: Copied (replaced existing)
2024/12/07 03:52:53 DEBUG : only6: md5 = 5927ef8813ac2bb3c6ae4ad3d9d0ca16 OK
2024/12/07 03:52:53 INFO  : only6: Copied (replaced existing)
2024/12/07 03:52:54 DEBUG : only7: md5 = e34e458ef813ba0045bfe28685f08a71 OK
2024/12/07 03:52:54 INFO  : only7: Copied (replaced existing)
2024/12/07 03:52:54 DEBUG : only8: md5 = 3a3043e91c248b99783cc5e0aff414ea OK
2024/12/07 03:52:54 INFO  : only8: Copied (replaced existing)
2024/12/07 03:52:54 DEBUG : only9: md5 = b4545c5167062482f3b12a082ddc6e8c OK
2024/12/07 03:52:54 INFO  : only9: Copied (replaced existing)
2024/12/07 03:52:54 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (100.34s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:53:18 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/07 03:53:18 DEBUG : sub dir: Making directory with metadata
2024/12/07 03:53:19 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:53:40 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/12/07 03:53:41 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/12/07 03:53:41 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/07 03:53:41 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:53:57 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2024/12/07 03:53:58 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/12/07 03:53:59 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/12/07 03:54:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/12/07 03:54:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/07 03:54:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/07 03:54:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/07 03:54:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/07 03:54:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/12/07 03:54:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/12/07 03:54:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/07 03:54:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (49.95s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:54:08 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/07 03:54:08 DEBUG : sub dir: Making directory with metadata
2024/12/07 03:54:09 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:54:35 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/12/07 03:54:36 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/12/07 03:54:36 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/07 03:54:36 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha'", Local "Local file system at /tmp/rclone2861789748", Modify Window "1ms"
2024/12/07 03:54:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/12/07 03:54:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/12/07 03:54:52 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/12/07 03:54:52 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/07 03:54:53 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/07 03:54:54 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/07 03:54:55 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/07 03:54:56 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/12/07 03:54:57 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/12/07 03:54:57 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/07 03:54:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (51.56s)
PASS
2024/12/07 03:55:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tadisoz1giha': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 18m20.146885562s (try 1/5)