"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5)
2024/11/28 03:46:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho"
2024/11/28 03:46:45 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/11/28 03:46:45 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50"
2024/11/28 03:46:46 DEBUG : Creating backend with remote "/tmp/rclone317814031"
=== 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-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:46:47 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 03:46:47 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 03:46:47 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2024/11/28 03:46:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:46:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:46:47 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.40s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:46:48 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 03:46:48 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 03:46:48 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 03:46:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:46:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:46:51 DEBUG : sub dir/hello world: md5 = 52cf47589ca678a4edbd42e713b4cb7d OK
2024/11/28 03:46:51 INFO  : sub dir/hello world: Copied (new)
2024/11/28 03:46:52 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:46:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (7.25s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:46:55 DEBUG : metadata sub dir: Making directory with metadata
2024/11/28 03:46:55 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 03:46:55 DEBUG : empty metadata sub dir: Making directory with metadata
2024/11/28 03:46:55 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 03:46:55 DEBUG : Local file system at /tmp/rclone317814031: File to upload is small (21 bytes), uploading instead of streaming
2024/11/28 03:46:55 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/11/28 03:46:55 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/11/28 03:46:55 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 03:46:56 DEBUG : Google drive root 'crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50': Skipping btime metadata as can't update it on an existing file: 2024-11-28T03:46:55.985056625Z
2024/11/28 03:46:57 INFO  : empty metadata sub dir: Updated directory metadata
2024/11/28 03:46:57 DEBUG : Google drive root 'crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50': Skipping btime metadata as can't update it on an existing file: 2024-11-28T03:46:55.985056625Z
2024/11/28 03:46:58 INFO  : metadata sub dir: Updated directory metadata
2024/11/28 03:46:58 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/11/28 03:46:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:46:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:47:00 DEBUG : metadata sub dir/hello metadata world: md5 = bbe09a2b4879926fc1583634df8812e7 OK
2024/11/28 03:47:00 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:47:03 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (9.29s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:47:05 DEBUG : metadata sub dir: Making directory with metadata
2024/11/28 03:47:05 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 03:47:05 DEBUG : empty metadata sub dir: Making directory with metadata
2024/11/28 03:47:05 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 03:47:05 DEBUG : Local file system at /tmp/rclone317814031: File to upload is small (21 bytes), uploading instead of streaming
2024/11/28 03:47:05 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/11/28 03:47:05 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/11/28 03:47:05 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 03:47:05 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2024/11/28 03:47:05 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2024/11/28 03:47:05 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/11/28 03:47:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:47:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:47:08 DEBUG : metadata sub dir/hello metadata world: md5 = a786329f59b05900939f0c3ae0a86620 OK
2024/11/28 03:47:08 INFO  : metadata sub dir/hello metadata world: Copied (new)
2024/11/28 03:47:08 DEBUG : Google drive root 'crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50': Skipping btime metadata as can't update it on an existing file: 2024-11-28T03:47:05.273007787Z
2024/11/28 03:47:08 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:47:11 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (7.87s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:47:13 DEBUG : Creating backend with remote "/non-existing"
2024/11/28 03:47:13 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2024/11/28 03:47:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:47:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.15s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:47:14 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 03:47:14 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 03:47:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:47:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:47:17 DEBUG : sub dir/hello world: md5 = 619ed09ef8fec36329238f1a88d8ebb0 OK
2024/11/28 03:47:17 INFO  : sub dir/hello world: Copied (new)
2024/11/28 03:47:18 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:47:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (6.95s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:47:21 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Running all checks before starting transfers
2024/11/28 03:47:21 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 03:47:21 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 03:47:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:47:21 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Checks finished, now starting transfers
2024/11/28 03:47:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:47:24 DEBUG : sub dir/hello world: md5 = 3901ff7bfb7bf5d26a08dbeed0469148 OK
2024/11/28 03:47:24 INFO  : sub dir/hello world: Copied (new)
2024/11/28 03:47:24 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:47:26 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (6.66s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:47:27 ERROR : Ignoring --no-traverse with sync
2024/11/28 03:47:28 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 03:47:28 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 03:47:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:47:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:47:30 DEBUG : sub dir/hello world: md5 = 1a4cd96cd9bd4637aff69ddd8f5ab53c OK
2024/11/28 03:47:30 INFO  : sub dir/hello world: Copied (new)
2024/11/28 03:47:30 DEBUG : Waiting for deletions to finish
2024/11/28 03:47:31 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:47:33 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (6.55s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:47:34 DEBUG : hello world2: Need to transfer - File not found at Destination
2024/11/28 03:47:34 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 03:47:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:47:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:47:36 DEBUG : hello world2: md5 = 48e443ae7565183bbc461f2814e1485a OK
2024/11/28 03:47:36 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestCopyWithDepth (3.83s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:47:38 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 03:47:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:47:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:47:40 DEBUG : potato2: md5 = 2de5f17cf6bac3534e1d2364113889c1 OK
2024/11/28 03:47:40 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.59s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:47:42 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 03:47:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:47:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:47:43 DEBUG : potato2: md5 = 878d7c1220e00a87961316608ec8b3fe OK
2024/11/28 03:47:43 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.77s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:47:45 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/28 03:47:45 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 03:47:45 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/28 03:47:45 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 03:47:45 DEBUG : sub dir: Making directory with metadata
2024/11/28 03:47:47 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/28 03:47:47 DEBUG : sub dir2: Making directory with metadata
2024/11/28 03:47:48 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 03:47:48 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/28 03:47:48 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 03:47:49 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 03:47:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:47:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:47:49 DEBUG : sub dir/hello world: md5 = a1f1336403f594d045fdaff875cde256 OK
2024/11/28 03:47:49 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:47:53 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2024/11/28 03:47:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (10.36s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:47:56 DEBUG : sub dir2: Making directory
2024/11/28 03:47:56 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/28 03:47:56 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 03:47:56 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 03:47:56 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/28 03:47:56 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2024/11/28 03:47:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 03:47:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:47:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:47:58 DEBUG : sub dir/hello world: md5 = 03365503c59d89318ef4ff16fdc82ff3 OK
2024/11/28 03:47:58 INFO  : sub dir/hello world: Copied (new)
2024/11/28 03:47:59 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 03:48:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (6.31s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:48:02 DEBUG : sub dir2: Making directory with metadata
2024/11/28 03:48:02 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 03:48:02 DEBUG : sub dir: Making directory with metadata
2024/11/28 03:48:03 INFO  : sub dir: Made directory with metadata (mtime=2024-11-28T03:48:02.308704666Z)
2024/11/28 03:48:03 DEBUG : sub dir2: Making directory with metadata
2024/11/28 03:48:04 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 03:48:04 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 03:48:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:48:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:48:06 DEBUG : sub dir/hello world: md5 = c5bf13d371d96f848223b12a2a5f31ae OK
2024/11/28 03:48:06 INFO  : sub dir/hello world: Copied (new)
2024/11/28 03:48:06 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:48:09 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (8.82s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:48:11 DEBUG : sub dir no update dir modtime: Making directory with metadata
2024/11/28 03:48:11 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/28 03:48:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:48:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:48:12 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (4.56s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:48:15 DEBUG : sub dir2: Making directory
2024/11/28 03:48:15 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 03:48:15 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/28 03:48:15 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 03:48:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:48:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:48:18 DEBUG : sub dir/hello world: md5 = 897f185dabc248a255a7f96ce3689f0d OK
2024/11/28 03:48:18 INFO  : sub dir/hello world: Copied (new)
2024/11/28 03:48:18 INFO  : sub dir/hello world: Deleted
2024/11/28 03:48:19 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 03:48:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (6.20s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:48:21 DEBUG : sub dir2: Making directory with metadata
2024/11/28 03:48:21 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 03:48:21 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 03:48:22 DEBUG : sub dir: Making directory with metadata
2024/11/28 03:48:23 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/28 03:48:23 DEBUG : sub dir2: Making directory with metadata
2024/11/28 03:48:24 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 03:48:24 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 03:48:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:48:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:48:25 DEBUG : sub dir/hello world: md5 = 39194a4a576ede4f364f5fb64be32531 OK
2024/11/28 03:48:25 INFO  : sub dir/hello world: Copied (new)
2024/11/28 03:48:25 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:48:29 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (8.44s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.48s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:48:30 DEBUG : sub dir2: Making directory
2024/11/28 03:48:31 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 03:48:31 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/28 03:48:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 03:48:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:48:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:48:33 DEBUG : sub dir/hello world: md5 = ee66cefa8ad177eb314b279e46fd293e OK
2024/11/28 03:48:33 INFO  : sub dir/hello world: Copied (new)
2024/11/28 03:48:33 DEBUG : Waiting for deletions to finish
2024/11/28 03:48:34 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 03:48:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (6.14s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:48:39 DEBUG : sub dir/hello world: md5 = a10b99a1f2d0437c3941b62df5a4a29c OK
2024/11/28 03:48:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vequsow2zuxo"
2024/11/28 03:48:40 DEBUG : Creating backend with remote "TestDrive:crypt/m4u0gd8e7tckdbtdqvloa4uuo31o9rg9u8j9d6f9bql7n5onr220"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho' -> Encrypted drive 'TestCryptDrive:rclone-test-vequsow2zuxo'
2024/11/28 03:48:41 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 03:48:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 03:48:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vequsow2zuxo': Waiting for checks to finish
2024/11/28 03:48:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vequsow2zuxo': Waiting for transfers to finish
2024/11/28 03:48:45 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/28 03:48:45 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:48:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vequsow2zuxo': Purge remote
2024/11/28 03:48:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (12.48s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:48:51 DEBUG : sub dir/hello world: md5 = 5bd91cb990082ac62772ce4ebeb7c42b OK
2024/11/28 03:48:52 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/28 03:48:52 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/28 03:48:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:48:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:48:54 DEBUG : sub dir/hello world: md5 = 47d11f38eef5d3708694d95edcf4068d OK
2024/11/28 03:48:54 INFO  : sub dir/hello world: Copied (replaced existing)
2024/11/28 03:48:55 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:48:56 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (8.74s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:49:00 DEBUG : sub dir/hello world: md5 = cd7f3bc35270b94ac4a0e15bf5838b04 OK
2024/11/28 03:49:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zahicen6fabo"
2024/11/28 03:49:01 DEBUG : Creating backend with remote "TestDrive:crypt/q0gmffmjd0lvr1hoavv1th2bifdqcrgrmkms7areij2mdfpijgm0"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho' -> Encrypted drive 'TestCryptDrive:rclone-test-zahicen6fabo'
2024/11/28 03:49:03 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 03:49:03 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 03:49:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zahicen6fabo': Waiting for checks to finish
2024/11/28 03:49:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zahicen6fabo': Waiting for transfers to finish
2024/11/28 03:49:06 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/28 03:49:07 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:49:09 DEBUG : sub dir/hello world: md5 = 66fbab0925f5cd064a82e1c3aefded85 OK
2024/11/28 03:49:10 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/28 03:49:10 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/28 03:49:10 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/28 03:49:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zahicen6fabo': Waiting for checks to finish
2024/11/28 03:49:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zahicen6fabo': Waiting for transfers to finish
2024/11/28 03:49:12 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/28 03:49:12 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:49:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zahicen6fabo': Purge remote
2024/11/28 03:49:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (18.77s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:49:19 DEBUG : sub dir/hello world: md5 = b792e6fc6957de3a70d34bf95faf7779 OK
2024/11/28 03:49:20 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/28 03:49:20 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/28 03:49:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:49:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:49:22 DEBUG : sub dir/hello world: md5 = f0c0b5073d2eae27fa84d4155406dc07 OK
2024/11/28 03:49:22 INFO  : sub dir/hello world: Copied (replaced existing)
2024/11/28 03:49:22 INFO  : sub dir/hello world: Deleted
2024/11/28 03:49:22 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:49:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (9.33s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:49:29 DEBUG : sub dir/hello world: md5 = 350ea4026d6da480006d884e96ce499d OK
2024/11/28 03:49:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-resafez0heci"
2024/11/28 03:49:29 DEBUG : Creating backend with remote "TestDrive:crypt/61ntd8ikell2ldln2lpq33nmmel94l9srt2i8rurol6bspmv6gpg"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho' -> Encrypted drive 'TestCryptDrive:rclone-test-resafez0heci'
2024/11/28 03:49:30 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 03:49:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 03:49:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-resafez0heci': Waiting for checks to finish
2024/11/28 03:49:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-resafez0heci': Waiting for transfers to finish
2024/11/28 03:49:34 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/28 03:49:34 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:49:37 DEBUG : sub dir/hello world: md5 = bbc34cf83b9eb2f71193e77aca3eb7ef OK
2024/11/28 03:49:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-resafez0heci': Using server-side directory move
2024/11/28 03:49:37 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-resafez0heci': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/28 03:49:37 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/28 03:49:37 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/28 03:49:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-resafez0heci': Waiting for checks to finish
2024/11/28 03:49:38 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/28 03:49:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-resafez0heci': Waiting for transfers to finish
2024/11/28 03:49:38 INFO  : sub dir/hello world: Deleted
2024/11/28 03:49:39 INFO  : sub dir/hello world: Moved (server-side)
2024/11/28 03:49:40 INFO  : sub dir: Set directory modification time (using SetModTime)
2024/11/28 03:49:42 DEBUG : sub dir/hello world: md5 = 8df8b54da604529e7f848e4c741978b6 OK
2024/11/28 03:49:43 DEBUG : testing file moves
2024/11/28 03:49:43 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/28 03:49:43 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/28 03:49:43 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2024/11/28 03:49:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-resafez0heci': Waiting for checks to finish
2024/11/28 03:49:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-resafez0heci': Waiting for transfers to finish
2024/11/28 03:49:44 INFO  : sub dir/hello world: Deleted
2024/11/28 03:49:45 INFO  : sub dir/hello world: Moved (server-side)
2024/11/28 03:49:45 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:49:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-resafez0heci': Purge remote
--- PASS: TestServerSideMoveOverSelf (23.62s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:49:52 DEBUG : sub dir/hello world: md5 = b4d20c4c2731cc382b827d66a5bdbcd9 OK
2024/11/28 03:49:52 ERROR : : error listing: directory not found
2024/11/28 03:49:53 DEBUG : Local file system at /tmp/rclone317814031: Making directory
2024/11/28 03:49:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:49:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:49:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (6.93s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:49:59 DEBUG : sub dir/hello world: md5 = 585a3ce0ae933fd85b2ad6f1d321e10a OK
2024/11/28 03:50:00 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 03:50:00 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 03:50:00 DEBUG : Local file system at /tmp/rclone317814031: Waiting for checks to finish
2024/11/28 03:50:00 DEBUG : Local file system at /tmp/rclone317814031: Waiting for transfers to finish
2024/11/28 03:50:01 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2024/11/28 03:50:01 INFO  : sub dir/hello world: Copied (new)
2024/11/28 03:50:01 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:50:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (7.64s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:50:04 DEBUG : check sum: Need to transfer - File not found at Destination
2024/11/28 03:50:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:50:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:50:06 DEBUG : check sum: md5 = 83360d9f66b6702bf89c66fdcfed40a9 OK
2024/11/28 03:50:06 INFO  : check sum: Copied (new)
2024/11/28 03:50:06 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:50:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:50:07 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2024/11/28 03:50:07 DEBUG : check sum: Size of src and dst objects identical
2024/11/28 03:50:07 DEBUG : check sum: Unchanged skipping
2024/11/28 03:50:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:50:07 DEBUG : Waiting for deletions to finish
2024/11/28 03:50:07 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (5.02s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:50:09 DEBUG : sizeonly: Need to transfer - File not found at Destination
2024/11/28 03:50:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:50:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:50:11 DEBUG : sizeonly: md5 = 2b130a79b720ca09079989e2fafe3573 OK
2024/11/28 03:50:11 INFO  : sizeonly: Copied (new)
2024/11/28 03:50:11 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:50:11 DEBUG : sizeonly: Sizes identical
2024/11/28 03:50:11 DEBUG : sizeonly: Unchanged skipping
2024/11/28 03:50:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:50:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:50:11 DEBUG : Waiting for deletions to finish
2024/11/28 03:50:11 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (4.87s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:50:14 DEBUG : ignore-size: Need to transfer - File not found at Destination
2024/11/28 03:50:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:50:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:50:16 DEBUG : ignore-size: md5 = 2e838fba0ff179f5a065a94f3a9de908 OK
2024/11/28 03:50:16 INFO  : ignore-size: Copied (new)
2024/11/28 03:50:16 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:50:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:50:16 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:50:16 DEBUG : ignore-size: Unchanged skipping
2024/11/28 03:50:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:50:16 DEBUG : Waiting for deletions to finish
2024/11/28 03:50:16 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (4.69s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:50:20 DEBUG : existing: md5 = c58d9321ade6283b3098c936293c0b53 OK
2024/11/28 03:50:21 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:50:21 DEBUG : existing: Unchanged skipping
2024/11/28 03:50:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:50:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:50:21 DEBUG : Waiting for deletions to finish
2024/11/28 03:50:21 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:50:21 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2024/11/28 03:50:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:50:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:50:22 DEBUG : existing: md5 = 25aed739ec0c64fe36b6ed85ff45e3f4 OK
2024/11/28 03:50:22 INFO  : existing: Copied (replaced existing)
2024/11/28 03:50:22 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (6.15s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:50:25 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/28 03:50:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:50:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:50:27 DEBUG : existing: md5 = b1d0a3765c097532d85b0bde2e6bc408 OK
2024/11/28 03:50:27 INFO  : existing: Copied (new)
2024/11/28 03:50:27 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:50:27 DEBUG : existing: Destination exists, skipping
2024/11/28 03:50:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:50:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:50:27 DEBUG : Waiting for deletions to finish
2024/11/28 03:50:27 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (4.71s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:50:32 DEBUG : b/potato: md5 = faac69c85358194e93e93413213d2f18 OK
2024/11/28 03:50:35 DEBUG : c/non empty space: md5 = 438ebb3b959c1ad4d89028a7039a1643 OK
2024/11/28 03:50:35 DEBUG : d: Making directory
2024/11/28 03:50:37 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/28 03:50:37 DEBUG : Added delayed dir = "c", newDst=c
2024/11/28 03:50:37 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/28 03:50:37 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:50:37 DEBUG : c/non empty space: Unchanged skipping
2024/11/28 03:50:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:50:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:50:40 DEBUG : a/potato2: md5 = e01426c52858bda7fbd8ef7128ba984d OK
2024/11/28 03:50:40 INFO  : a/potato2: Copied (new)
2024/11/28 03:50:40 DEBUG : Waiting for deletions to finish
2024/11/28 03:50:40 INFO  : b/potato: Deleted
2024/11/28 03:50:41 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/28 03:50:41 INFO  : d: Removing directory
2024/11/28 03:50:42 INFO  : b: Removing directory
2024/11/28 03:50:42 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/28 03:50:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:50:45 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/28 03:50:46 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (17.63s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:50:49 DEBUG : empty space: md5 = ba523662d25e1b44a4c8d35d999eabae OK
2024/11/28 03:50:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:50:49 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2024/11/28 03:50:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:50:49 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2024/11/28 03:50:49 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:50:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:50:50 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2024/11/28 03:50:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:50:51 DEBUG : empty space: md5 = b86a6fe919bfca18da9e53a91f9e761f OK
2024/11/28 03:50:51 INFO  : empty space: Copied (replaced existing)
2024/11/28 03:50:51 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (6.47s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.47s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:50:55 DEBUG : foo: md5 = 3350fb7389841db241e5701ffa58fdad OK
2024/11/28 03:50:56 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2024/11/28 03:50:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:50:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:50:57 DEBUG : foo: md5 = 83d95b190136184832de15fae1065b70 OK
2024/11/28 03:50:57 INFO  : foo: Copied (replaced existing)
2024/11/28 03:50:57 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (5.27s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:51:01 DEBUG : empty space: md5 = 138d2af5025f421311f01975f82f1de1 OK
2024/11/28 03:51:01 DEBUG : potato: Need to transfer - File not found at Destination
2024/11/28 03:51:01 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:51:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:51:01 DEBUG : empty space: Unchanged skipping
2024/11/28 03:51:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:51:03 DEBUG : potato: md5 = ad5c2278870b61feaf35202a0a713b38 OK
2024/11/28 03:51:03 INFO  : potato: Copied (new)
2024/11/28 03:51:03 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (6.09s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:51:07 DEBUG : potato: md5 = 5b2d443d448e05715b2afb1a1fa9de73 OK
2024/11/28 03:51:07 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2024/11/28 03:51:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:51:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:51:09 DEBUG : potato: md5 = 45a3e95e580404fbb1031d5279e9debe OK
2024/11/28 03:51:09 INFO  : potato: Copied (replaced existing)
2024/11/28 03:51:09 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (5.28s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:51:12 DEBUG : potato: md5 = 6721631ab6436661ae02d3623d21ef2a OK
2024/11/28 03:51:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:51:13 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC
2024/11/28 03:51:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:51:14 DEBUG : potato: md5 = 87130a0e2cfa39f0f1092a7c996643e0 OK
2024/11/28 03:51:14 INFO  : potato: Copied (replaced existing)
2024/11/28 03:51:14 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (5.81s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:51:18 DEBUG : potato: md5 = 59fadff5dbbf8b910c2b1a2f5f5304f9 OK
2024/11/28 03:51:20 DEBUG : empty space: md5 = 8b55721632df4317c9296323e8b3ed7b OK
2024/11/28 03:51:20 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 03:51:20 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2024/11/28 03:51:20 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:51:20 DEBUG : empty space: Unchanged skipping
2024/11/28 03:51:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:51:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:51:20 DEBUG : Waiting for deletions to finish
2024/11/28 03:51:20 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.74s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:51:24 DEBUG : potato: md5 = d671ef1b42886f267f68b34f441aec8b OK
2024/11/28 03:51:26 DEBUG : empty space: md5 = 0c4b0ac21af2a1a1972c7775e224160a OK
2024/11/28 03:51:26 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 03:51:26 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:51:26 DEBUG : empty space: Unchanged skipping
2024/11/28 03:51:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:51:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:51:28 DEBUG : potato2: md5 = ccf999e0dd28e6119cf384939d4b2365 OK
2024/11/28 03:51:28 INFO  : potato2: Copied (new)
2024/11/28 03:51:28 DEBUG : Waiting for deletions to finish
2024/11/28 03:51:29 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.97s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:51:34 DEBUG : b/potato: md5 = 85ffd27a4e5c4b7e8209b4c5d7a9347c OK
2024/11/28 03:51:37 DEBUG : c/non empty space: md5 = 268355879fe8b8636a740bb143548b10 OK
2024/11/28 03:51:37 DEBUG : d: Making directory
2024/11/28 03:51:38 DEBUG : d/e: Making directory
2024/11/28 03:51:40 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/28 03:51:40 DEBUG : Added delayed dir = "c", newDst=c
2024/11/28 03:51:40 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/28 03:51:40 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:51:40 DEBUG : c/non empty space: Unchanged skipping
2024/11/28 03:51:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:51:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:51:42 DEBUG : a/potato2: md5 = f835c4ad47931438b8d464ac53272787 OK
2024/11/28 03:51:42 INFO  : a/potato2: Copied (new)
2024/11/28 03:51:42 DEBUG : Waiting for deletions to finish
2024/11/28 03:51:43 INFO  : b/potato: Deleted
2024/11/28 03:51:44 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/28 03:51:44 INFO  : d/e: Removing directory
2024/11/28 03:51:45 INFO  : d: Removing directory
2024/11/28 03:51:45 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2024/11/28 03:51:45 INFO  : b: Removing directory
2024/11/28 03:51:46 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/28 03:51:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:51:49 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/28 03:51:50 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (19.97s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:51:54 DEBUG : b/potato: md5 = fdf0951786bb80507b56459303dc1c01 OK
2024/11/28 03:51:57 DEBUG : c/non empty space: md5 = f7105e035d79e420dc5a03d585a1216b OK
2024/11/28 03:51:57 DEBUG : d: Making directory
2024/11/28 03:51:59 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/28 03:51:59 DEBUG : Added delayed dir = "c", newDst=c
2024/11/28 03:51:59 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/28 03:51:59 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:51:59 DEBUG : c/non empty space: Unchanged skipping
2024/11/28 03:51:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:51:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:52:02 DEBUG : a/potato2: md5 = 7a0d4fbbebc5a0c880bbbcf7829196d4 OK
2024/11/28 03:52:02 INFO  : a/potato2: Copied (new)
2024/11/28 03:52:02 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': not deleting files as there were IO errors
2024/11/28 03:52:02 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/28 03:52:02 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:52:06 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/28 03:52:07 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/28 03:52:08 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (18.27s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:52:11 DEBUG : potato: md5 = 60a5725ad90418c8fa1e256d380e09b4 OK
2024/11/28 03:52:13 DEBUG : empty space: md5 = 2071cdaf45d60a2438d0b90943bcfc19 OK
2024/11/28 03:52:13 DEBUG : Waiting for deletions to finish
2024/11/28 03:52:13 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 03:52:13 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:52:13 DEBUG : empty space: Unchanged skipping
2024/11/28 03:52:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:52:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:52:14 INFO  : potato: Deleted
2024/11/28 03:52:15 DEBUG : potato2: md5 = ba2e8b8dbcfd01f23afef09040292692 OK
2024/11/28 03:52:15 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (8.06s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:52:19 DEBUG : potato: md5 = 21dbe5a8e563dcd5eb704746f0385497 OK
2024/11/28 03:52:21 DEBUG : empty space: md5 = 61139f497665a9b8a5a0364f0763947f OK
2024/11/28 03:52:21 DEBUG : Waiting for deletions to finish
2024/11/28 03:52:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:52:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:52:22 INFO  : potato: Deleted
2024/11/28 03:52:22 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 03:52:22 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:52:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:52:22 DEBUG : empty space: Unchanged skipping
2024/11/28 03:52:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:52:24 DEBUG : potato2: md5 = d56181fba4f9eb3262dfc53bd8770e58 OK
2024/11/28 03:52:24 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (10.11s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:52:29 DEBUG : potato: md5 = c55037c5876750e931a6b73b48930eb0 OK
2024/11/28 03:52:30 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 03:52:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:52:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:52:31 DEBUG : potato2: md5 = 5f6ee369d99441ecf62ae9eeca91b532 OK
2024/11/28 03:52:31 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (6.04s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:52:35 DEBUG : potato2: md5 = 158baf946ece7968a3e22e92ec7b2bb5 OK
2024/11/28 03:52:37 DEBUG : empty space: md5 = 6ca44201aefacc6802a630101992e5db OK
2024/11/28 03:52:37 DEBUG : enormous: Excluded (Size Filter)
2024/11/28 03:52:37 DEBUG : enormous: Excluded
2024/11/28 03:52:37 DEBUG : potato2: Excluded (Size Filter)
2024/11/28 03:52:37 DEBUG : potato2: Excluded
2024/11/28 03:52:38 DEBUG : potato2: Excluded (Size Filter)
2024/11/28 03:52:38 DEBUG : potato2: Excluded
2024/11/28 03:52:38 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:52:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:52:38 DEBUG : empty space: Unchanged skipping
2024/11/28 03:52:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:52:38 DEBUG : Waiting for deletions to finish
2024/11/28 03:52:38 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:52:38 DEBUG : enormous: Excluded (Size Filter)
2024/11/28 03:52:38 DEBUG : enormous: Excluded
2024/11/28 03:52:38 DEBUG : potato2: Excluded (Size Filter)
2024/11/28 03:52:38 DEBUG : potato2: Excluded
2024/11/28 03:52:38 DEBUG : potato2: Excluded (Size Filter)
2024/11/28 03:52:38 DEBUG : potato2: Excluded
2024/11/28 03:52:38 DEBUG : Local file system at /tmp/rclone317814031: Waiting for checks to finish
2024/11/28 03:52:38 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/11/28 03:52:38 DEBUG : empty space: Unchanged skipping
2024/11/28 03:52:38 DEBUG : Local file system at /tmp/rclone317814031: Waiting for transfers to finish
2024/11/28 03:52:38 DEBUG : Waiting for deletions to finish
2024/11/28 03:52:38 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncWithExclude (7.22s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:52:43 DEBUG : potato2: md5 = 73e35d86372908198e1b2502ea342f28 OK
2024/11/28 03:52:44 DEBUG : empty space: md5 = c96b8c774266ef0daa71b9ee2f4f6589 OK
2024/11/28 03:52:46 DEBUG : enormous: md5 = 53b3ec58de074be3ad98de4ddc60c294 OK
2024/11/28 03:52:46 DEBUG : enormous: Excluded (Size Filter)
2024/11/28 03:52:46 DEBUG : enormous: Excluded
2024/11/28 03:52:46 DEBUG : potato2: Excluded (Size Filter)
2024/11/28 03:52:46 DEBUG : potato2: Excluded
2024/11/28 03:52:47 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:52:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:52:47 DEBUG : empty space: Unchanged skipping
2024/11/28 03:52:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:52:47 DEBUG : Waiting for deletions to finish
2024/11/28 03:52:47 INFO  : potato2: Deleted
2024/11/28 03:52:47 INFO  : enormous: Deleted
2024/11/28 03:52:47 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:52:48 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/11/28 03:52:48 DEBUG : empty space: Unchanged skipping
2024/11/28 03:52:48 DEBUG : Local file system at /tmp/rclone317814031: Waiting for checks to finish
2024/11/28 03:52:48 DEBUG : Local file system at /tmp/rclone317814031: Waiting for transfers to finish
2024/11/28 03:52:48 DEBUG : Waiting for deletions to finish
2024/11/28 03:52:48 INFO  : potato2: Deleted
2024/11/28 03:52:48 INFO  : enormous: Deleted
2024/11/28 03:52:48 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (8.97s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:52:51 DEBUG : one: md5 = cf6e73f7078c3b9733a61dec3f3dbca6 OK
2024/11/28 03:52:53 DEBUG : two: md5 = a5ddae06efad024e5e63f3c618167466 OK
2024/11/28 03:52:55 DEBUG : three: md5 = a649f359f60aaf99a5604c44e3c987e9 OK
2024/11/28 03:52:57 DEBUG : four: md5 = 1e0320ddc80a71c71f2424b02b3713ca OK
2024/11/28 03:52:57 DEBUG : five: Need to transfer - File not found at Destination
2024/11/28 03:52:57 DEBUG : four: Sizes differ (src 4 vs dst 8)
2024/11/28 03:52:57 DEBUG : one: Destination is newer than source, skipping
2024/11/28 03:52:57 DEBUG : three: Sizes identical
2024/11/28 03:52:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:52:57 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2024/11/28 03:52:57 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2024/11/28 03:52:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:52:58 DEBUG : four: md5 = 65c4ef6fabd30d7af406b1e447421fa7 OK
2024/11/28 03:52:58 INFO  : four: Copied (replaced existing)
2024/11/28 03:52:58 DEBUG : two: md5 = 3eef591ca1f3fd4a0fee01313c998337 OK
2024/11/28 03:52:58 INFO  : two: Copied (replaced existing)
2024/11/28 03:52:59 DEBUG : five: md5 = 402b77792568ce5af4de62cdc3c65b0d OK
2024/11/28 03:52:59 INFO  : five: Copied (new)
2024/11/28 03:52:59 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (12.56s)
=== 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-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2024/11/28 03:53:02 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Ignoring --track-renames as the source and destination do not have a common hash
2024/11/28 03:53:03 DEBUG : potato: Need to transfer - File not found at Destination
2024/11/28 03:53:03 DEBUG : yam: Need to transfer - File not found at Destination
2024/11/28 03:53:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:53:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:53:04 DEBUG : yam: md5 = b20f26e7e12b2ae5c8ffe5f6d652acce OK
2024/11/28 03:53:04 INFO  : yam: Copied (new)
2024/11/28 03:53:04 DEBUG : potato: md5 = b3213d4e6fd89292c85a988e387eca57 OK
2024/11/28 03:53:04 INFO  : potato: Copied (new)
2024/11/28 03:53:04 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:53:04 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Ignoring --track-renames as the source and destination do not have a common hash
2024/11/28 03:53:05 DEBUG : yaml: Need to transfer - File not found at Destination
2024/11/28 03:53:05 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:53:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:53:05 DEBUG : potato: Unchanged skipping
2024/11/28 03:53:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:53:06 DEBUG : yaml: md5 = 403aee688f0f99b81bcc542e543e1b0d OK
2024/11/28 03:53:06 INFO  : yaml: Copied (new)
2024/11/28 03:53:06 DEBUG : Waiting for deletions to finish
2024/11/28 03:53:07 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (7.47s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2024/11/28 03:53:10 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Making map for --track-renames
2024/11/28 03:53:10 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Finished making map for --track-renames
2024/11/28 03:53:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:53:10 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/11/28 03:53:10 DEBUG : yam: Need to transfer - No matching file found at Destination
2024/11/28 03:53:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for renames to finish
2024/11/28 03:53:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:53:12 DEBUG : potato: md5 = e7ddd07850d9384b4b4bcb13418fd90f OK
2024/11/28 03:53:12 INFO  : potato: Copied (new)
2024/11/28 03:53:12 DEBUG : yam: md5 = 8622157dc5968eba922384958919031e OK
2024/11/28 03:53:12 INFO  : yam: Copied (new)
2024/11/28 03:53:12 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:53:12 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:53:12 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Making map for --track-renames
2024/11/28 03:53:12 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Finished making map for --track-renames
2024/11/28 03:53:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:53:12 DEBUG : potato: Unchanged skipping
2024/11/28 03:53:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for renames to finish
2024/11/28 03:53:13 INFO  : yam: Moved (server-side) to: yaml
2024/11/28 03:53:13 INFO  : yaml: Renamed from "yam"
2024/11/28 03:53:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:53:13 DEBUG : Waiting for deletions to finish
2024/11/28 03:53:13 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (6.07s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2024/11/28 03:53:16 DEBUG : Added delayed dir = "sub", newDst=<nil>
2024/11/28 03:53:16 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Making map for --track-renames
2024/11/28 03:53:16 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Finished making map for --track-renames
2024/11/28 03:53:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:53:16 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/11/28 03:53:16 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2024/11/28 03:53:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for renames to finish
2024/11/28 03:53:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:53:19 DEBUG : sub/yam: md5 = 6622a67b5acec5ec510e0fb87047c6d0 OK
2024/11/28 03:53:19 INFO  : sub/yam: Copied (new)
2024/11/28 03:53:19 DEBUG : potato: md5 = f8bf8452066ebe2fd86f82489fdebdd3 OK
2024/11/28 03:53:19 INFO  : potato: Copied (new)
2024/11/28 03:53:19 DEBUG : Waiting for deletions to finish
2024/11/28 03:53:20 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:53:20 DEBUG : Added delayed dir = "sub", newDst=sub
2024/11/28 03:53:20 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:53:20 DEBUG : potato: Unchanged skipping
2024/11/28 03:53:21 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Making map for --track-renames
2024/11/28 03:53:21 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Finished making map for --track-renames
2024/11/28 03:53:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:53:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for renames to finish
2024/11/28 03:53:22 INFO  : sub/yam: Moved (server-side) to: yam
2024/11/28 03:53:22 INFO  : yam: Renamed from "sub/yam"
2024/11/28 03:53:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:53:22 DEBUG : Waiting for deletions to finish
2024/11/28 03:53:22 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.92s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:53:26 DEBUG : Creating backend with remote "/tmp/rclone317814031/dir1"
2024/11/28 03:53:26 DEBUG : Config file has changed externally - reloading
2024/11/28 03:53:26 DEBUG : Creating backend with remote "/tmp/rclone317814031/dir2"
2024/11/28 03:53:26 DEBUG : Local file system at /tmp/rclone317814031/dir2: Using server-side directory move
2024/11/28 03:53:26 INFO  : Local file system at /tmp/rclone317814031/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/28 03:53:26 DEBUG : file1.txt: Need to transfer - File not found at Destination
2024/11/28 03:53:26 INFO  : file1.txt: Moved (server-side)
2024/11/28 03:53:26 DEBUG : Local file system at /tmp/rclone317814031/dir2: Waiting for checks to finish
2024/11/28 03:53:26 DEBUG : Local file system at /tmp/rclone317814031/dir2: Waiting for transfers to finish
--- PASS: TestServerSideMoveLocal (0.58s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:53:27 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/11/28 03:53:27 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 03:53:27 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 03:53:27 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/11/28 03:53:27 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/11/28 03:53:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:53:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:53:29 DEBUG : sub dir/hello world: md5 = 017aa3b62ed8a8df37f23269cdb92806 OK
2024/11/28 03:53:29 INFO  : sub dir/hello world: Copied (new)
2024/11/28 03:53:29 INFO  : sub dir/hello world: Deleted
2024/11/28 03:53:31 DEBUG : nested/sub dir/file: md5 = 153b91a5246f4e76081997527fc210f2 OK
2024/11/28 03:53:31 INFO  : nested/sub dir/file: Copied (new)
2024/11/28 03:53:31 INFO  : nested/sub dir/file: Deleted
2024/11/28 03:53:32 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 03:53:32 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 03:53:33 INFO  : nested: Set directory modification time (using DirSetModTime)
2024/11/28 03:53:33 INFO  : sub dir: Removing directory
2024/11/28 03:53:33 INFO  : nested/sub dir: Removing directory
2024/11/28 03:53:33 INFO  : nested: Removing directory
2024/11/28 03:53:33 DEBUG : Local file system at /tmp/rclone317814031: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:53:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/28 03:53:36 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/11/28 03:53:37 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (12.11s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:53:39 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/11/28 03:53:39 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 03:53:39 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 03:53:39 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/11/28 03:53:39 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/11/28 03:53:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:53:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:53:41 DEBUG : sub dir/hello world: md5 = f1e8ce25f9adf6849f83711eb4dd4854 OK
2024/11/28 03:53:41 INFO  : sub dir/hello world: Copied (new)
2024/11/28 03:53:41 INFO  : sub dir/hello world: Deleted
2024/11/28 03:53:43 DEBUG : nested/sub dir/file: md5 = 055cb4855637d4bacb49a03e5a9fa09d OK
2024/11/28 03:53:43 INFO  : nested/sub dir/file: Copied (new)
2024/11/28 03:53:43 INFO  : nested/sub dir/file: Deleted
2024/11/28 03:53:44 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 03:53:45 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 03:53:45 INFO  : nested: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:53:47 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/28 03:53:48 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/11/28 03:53:49 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (12.04s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:53:51 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/28 03:53:51 DEBUG : existing-b: Need to transfer - File not found at Destination
2024/11/28 03:53:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:53:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:53:52 DEBUG : existing: md5 = 138aa1b6fef2aa04b55def7a97ea4d17 OK
2024/11/28 03:53:52 INFO  : existing: Copied (new)
2024/11/28 03:53:52 INFO  : existing: Deleted
2024/11/28 03:53:53 DEBUG : existing-b: md5 = c40c680ab61db4a3d0f530fa45f292ba OK
2024/11/28 03:53:53 INFO  : existing-b: Copied (new)
2024/11/28 03:53:53 INFO  : existing-b: Deleted
2024/11/28 03:53:53 DEBUG : existing: Destination exists, skipping
2024/11/28 03:53:53 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2024/11/28 03:53:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:53:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:53:53 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (5.08s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:53:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fokoxih4geko"
2024/11/28 03:53:56 DEBUG : Creating backend with remote "TestDrive:crypt/1v5sfbe0usql3opb78c64l0qbp2e19n1u754fh0ipgohhmhbfd1g"
2024/11/28 03:53:58 DEBUG : potato2: md5 = e9dcf3e589cc90b73bb3ce58dd67955d OK
2024/11/28 03:54:00 DEBUG : empty space: md5 = c301d7835a9ecf513ab101f163b99474 OK
2024/11/28 03:54:02 DEBUG : potato3: md5 = e85e5183bbfc4d826b827875aa663fb4 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho' -> Encrypted drive 'TestCryptDrive:rclone-test-fokoxih4geko'
2024/11/28 03:54:05 DEBUG : empty space: md5 = 94738eb7f2bbaf74f24e4025f367b4e9 OK
2024/11/28 03:54:07 DEBUG : potato3: md5 = e01dd2f7b73a1f4ccd5f6ed8abe632aa OK
2024/11/28 03:54:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fokoxih4geko': Using server-side directory move
2024/11/28 03:54:07 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-fokoxih4geko': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/28 03:54:07 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 03:54:07 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/11/28 03:54:07 DEBUG : empty space: Unchanged skipping
2024/11/28 03:54:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fokoxih4geko': Waiting for checks to finish
2024/11/28 03:54:07 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/28 03:54:08 INFO  : potato3: Deleted
2024/11/28 03:54:08 INFO  : empty space: Deleted
2024/11/28 03:54:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fokoxih4geko': Waiting for transfers to finish
2024/11/28 03:54:08 INFO  : potato2: Moved (server-side)
2024/11/28 03:54:09 INFO  : potato3: Moved (server-side)
2024/11/28 03:54:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-poyepan2zure"
2024/11/28 03:54:09 DEBUG : Creating backend with remote "TestDrive:crypt/l39cdfimb9fcprfdp3qgpc5lcfbdibe7g3204htids8nf57bang0"
2024/11/28 03:54:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-poyepan2zure': Using server-side directory move
2024/11/28 03:54:11 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-poyepan2zure': Server side directory move succeeded
2024/11/28 03:54:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-poyepan2zure': Purge remote
2024/11/28 03:54:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fokoxih4geko': Purge remote
2024/11/28 03:54:13 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (17.71s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:54:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lozowuj2zese"
2024/11/28 03:54:13 DEBUG : Creating backend with remote "TestDrive:crypt/7280gh9rffd29bvrfm9rop8239fs1ifg4q1hifn5lapb902ma7sg"
2024/11/28 03:54:16 DEBUG : potato2: md5 = dee09f2ec0efa0654676b9338abf7571 OK
2024/11/28 03:54:18 DEBUG : empty space: md5 = f46b50c5712a97b386e815b5071afc39 OK
2024/11/28 03:54:20 DEBUG : potato3: md5 = 5b8c0cdc2b298e8bf3bbc2c400908e1d OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho' -> Encrypted drive 'TestCryptDrive:rclone-test-lozowuj2zese'
2024/11/28 03:54:23 DEBUG : empty space: md5 = c232c7157b1e96478222110a0e023ba4 OK
2024/11/28 03:54:24 DEBUG : potato3: md5 = 5cd0357a438afa0e85c6c7e003ba4f16 OK
2024/11/28 03:54:25 DEBUG : empty space: Excluded (Size Filter)
2024/11/28 03:54:25 DEBUG : empty space: Excluded
2024/11/28 03:54:25 DEBUG : empty space: Excluded (Size Filter)
2024/11/28 03:54:25 DEBUG : empty space: Excluded
2024/11/28 03:54:25 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 03:54:25 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/28 03:54:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lozowuj2zese': Waiting for checks to finish
2024/11/28 03:54:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lozowuj2zese': Waiting for transfers to finish
2024/11/28 03:54:25 INFO  : potato3: Deleted
2024/11/28 03:54:26 INFO  : potato2: Moved (server-side)
2024/11/28 03:54:26 INFO  : potato3: Moved (server-side)
2024/11/28 03:54:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dugixad9koza"
2024/11/28 03:54:27 DEBUG : Creating backend with remote "TestDrive:crypt/h9ao4f3ism9vq35eblde6nhaa1ksl968v70lqrqnhsfdtl52mam0"
2024/11/28 03:54:28 DEBUG : empty space: Excluded (Size Filter)
2024/11/28 03:54:28 DEBUG : empty space: Excluded
2024/11/28 03:54:28 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 03:54:28 DEBUG : potato3: Need to transfer - File not found at Destination
2024/11/28 03:54:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dugixad9koza': Waiting for checks to finish
2024/11/28 03:54:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dugixad9koza': Waiting for transfers to finish
2024/11/28 03:54:30 INFO  : potato2: Moved (server-side)
2024/11/28 03:54:31 INFO  : potato3: Moved (server-side)
2024/11/28 03:54:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dugixad9koza': Purge remote
2024/11/28 03:54:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lozowuj2zese': Purge remote
--- PASS: TestServerSideMoveWithFilter (20.21s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:54:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xocirox0duqi"
2024/11/28 03:54:34 DEBUG : Creating backend with remote "TestDrive:crypt/svksv13spbamp3nt36qot1ko551ri0s2moqlol1p11i2ohm0s000"
2024/11/28 03:54:36 DEBUG : potato2: md5 = 4a3907e33a0dbd8165dd37725697697b OK
2024/11/28 03:54:38 DEBUG : empty space: md5 = ef5c3ba717d8186a8547521ae22e5cff OK
2024/11/28 03:54:40 DEBUG : potato3: md5 = 5ac8abecbb87200824f6ff83184f59a2 OK
2024/11/28 03:54:40 DEBUG : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho' -> Encrypted drive 'TestCryptDrive:rclone-test-xocirox0duqi'
2024/11/28 03:54:44 DEBUG : empty space: md5 = a0bb4bed3d109633e4c0b67a7eb24758 OK
2024/11/28 03:54:45 DEBUG : potato3: md5 = 7ca3f60fc629abf8f45ab0d74e0c6860 OK
2024/11/28 03:54:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xocirox0duqi': Using server-side directory move
2024/11/28 03:54:46 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-xocirox0duqi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/28 03:54:46 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 03:54:46 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2024/11/28 03:54:46 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/11/28 03:54:46 DEBUG : empty space: Unchanged skipping
2024/11/28 03:54:46 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/28 03:54:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xocirox0duqi': Waiting for checks to finish
2024/11/28 03:54:47 INFO  : empty space: Deleted
2024/11/28 03:54:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xocirox0duqi': Waiting for transfers to finish
2024/11/28 03:54:47 INFO  : potato3: Deleted
2024/11/28 03:54:47 INFO  : potato2: Moved (server-side)
2024/11/28 03:54:47 INFO  : potato3: Moved (server-side)
2024/11/28 03:54:47 INFO  : tomatoDir: Removing directory
2024/11/28 03:54:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': deleted 1 directories
2024/11/28 03:54:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qubuqix2voka"
2024/11/28 03:54:49 DEBUG : Creating backend with remote "TestDrive:crypt/hvh598vs2r92fds5rc0u8493a0sqjj70am9pv5kpfneajpt2rdi0"
2024/11/28 03:54:50 DEBUG : tomatoDir: Making directory
2024/11/28 03:54:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qubuqix2voka': Using server-side directory move
2024/11/28 03:54:52 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-qubuqix2voka': Server side directory move succeeded
2024/11/28 03:54:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qubuqix2voka': Purge remote
2024/11/28 03:54:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xocirox0duqi': Purge remote
2024/11/28 03:54:54 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (21.35s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.46s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:54:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/rclone-sync-test"
2024/11/28 03:54:55 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncOverlap (4.02s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:54:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/rclone-sync-test"
2024/11/28 03:54:59 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2024/11/28 03:55:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/rclone-sync-test-include/layer2"
2024/11/28 03:55:02 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2024/11/28 03:55:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/rclone-sync-test-ignore-file"
2024/11/28 03:55:06 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2024/11/28 03:55:10 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 29c9ce6220522644f5e5e38af899ae99 OK
2024/11/28 03:55:11 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/28 03:55:11 DEBUG : rclone-sync-test: Excluded
2024/11/28 03:55:11 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/28 03:55:12 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/28 03:55:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/rclone-sync-test': Waiting for checks to finish
2024/11/28 03:55:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/rclone-sync-test': Waiting for transfers to finish
2024/11/28 03:55:12 DEBUG : Waiting for deletions to finish
2024/11/28 03:55:12 INFO  : There was nothing to transfer
2024/11/28 03:55:13 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/28 03:55:13 DEBUG : rclone-sync-test: Excluded
2024/11/28 03:55:14 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/28 03:55:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:55:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:55:14 DEBUG : Waiting for deletions to finish
2024/11/28 03:55:14 INFO  : rclone-sync-test-include: Removing directory
2024/11/28 03:55:14 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/28 03:55:14 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/11/28 03:55:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': failed to delete 1 directories
2024/11/28 03:55:14 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:55:15 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/28 03:55:15 DEBUG : rclone-sync-test: Excluded
2024/11/28 03:55:15 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/28 03:55:16 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/28 03:55:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/rclone-sync-test-include/layer2': Waiting for checks to finish
2024/11/28 03:55:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/rclone-sync-test-include/layer2': Waiting for transfers to finish
2024/11/28 03:55:16 DEBUG : Waiting for deletions to finish
2024/11/28 03:55:16 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:55:16 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/28 03:55:17 DEBUG : rclone-sync-test: Excluded
2024/11/28 03:55:17 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/28 03:55:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:55:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:55:17 DEBUG : Waiting for deletions to finish
2024/11/28 03:55:17 INFO  : rclone-sync-test-include: Removing directory
2024/11/28 03:55:18 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/28 03:55:18 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/11/28 03:55:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': failed to delete 1 directories
2024/11/28 03:55:18 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:55:18 DEBUG : : Excluded
2024/11/28 03:55:18 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/28 03:55:19 DEBUG : rclone-sync-test: Excluded
2024/11/28 03:55:19 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/28 03:55:19 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/28 03:55:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/rclone-sync-test-ignore-file': Waiting for checks to finish
2024/11/28 03:55:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/rclone-sync-test-ignore-file': Waiting for transfers to finish
2024/11/28 03:55:19 DEBUG : Waiting for deletions to finish
2024/11/28 03:55:19 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:55:22 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/28 03:55:22 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (33.13s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:55:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/dst"
2024/11/28 03:55:33 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/28 03:55:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/CompareDest"
2024/11/28 03:55:34 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/gveqi14airsml4bgu7krj116o8"
2024/11/28 03:55:36 DEBUG : one: Need to transfer - File not found at Destination
2024/11/28 03:55:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:55:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:55:40 DEBUG : one: md5 = 84ff7bb82ca1c128e9719c1c91bcc13d OK
2024/11/28 03:55:40 INFO  : one: Copied (new)
2024/11/28 03:55:40 DEBUG : Waiting for deletions to finish
2024/11/28 03:55:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:55:41 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/28 03:55:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:55:43 DEBUG : one: md5 = 47d3c1a90c9937cc5858f0f4dec330f8 OK
2024/11/28 03:55:43 INFO  : one: Copied (replaced existing)
2024/11/28 03:55:43 DEBUG : Waiting for deletions to finish
2024/11/28 03:55:45 DEBUG : dst/one: md5 = a75e553bc2b337f2e6b6af55fb954ebc OK
2024/11/28 03:55:47 DEBUG : CompareDest/one: md5 = c5d53a340f4b5a6ef1589107ba3a9c57 OK
2024/11/28 03:55:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:55:48 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/28 03:55:49 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:55:49 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/28 03:55:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:55:49 DEBUG : Waiting for deletions to finish
2024/11/28 03:55:49 INFO  : There was nothing to transfer
2024/11/28 03:55:51 DEBUG : CompareDest/two: md5 = 04ecc3cfc2235089dfba6219c759914b OK
2024/11/28 03:55:52 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:55:52 DEBUG : two: Destination found in --compare-dest, skipping
2024/11/28 03:55:52 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/28 03:55:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:55:52 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:55:52 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/28 03:55:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:55:52 DEBUG : Waiting for deletions to finish
2024/11/28 03:55:52 INFO  : There was nothing to transfer
2024/11/28 03:55:53 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:55:53 DEBUG : two: Destination found in --compare-dest, skipping
2024/11/28 03:55:53 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/28 03:55:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:55:54 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:55:54 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/28 03:55:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:55:54 DEBUG : Waiting for deletions to finish
2024/11/28 03:55:54 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2024/11/28 03:55:55 DEBUG : two: Sizes differ (src 5 vs dst 3)
2024/11/28 03:55:55 DEBUG : two: Need to transfer - File not found at Destination
2024/11/28 03:55:55 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/28 03:55:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:55:56 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:55:56 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/28 03:55:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:55:57 DEBUG : two: md5 = 0556f307253bcd3918da47fed3da4963 OK
2024/11/28 03:55:57 INFO  : two: Copied (new)
2024/11/28 03:55:57 DEBUG : Waiting for deletions to finish
2024/11/28 03:56:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/28 03:56:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 03:56:01 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/28 03:56:01 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCompareDest (29.78s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:56:05 DEBUG : pre-dest1/1: md5 = 7d08c09b57c8b34d11e86139d1be5ea8 OK
2024/11/28 03:56:08 DEBUG : pre-dest2/2: md5 = c22ebdfca0e50763822032d40b527add OK
2024/11/28 03:56:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/dest"
2024/11/28 03:56:09 DEBUG : Config file has changed externally - reloading
2024/11/28 03:56:09 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/rg03c1jvnehrrc617i0lnqjddc"
2024/11/28 03:56:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/pre-dest1"
2024/11/28 03:56:11 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/bbnblvh6k061ssopqrp18kd7gc"
2024/11/28 03:56:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/pre-dest2"
2024/11/28 03:56:11 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/dgicm1h6b5ejvlltm8eeif0bnk"
2024/11/28 03:56:13 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:56:13 DEBUG : 1: Destination found in --compare-dest, skipping
2024/11/28 03:56:13 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:56:13 DEBUG : 2: Destination found in --compare-dest, skipping
2024/11/28 03:56:14 DEBUG : 3: Need to transfer - File not found at Destination
2024/11/28 03:56:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dest': Waiting for checks to finish
2024/11/28 03:56:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dest': Waiting for transfers to finish
2024/11/28 03:56:17 DEBUG : 3: md5 = aac7a9ef577581deed9fb1d365abd154 OK
2024/11/28 03:56:17 INFO  : 3: Copied (new)
2024/11/28 03:56:17 DEBUG : Waiting for deletions to finish
2024/11/28 03:56:20 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2024/11/28 03:56:21 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2024/11/28 03:56:22 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (20.72s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:56:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/dst"
2024/11/28 03:56:23 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/28 03:56:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/CopyDest"
2024/11/28 03:56:25 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/d09o6po3f7bm6ce32vdgs8h9ls"
2024/11/28 03:56:27 DEBUG : one: Need to transfer - File not found at Destination
2024/11/28 03:56:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:56:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:56:29 DEBUG : one: md5 = 65c2fe84920ec1a025b1963755861c41 OK
2024/11/28 03:56:29 INFO  : one: Copied (new)
2024/11/28 03:56:29 DEBUG : Waiting for deletions to finish
2024/11/28 03:56:31 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/28 03:56:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:56:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:56:32 DEBUG : one: md5 = db20cf7ee1bc161d4a17e07e201dedb8 OK
2024/11/28 03:56:32 INFO  : one: Copied (replaced existing)
2024/11/28 03:56:32 DEBUG : Waiting for deletions to finish
2024/11/28 03:56:34 DEBUG : dst/one: md5 = 2ce1348e9af58222dcdfc648a9afdf06 OK
2024/11/28 03:56:37 DEBUG : CopyDest/one: md5 = a80a374388cca925d3b08b3a7d2e5110 OK
2024/11/28 03:56:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/BackupDir"
2024/11/28 03:56:37 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/s6dbk3lfi7c9kfvo6j7bla9m0g"
2024/11/28 03:56:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:56:39 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/28 03:56:40 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:56:40 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/28 03:56:42 INFO  : one: Moved (server-side)
2024/11/28 03:56:43 INFO  : one: Copied (server-side copy)
2024/11/28 03:56:43 DEBUG : one: Destination found in --copy-dest, using server-side copy
2024/11/28 03:56:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:56:43 DEBUG : Waiting for deletions to finish
2024/11/28 03:56:45 DEBUG : CopyDest/two: md5 = 89ccbc8fe5e8031f0da1eaa237513602 OK
2024/11/28 03:56:46 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:56:48 INFO  : two: Copied (server-side copy)
2024/11/28 03:56:48 DEBUG : two: Destination found in --copy-dest, using server-side copy
2024/11/28 03:56:48 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:56:48 DEBUG : one: Unchanged skipping
2024/11/28 03:56:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:56:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:56:48 DEBUG : Waiting for deletions to finish
2024/11/28 03:56:48 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:56:48 DEBUG : one: Unchanged skipping
2024/11/28 03:56:48 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:56:48 DEBUG : two: Unchanged skipping
2024/11/28 03:56:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:56:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:56:48 DEBUG : Waiting for deletions to finish
2024/11/28 03:56:48 INFO  : There was nothing to transfer
2024/11/28 03:56:50 DEBUG : CopyDest/three: md5 = 732a152e1741ed9b1a1a2b468fb46a4c OK
2024/11/28 03:56:51 DEBUG : three: Sizes differ (src 7 vs dst 5)
2024/11/28 03:56:51 DEBUG : three: Destination not found in --copy-dest
2024/11/28 03:56:51 DEBUG : three: Need to transfer - File not found at Destination
2024/11/28 03:56:51 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:56:51 DEBUG : one: Unchanged skipping
2024/11/28 03:56:51 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 03:56:51 DEBUG : two: Unchanged skipping
2024/11/28 03:56:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:56:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:56:53 DEBUG : three: md5 = 64f6ac6c2488875dfeaab355bc2f9094 OK
2024/11/28 03:56:53 INFO  : three: Copied (new)
2024/11/28 03:56:53 DEBUG : Waiting for deletions to finish
2024/11/28 03:56:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/11/28 03:56:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/28 03:56:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 03:57:00 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/11/28 03:57:00 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 03:57:00 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/28 03:57:01 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (38.46s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:57:04 DEBUG : dst/one: md5 = 8c9a3d395e1cb52ec298b56419af4605 OK
2024/11/28 03:57:06 DEBUG : dst/two: md5 = 5250b147a7537e6bfa582709a9b58c3a OK
2024/11/28 03:57:07 DEBUG : dst/three.txt: md5 = a136c0867c35e29e61ebc3969adf61aa OK
2024/11/28 03:57:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/dst"
2024/11/28 03:57:08 DEBUG : Config file has changed externally - reloading
2024/11/28 03:57:08 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/28 03:57:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/backup"
2024/11/28 03:57:09 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/1nrff024r7pq65ecp72fc28jb0"
2024/11/28 03:57:10 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/28 03:57:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:57:10 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:57:10 DEBUG : two: Unchanged skipping
2024/11/28 03:57:13 INFO  : one: Moved (server-side)
2024/11/28 03:57:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:57:15 DEBUG : one: md5 = 67cea84f5064cead1a74eddf406dafe9 OK
2024/11/28 03:57:15 INFO  : one: Copied (new)
2024/11/28 03:57:15 DEBUG : Waiting for deletions to finish
2024/11/28 03:57:16 INFO  : three.txt: Moved (server-side)
2024/11/28 03:57:16 INFO  : three.txt: Moved into backup dir
2024/11/28 03:57:18 DEBUG : dst/three.txt: md5 = 693b8f940be77c55af1e615083732944 OK
2024/11/28 03:57:19 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/28 03:57:19 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:57:19 DEBUG : two: Unchanged skipping
2024/11/28 03:57:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:57:20 INFO  : one: Deleted
2024/11/28 03:57:21 INFO  : one: Moved (server-side)
2024/11/28 03:57:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:57:22 DEBUG : one: md5 = 3844907583f15e2911e430a9a3078d17 OK
2024/11/28 03:57:22 INFO  : one: Copied (new)
2024/11/28 03:57:22 DEBUG : Waiting for deletions to finish
2024/11/28 03:57:23 INFO  : three.txt: Deleted
2024/11/28 03:57:24 INFO  : three.txt: Moved (server-side)
2024/11/28 03:57:24 INFO  : three.txt: Moved into backup dir
2024/11/28 03:57:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 03:57:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/28 03:57:29 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/28 03:57:29 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 03:57:29 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/28 03:57:29 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncBackupDir (28.12s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:57:32 DEBUG : dst/one: md5 = 3fb5210305c7e525c9e5dfbbd0016057 OK
2024/11/28 03:57:34 DEBUG : dst/two: md5 = 79a07ca092add6b31cc0f32b44a5a6bc OK
2024/11/28 03:57:35 DEBUG : dst/three.txt: md5 = e0de8fdfc65d8ab268fbaa1bcc099e53 OK
2024/11/28 03:57:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/dst"
2024/11/28 03:57:36 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/28 03:57:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/backup"
2024/11/28 03:57:37 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/1nrff024r7pq65ecp72fc28jb0"
2024/11/28 03:57:38 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/28 03:57:38 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:57:38 DEBUG : two: Unchanged skipping
2024/11/28 03:57:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:57:41 INFO  : one: Moved (server-side) to: one.bak
2024/11/28 03:57:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:57:42 DEBUG : one: md5 = 996b1d4ea72e36f6eea56b03e119ef1f OK
2024/11/28 03:57:42 INFO  : one: Copied (new)
2024/11/28 03:57:42 DEBUG : Waiting for deletions to finish
2024/11/28 03:57:44 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/28 03:57:44 INFO  : three.txt: Moved into backup dir
2024/11/28 03:57:46 DEBUG : dst/three.txt: md5 = 43bbd732b2447ac94a27e4bf6a549fdd OK
2024/11/28 03:57:46 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/28 03:57:46 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:57:46 DEBUG : two: Unchanged skipping
2024/11/28 03:57:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:57:47 INFO  : one.bak: Deleted
2024/11/28 03:57:48 INFO  : one: Moved (server-side) to: one.bak
2024/11/28 03:57:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:57:50 DEBUG : one: md5 = cf314cbc6244b2d37b52a2b276b451c7 OK
2024/11/28 03:57:50 INFO  : one: Copied (new)
2024/11/28 03:57:50 DEBUG : Waiting for deletions to finish
2024/11/28 03:57:51 INFO  : three.txt.bak: Deleted
2024/11/28 03:57:52 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/28 03:57:52 INFO  : three.txt: Moved into backup dir
2024/11/28 03:57:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 03:57:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/28 03:57:56 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/28 03:57:56 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/28 03:57:56 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/28 03:57:56 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirWithSuffix (27.48s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:58:00 DEBUG : dst/one: md5 = 22573c2992811ce6eb919325b10336a8 OK
2024/11/28 03:58:01 DEBUG : dst/two: md5 = a6cd4de82ac45c06d8fe092e33c67a44 OK
2024/11/28 03:58:03 DEBUG : dst/three.txt: md5 = 64961a342d72c882ad32d0964a551f5e OK
2024/11/28 03:58:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/dst"
2024/11/28 03:58:04 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/28 03:58:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/backup"
2024/11/28 03:58:04 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/1nrff024r7pq65ecp72fc28jb0"
2024/11/28 03:58:06 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/28 03:58:06 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:58:06 DEBUG : two: Unchanged skipping
2024/11/28 03:58:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:58:08 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/28 03:58:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:58:10 DEBUG : one: md5 = 6f6896341207d6d5795ecef9094b922f OK
2024/11/28 03:58:10 INFO  : one: Copied (new)
2024/11/28 03:58:10 DEBUG : Waiting for deletions to finish
2024/11/28 03:58:11 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/28 03:58:11 INFO  : three.txt: Moved into backup dir
2024/11/28 03:58:14 DEBUG : dst/three.txt: md5 = 566bc43b1f210f8f196c5e434461478b OK
2024/11/28 03:58:14 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/28 03:58:14 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:58:14 DEBUG : two: Unchanged skipping
2024/11/28 03:58:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:58:15 INFO  : one-2019-01-01: Deleted
2024/11/28 03:58:16 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/28 03:58:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:58:18 DEBUG : one: md5 = e27727424a3a3449baa34af17d3beeca OK
2024/11/28 03:58:18 INFO  : one: Copied (new)
2024/11/28 03:58:18 DEBUG : Waiting for deletions to finish
2024/11/28 03:58:19 INFO  : three-2019-01-01.txt: Deleted
2024/11/28 03:58:19 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/28 03:58:19 INFO  : three.txt: Moved into backup dir
2024/11/28 03:58:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 03:58:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/28 03:58:24 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/28 03:58:24 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/28 03:58:24 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/28 03:58:24 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (27.73s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:58:27 DEBUG : dst/one: md5 = 82c5d9dac8dd628a81c1d156290e6c68 OK
2024/11/28 03:58:29 DEBUG : dst/two: md5 = 6db3240e2a31b0f866d0a257e74bd8a7 OK
2024/11/28 03:58:31 DEBUG : dst/three.txt: md5 = 5d179bda12e54dbf3a4d061f10ebd590 OK
2024/11/28 03:58:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/dst"
2024/11/28 03:58:32 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/28 03:58:33 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/28 03:58:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:58:33 DEBUG : two: Unchanged skipping
2024/11/28 03:58:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:58:33 INFO  : one: Moved (server-side) to: one.bak
2024/11/28 03:58:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:58:35 DEBUG : one: md5 = 694738e8a276112f9f8ec9136ba642a9 OK
2024/11/28 03:58:35 INFO  : one: Copied (new)
2024/11/28 03:58:35 DEBUG : Waiting for deletions to finish
2024/11/28 03:58:36 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/28 03:58:36 INFO  : three.txt: Moved into backup dir
2024/11/28 03:58:38 DEBUG : dst/three.txt: md5 = 5d005b05e26d5ed83c664d87e3a43edc OK
2024/11/28 03:58:39 DEBUG : three.txt.bak: Excluded (Path Filter)
2024/11/28 03:58:39 DEBUG : three.txt.bak: Excluded
2024/11/28 03:58:39 DEBUG : one.bak: Excluded (Path Filter)
2024/11/28 03:58:39 DEBUG : one.bak: Excluded
2024/11/28 03:58:39 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/28 03:58:39 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:58:39 DEBUG : two: Unchanged skipping
2024/11/28 03:58:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for checks to finish
2024/11/28 03:58:40 INFO  : one.bak: Deleted
2024/11/28 03:58:40 INFO  : one: Moved (server-side) to: one.bak
2024/11/28 03:58:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho/dst': Waiting for transfers to finish
2024/11/28 03:58:42 DEBUG : one: md5 = 7df92d90c8ad6e002c3acfe3d9136b11 OK
2024/11/28 03:58:42 INFO  : one: Copied (new)
2024/11/28 03:58:42 DEBUG : Waiting for deletions to finish
2024/11/28 03:58:43 INFO  : three.txt.bak: Deleted
2024/11/28 03:58:44 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/28 03:58:44 INFO  : three.txt: Moved into backup dir
2024/11/28 03:58:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 03:58:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/28 03:58:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/28 03:58:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/28 03:58:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/28 03:58:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncBackupDirSuffixOnly (22.97s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:58:50 DEBUG : dst/one: md5 = d531375d63f3c191109dff6128353f86 OK
2024/11/28 03:58:52 DEBUG : dst/two: md5 = bd6315c37834a38687b5d4966711a4f1 OK
2024/11/28 03:58:54 DEBUG : dst/three.txt: md5 = d9f4316d82bad3d29f212646277fd528 OK
2024/11/28 03:58:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/dst"
2024/11/28 03:58:54 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/28 03:58:55 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/28 03:58:56 INFO  : one: Moved (server-side) to: one.bak
2024/11/28 03:58:58 DEBUG : one: md5 = 3c163507a2223ad9d43e7df579d4dd7c OK
2024/11/28 03:58:58 INFO  : one: Copied (new)
2024/11/28 03:58:58 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:58:58 DEBUG : two: Unchanged skipping
2024/11/28 03:58:58 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/11/28 03:58:59 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/28 03:59:01 DEBUG : three.txt: md5 = 768eb0dcf78deb807b75eae062b30ebf OK
2024/11/28 03:59:01 INFO  : three.txt: Copied (new)
2024/11/28 03:59:02 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/28 03:59:03 INFO  : one.bak: Deleted
2024/11/28 03:59:04 INFO  : one: Moved (server-side) to: one.bak
2024/11/28 03:59:05 DEBUG : one: md5 = e98692639bb2cc61e0d1ac86573bce8b OK
2024/11/28 03:59:05 INFO  : one: Copied (new)
2024/11/28 03:59:06 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:59:06 DEBUG : two: Unchanged skipping
2024/11/28 03:59:06 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/11/28 03:59:07 INFO  : three.txt.bak: Deleted
2024/11/28 03:59:07 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/28 03:59:09 DEBUG : three.txt: md5 = dc9ac38ef8a0f888723cbd6498baa1b6 OK
2024/11/28 03:59:09 INFO  : three.txt: Copied (new)
2024/11/28 03:59:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/28 03:59:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 03:59:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/28 03:59:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/28 03:59:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/28 03:59:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/28 03:59:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncSuffix (26.84s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:59:17 DEBUG : dst/one: md5 = 1f45a5b9493826020a47f6a3f3841525 OK
2024/11/28 03:59:19 DEBUG : dst/two: md5 = 1b6f5773dec8ca3a750f17f23ee2e2ca OK
2024/11/28 03:59:21 DEBUG : dst/three.txt: md5 = 0f421f965c05e946204c9d05e7ff421a OK
2024/11/28 03:59:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pohiror7duho/dst"
2024/11/28 03:59:22 DEBUG : Creating backend with remote "TestDrive:crypt/kaeakjep0hs4894l00qd6pup1jqi8r7flobe0o1po2m47cp9vu50/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/28 03:59:23 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/28 03:59:23 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/28 03:59:25 DEBUG : one: md5 = 7e460128c63a3b168ced40a0817d77a3 OK
2024/11/28 03:59:25 INFO  : one: Copied (new)
2024/11/28 03:59:25 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:59:25 DEBUG : two: Unchanged skipping
2024/11/28 03:59:25 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/11/28 03:59:26 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/28 03:59:28 DEBUG : three.txt: md5 = 17a8aad1102732abbf6610683161e2c4 OK
2024/11/28 03:59:28 INFO  : three.txt: Copied (new)
2024/11/28 03:59:29 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/28 03:59:30 INFO  : one-2019-01-01: Deleted
2024/11/28 03:59:31 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/28 03:59:32 DEBUG : one: md5 = a10f71cd594c0864e813f2f94291ceaa OK
2024/11/28 03:59:32 INFO  : one: Copied (new)
2024/11/28 03:59:32 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:59:32 DEBUG : two: Unchanged skipping
2024/11/28 03:59:33 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/11/28 03:59:34 INFO  : three-2019-01-01.txt: Deleted
2024/11/28 03:59:34 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/28 03:59:36 DEBUG : three.txt: md5 = 1a5754faf1314a328557dff597a5f441 OK
2024/11/28 03:59:36 INFO  : three.txt: Copied (new)
2024/11/28 03:59:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 03:59:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/28 03:59:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/28 03:59:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/28 03:59:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/28 03:59:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/28 03:59:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncSuffixKeepExtension (26.66s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:59:43 DEBUG : Testêé: md5 = 46bc34513fd48eaec06bd7d895b62dae OK
2024/11/28 03:59:43 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2024/11/28 03:59:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:59:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:59:45 DEBUG : Testêé: md5 = 7e6fb130a453930a8aff232f9be2920e OK
2024/11/28 03:59:45 INFO  : Testêé: Copied (replaced existing) to: Testêé
2024/11/28 03:59:45 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (5.01s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:59:47 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/28 03:59:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:59:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:59:48 DEBUG : existing: md5 = 0f63a9e38759cfe97f15c0dfd19dbd7a OK
2024/11/28 03:59:48 INFO  : existing: Copied (new)
2024/11/28 03:59:48 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:59:49 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2024/11/28 03:59:49 ERROR : existing: Source and destination exist but do not match: immutable file modified
2024/11/28 03:59:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:59:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:59:49 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': not deleting files as there were IO errors
2024/11/28 03:59:49 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncImmutable (5.10s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:59:53 DEBUG : EXISTING: md5 = 7d2daf0a3c0a617a24ea6780aad7f67a OK
2024/11/28 03:59:53 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 03:59:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 03:59:53 DEBUG : existing: Unchanged skipping
2024/11/28 03:59:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 03:59:53 DEBUG : Waiting for deletions to finish
2024/11/28 03:59:53 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (3.50s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.47s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", 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-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", 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-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.39s)
    --- SKIP: TestMaxTransfer/Hard (0.48s)
    --- SKIP: TestMaxTransfer/Soft (0.46s)
    --- SKIP: TestMaxTransfer/Cautious (0.44s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 03:59:59 DEBUG : both0: md5 = f8b145c769d3f7a59e8ddcb2bba6427c OK
2024/11/28 04:00:00 DEBUG : only0: md5 = 8baa40f4dd8ef71894a4bbc94359110b OK
2024/11/28 04:00:02 DEBUG : both1: md5 = 8dbe2303a6c936f7db9a090c7b4e84ea OK
2024/11/28 04:00:04 DEBUG : only1: md5 = 9d282d4bec97f07b06b2bd8eab6962e3 OK
2024/11/28 04:00:05 DEBUG : both2: md5 = b51154d391d9071cbdba35c1279bcb10 OK
2024/11/28 04:00:07 DEBUG : only2: md5 = a58cae97f563d458fa1b6b3552fe93b1 OK
2024/11/28 04:00:09 DEBUG : both3: md5 = 4e62d1532cf687019f6dc5883597628b OK
2024/11/28 04:00:10 DEBUG : only3: md5 = 911af37c289ce51509ac5bee172a788e OK
2024/11/28 04:00:12 DEBUG : both4: md5 = 17fa35bf926dd57b1cffaf6291dae1d0 OK
2024/11/28 04:00:14 DEBUG : only4: md5 = 858bba2b5c62b5099f1a128e685dc0a3 OK
2024/11/28 04:00:16 DEBUG : both5: md5 = 1d8c5885e18c7d2c8d253e40fdd22216 OK
2024/11/28 04:00:17 DEBUG : only5: md5 = 371d8fec53ef1264713acafabd47a918 OK
2024/11/28 04:00:19 DEBUG : both6: md5 = 93580fdc5ca65715359eb7097dce8991 OK
2024/11/28 04:00:21 DEBUG : only6: md5 = 45f439993eecffa7c9b25bce934e320c OK
2024/11/28 04:00:23 DEBUG : both7: md5 = e437e050b2206992c1aa00ff6e5b3578 OK
2024/11/28 04:00:24 DEBUG : only7: md5 = 5af2693e40b6f5cac513ef267bcc4538 OK
2024/11/28 04:00:26 DEBUG : both8: md5 = 522638a1d77bf79042ceeaa50c3f5d70 OK
2024/11/28 04:00:28 DEBUG : only8: md5 = dcddbc2473292f122a4a917417987cd4 OK
2024/11/28 04:00:29 DEBUG : both9: md5 = 8bbef1ffe71373ab0b8cb7b749de6e65 OK
2024/11/28 04:00:31 DEBUG : only9: md5 = 798d0e1b274ae9a56e25d3e205f3de03 OK
2024/11/28 04:00:33 DEBUG : both10: md5 = 5e4f513f72dcd063368af4303a258cab OK
2024/11/28 04:00:34 DEBUG : only10: md5 = 38ea0a6514635c5fd82fa4562b4ac329 OK
2024/11/28 04:00:36 DEBUG : both11: md5 = a72cefdf260fd6682e448379ac6d0b55 OK
2024/11/28 04:00:37 DEBUG : only11: md5 = b94e55ee930609f949ac395215282de2 OK
2024/11/28 04:00:39 DEBUG : both12: md5 = 66c78e76b100135205f9037433a3e1ef OK
2024/11/28 04:00:41 DEBUG : only12: md5 = 175ec34f4e72e3b202ce1948a194ca66 OK
2024/11/28 04:00:42 DEBUG : both13: md5 = 36f723fb3b2505dfed9d0a971833c907 OK
2024/11/28 04:00:45 DEBUG : only13: md5 = 2b6dab165ecd21317047992bdc0bb0be OK
2024/11/28 04:00:47 DEBUG : both14: md5 = 8101a00ae8553a2db772f05c515caa59 OK
2024/11/28 04:00:48 DEBUG : only14: md5 = 3ed004a637903db842722643d78b2f84 OK
2024/11/28 04:00:50 DEBUG : both15: md5 = c941655d5f1ac29547c145a5f343998c OK
2024/11/28 04:00:52 DEBUG : only15: md5 = f3e127ce7838be2a625b5154350a4f71 OK
2024/11/28 04:00:54 DEBUG : both16: md5 = 23a629811bdda81efd7a09e646e252f5 OK
2024/11/28 04:00:55 DEBUG : only16: md5 = 3b31cce59965ed93f1b768c92ba3d1c6 OK
2024/11/28 04:00:57 DEBUG : both17: md5 = 88b1e380b40a1e50c84d76812c8fad79 OK
2024/11/28 04:00:59 DEBUG : only17: md5 = 2db76f543dd9641135e8d08adfd98eb3 OK
2024/11/28 04:01:01 DEBUG : both18: md5 = 670b80963472812075dea37b92efe24e OK
2024/11/28 04:01:02 DEBUG : only18: md5 = 5cb54c8de1fd91c6bcafd2c9e87387e2 OK
2024/11/28 04:01:04 DEBUG : both19: md5 = dbfabae32d69a3317e696429dcf04ed3 OK
2024/11/28 04:01:06 DEBUG : only19: md5 = 09da19b111ca546dd0a8587df8384b4a OK
2024/11/28 04:01:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 04:01:06 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both10: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both11: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both13: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both14: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both15: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both16: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both17: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both18: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both12: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both2: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both0: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both1: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both5: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both6: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both19: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both8: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:01:06 DEBUG : both9: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both3: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both4: Unchanged skipping
2024/11/28 04:01:06 DEBUG : both7: Unchanged skipping
2024/11/28 04:01:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 04:01:06 DEBUG : Waiting for deletions to finish
2024/11/28 04:01:07 INFO  : only18: Deleted
2024/11/28 04:01:07 INFO  : only16: Deleted
2024/11/28 04:01:07 INFO  : only19: Deleted
2024/11/28 04:01:07 INFO  : only3: Deleted
2024/11/28 04:01:08 INFO  : only5: Deleted
2024/11/28 04:01:08 INFO  : only11: Deleted
2024/11/28 04:01:08 INFO  : only9: Deleted
2024/11/28 04:01:08 INFO  : only12: Deleted
2024/11/28 04:01:08 INFO  : only7: Deleted
2024/11/28 04:01:08 INFO  : only2: Deleted
2024/11/28 04:01:08 INFO  : only0: Deleted
2024/11/28 04:01:08 INFO  : only1: Deleted
2024/11/28 04:01:09 INFO  : only10: Deleted
2024/11/28 04:01:09 INFO  : only13: Deleted
2024/11/28 04:01:09 INFO  : only15: Deleted
2024/11/28 04:01:09 INFO  : only14: Deleted
2024/11/28 04:01:09 INFO  : only17: Deleted
2024/11/28 04:01:09 INFO  : only6: Deleted
2024/11/28 04:01:09 INFO  : only4: Deleted
2024/11/28 04:01:10 INFO  : only8: Deleted
2024/11/28 04:01:10 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (85.32s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 04:01:24 DEBUG : both0: md5 = 8d5feb49d8a6c6c75b9458bbc29d0000 OK
2024/11/28 04:01:25 DEBUG : only0: md5 = 35fac0615c4c1f9eb3281d04a92c0bf5 OK
2024/11/28 04:01:27 DEBUG : both1: md5 = ccf09b7ffa8d2d3561b88ea28529467d OK
2024/11/28 04:01:29 DEBUG : only1: md5 = 6d8e30396c91708ed6020cf65345d10a OK
2024/11/28 04:01:30 DEBUG : both2: md5 = 41cd28b99087e007a1e450841586fc8f OK
2024/11/28 04:01:32 DEBUG : only2: md5 = 222cca0477e3ece63dcf51da3e9a85f0 OK
2024/11/28 04:01:34 DEBUG : both3: md5 = 9e91e2e683478acafdc2c31734527280 OK
2024/11/28 04:01:35 DEBUG : only3: md5 = f3041fc3d7183263300f278c0cabf527 OK
2024/11/28 04:01:37 DEBUG : both4: md5 = 0c1d53a9d9bdcf6a0652a33d623f81c4 OK
2024/11/28 04:01:39 DEBUG : only4: md5 = 1fa323d00761d451cb9db92097f24f55 OK
2024/11/28 04:01:41 DEBUG : both5: md5 = 3d3c227219a6f37b2d4350815934913e OK
2024/11/28 04:01:42 DEBUG : only5: md5 = 7bd74b0595d695d34849afd579c92e21 OK
2024/11/28 04:01:44 DEBUG : both6: md5 = 7222e724303bc92092582dbc8dd9ebf0 OK
2024/11/28 04:01:45 DEBUG : only6: md5 = c1548982864b5f8323da27abce498c15 OK
2024/11/28 04:01:47 DEBUG : both7: md5 = d5e8816a624391cf5c68d64cf132d477 OK
2024/11/28 04:01:49 DEBUG : only7: md5 = 3712e411939dfcaba6178a3bb4823474 OK
2024/11/28 04:01:51 DEBUG : both8: md5 = fa014daa0ae10219ab719e964936b29c OK
2024/11/28 04:01:52 DEBUG : only8: md5 = 943198b56574b7f95f67a8ebe730bf7f OK
2024/11/28 04:01:54 DEBUG : both9: md5 = afd8ea7bce4827777dcca3d6966a561c OK
2024/11/28 04:01:55 DEBUG : only9: md5 = 6502ef6c672418ee5e26c005345a9dd0 OK
2024/11/28 04:01:57 DEBUG : both10: md5 = 153ca82347d333a7b31a950882efd95b OK
2024/11/28 04:01:59 DEBUG : only10: md5 = c2fb351bf4b0a0243b8a2df9f3321599 OK
2024/11/28 04:02:01 DEBUG : both11: md5 = 87286fdc1cbb07268b10ed39884b2217 OK
2024/11/28 04:02:02 DEBUG : only11: md5 = 6d1ac8765816d8f597f6ce577f2ff2fb OK
2024/11/28 04:02:04 DEBUG : both12: md5 = 7556ccd1785fe213e964b88a19c5c769 OK
2024/11/28 04:02:06 DEBUG : only12: md5 = a42dda673e96a619791ee1f4dbf245a2 OK
2024/11/28 04:02:07 DEBUG : both13: md5 = 107fd0cdc406b8ee54248bb2555c3068 OK
2024/11/28 04:02:09 DEBUG : only13: md5 = facf64022bb3b78c6958ce3bee3eced3 OK
2024/11/28 04:02:11 DEBUG : both14: md5 = b70583747fd6f3b44c8d01f6c0f3e43a OK
2024/11/28 04:02:12 DEBUG : only14: md5 = fab60f1a4fcc6039b0ceeee69d7638c3 OK
2024/11/28 04:02:14 DEBUG : both15: md5 = 03fc21928924b3c928eb303214e20a89 OK
2024/11/28 04:02:16 DEBUG : only15: md5 = 2a82394295984101fbf0ff2c27c3769a OK
2024/11/28 04:02:17 DEBUG : both16: md5 = 88fd33b5af4aa95dba24e55575a9da15 OK
2024/11/28 04:02:19 DEBUG : only16: md5 = 5fe038c6680b9b7fa81cec1da88e76cb OK
2024/11/28 04:02:20 DEBUG : both17: md5 = ddc892250adead206ec5bd4d7d719adb OK
2024/11/28 04:02:22 DEBUG : only17: md5 = 9d22c5deae7fa41911ff6964393f5224 OK
2024/11/28 04:02:24 DEBUG : both18: md5 = 0dc315dfe3a03eaabd7e3823ff064f5f OK
2024/11/28 04:02:26 DEBUG : only18: md5 = 35bba5a1bd1f57d28c460da45039bc84 OK
2024/11/28 04:02:27 DEBUG : both19: md5 = 50a1d38387272d6dc4611948f3e39970 OK
2024/11/28 04:02:29 DEBUG : only19: md5 = 71219af5412dbb283903d595b7945a7e OK
2024/11/28 04:02:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for checks to finish
2024/11/28 04:02:29 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both1: Unchanged skipping
2024/11/28 04:02:29 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both12: Unchanged skipping
2024/11/28 04:02:29 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both13: Unchanged skipping
2024/11/28 04:02:29 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both14: Unchanged skipping
2024/11/28 04:02:29 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both0: Unchanged skipping
2024/11/28 04:02:29 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both16: Unchanged skipping
2024/11/28 04:02:29 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both11: Unchanged skipping
2024/11/28 04:02:29 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both10: Unchanged skipping
2024/11/28 04:02:29 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both15: Unchanged skipping
2024/11/28 04:02:29 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both17: Unchanged skipping
2024/11/28 04:02:29 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both3: Unchanged skipping
2024/11/28 04:02:29 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both18: Unchanged skipping
2024/11/28 04:02:29 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both5: Unchanged skipping
2024/11/28 04:02:29 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both6: Unchanged skipping
2024/11/28 04:02:29 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both7: Unchanged skipping
2024/11/28 04:02:29 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both8: Unchanged skipping
2024/11/28 04:02:29 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 04:02:29 DEBUG : both9: Unchanged skipping
2024/11/28 04:02:29 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : both19: Unchanged skipping
2024/11/28 04:02:29 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : both2: Unchanged skipping
2024/11/28 04:02:29 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : both4: Unchanged skipping
2024/11/28 04:02:29 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2024/11/28 04:02:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Waiting for transfers to finish
2024/11/28 04:02:31 DEBUG : only13: md5 = dae8f042b7a174194d097a1ebf48d951 OK
2024/11/28 04:02:31 INFO  : only13: Copied (replaced existing)
2024/11/28 04:02:31 DEBUG : only11: md5 = 44d25ef67a41f2c8432c78731b0b9735 OK
2024/11/28 04:02:31 INFO  : only11: Copied (replaced existing)
2024/11/28 04:02:31 DEBUG : only14: md5 = 300fc0120f493d66f5360033e36feeaa OK
2024/11/28 04:02:31 INFO  : only14: Copied (replaced existing)
2024/11/28 04:02:31 DEBUG : only0: md5 = 8a574e08be65fb82c8d6c1499947b792 OK
2024/11/28 04:02:31 INFO  : only0: Copied (replaced existing)
2024/11/28 04:02:32 DEBUG : only15: md5 = 16ebffeb7b33c2be4f4f7ccba949fec2 OK
2024/11/28 04:02:32 INFO  : only15: Copied (replaced existing)
2024/11/28 04:02:32 DEBUG : only16: md5 = 27e21417bbdda33ee15ac44df3dd1780 OK
2024/11/28 04:02:32 INFO  : only16: Copied (replaced existing)
2024/11/28 04:02:32 DEBUG : only17: md5 = 79643ebbfccf54c88c869b654ec273d4 OK
2024/11/28 04:02:32 INFO  : only17: Copied (replaced existing)
2024/11/28 04:02:32 DEBUG : only18: md5 = fc0924ada5b11a6d0560ff78e72e659a OK
2024/11/28 04:02:32 INFO  : only18: Copied (replaced existing)
2024/11/28 04:02:33 DEBUG : only12: md5 = db451a734e21e533ae9e91466fb4c3f7 OK
2024/11/28 04:02:33 INFO  : only12: Copied (replaced existing)
2024/11/28 04:02:33 DEBUG : only19: md5 = 65c80b336172cd8ddd12929ffdc8e477 OK
2024/11/28 04:02:33 INFO  : only19: Copied (replaced existing)
2024/11/28 04:02:34 DEBUG : only10: md5 = ca01b98c46ba97b9c298ee1a914b3535 OK
2024/11/28 04:02:34 INFO  : only10: Copied (replaced existing)
2024/11/28 04:02:34 DEBUG : only3: md5 = dc7026f5455a6d2f9caa0a5f43540f8e OK
2024/11/28 04:02:34 INFO  : only3: Copied (replaced existing)
2024/11/28 04:02:35 DEBUG : only1: md5 = 16f0bce834e0c22f69a6d6b4dc0d8c91 OK
2024/11/28 04:02:35 INFO  : only1: Copied (replaced existing)
2024/11/28 04:02:35 DEBUG : only5: md5 = 4a5424c195a8331c56b34deb8dd123cc OK
2024/11/28 04:02:35 INFO  : only5: Copied (replaced existing)
2024/11/28 04:02:35 DEBUG : only7: md5 = 750e039dc40b8174211a5f6160036f1a OK
2024/11/28 04:02:35 INFO  : only7: Copied (replaced existing)
2024/11/28 04:02:35 DEBUG : only4: md5 = dfdad956d4658cdae70b360bd1e7ecac OK
2024/11/28 04:02:35 INFO  : only4: Copied (replaced existing)
2024/11/28 04:02:36 DEBUG : only9: md5 = d5d9160636c5ce67de173071dba1d0e3 OK
2024/11/28 04:02:36 INFO  : only9: Copied (replaced existing)
2024/11/28 04:02:36 DEBUG : only6: md5 = cecc6de19921a948a1a61ee491382f73 OK
2024/11/28 04:02:36 INFO  : only6: Copied (replaced existing)
2024/11/28 04:02:36 DEBUG : only2: md5 = 5ed83f6b47a6e512f77778318cc5ec60 OK
2024/11/28 04:02:36 INFO  : only2: Copied (replaced existing)
2024/11/28 04:02:37 DEBUG : only8: md5 = bc0dc527488353f5c892c8e94ad2771c OK
2024/11/28 04:02:37 INFO  : only8: Copied (replaced existing)
2024/11/28 04:02:37 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (99.06s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 04:03:01 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 04:03:01 DEBUG : sub dir: Making directory with metadata
2024/11/28 04:03:02 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 04:03:23 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/28 04:03:23 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/28 04:03:23 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 04:03:23 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 04:03:37 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2024/11/28 04:03:38 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/28 04:03:39 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/11/28 04:03:39 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/11/28 04:03:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 04:03:41 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 04:03:42 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 04:03:43 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 04:03:43 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/28 04:03:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/11/28 04:03:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 04:03:45 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (46.09s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 04:03:47 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 04:03:47 DEBUG : sub dir: Making directory with metadata
2024/11/28 04:03:48 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 04:04:13 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/28 04:04:14 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/28 04:04:14 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 04:04:14 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho'", Local "Local file system at /tmp/rclone317814031", Modify Window "1ms"
2024/11/28 04:04:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/28 04:04:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/11/28 04:04:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/11/28 04:04:29 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 04:04:30 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 04:04:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 04:04:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 04:04:32 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/28 04:04:33 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/11/28 04:04:33 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 04:04:34 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (49.34s)
PASS
2024/11/28 04:04:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pohiror7duho': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 17m52.334670024s (try 1/5)