"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5)
2024/11/05 02:11:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco"
2024/11/05 02:11:56 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/11/05 02:11:56 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0"
2024/11/05 02:11:57 DEBUG : Creating backend with remote "/tmp/rclone770401715"
=== RUN   TestPipe
--- PASS: TestPipe (0.00s)
=== RUN   TestPipeConcurrent
--- PASS: TestPipeConcurrent (0.03s)
=== RUN   TestPipeOrderBy
=== RUN   TestPipeOrderBy/#00
=== RUN   TestPipeOrderBy/size
=== RUN   TestPipeOrderBy/name
=== RUN   TestPipeOrderBy/modtime
=== RUN   TestPipeOrderBy/size,ascending
=== RUN   TestPipeOrderBy/name,asc
=== RUN   TestPipeOrderBy/modtime,ascending
=== RUN   TestPipeOrderBy/size,descending
=== RUN   TestPipeOrderBy/name,desc
=== RUN   TestPipeOrderBy/modtime,descending
=== RUN   TestPipeOrderBy/size,mixed,50
=== RUN   TestPipeOrderBy/size,mixed,51
--- PASS: TestPipeOrderBy (0.00s)
    --- PASS: TestPipeOrderBy/#00 (0.00s)
    --- PASS: TestPipeOrderBy/size (0.00s)
    --- PASS: TestPipeOrderBy/name (0.00s)
    --- PASS: TestPipeOrderBy/modtime (0.00s)
    --- PASS: TestPipeOrderBy/size,ascending (0.00s)
    --- PASS: TestPipeOrderBy/name,asc (0.00s)
    --- PASS: TestPipeOrderBy/modtime,ascending (0.00s)
    --- PASS: TestPipeOrderBy/size,descending (0.00s)
    --- PASS: TestPipeOrderBy/name,desc (0.00s)
    --- PASS: TestPipeOrderBy/modtime,descending (0.00s)
    --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s)
    --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s)
=== RUN   TestNewLess
=== RUN   TestNewLess/blankOK
=== RUN   TestNewLess/tooManyParts
=== RUN   TestNewLess/tooManyParts2
=== RUN   TestNewLess/badMixed
=== RUN   TestNewLess/unknownComparison
=== RUN   TestNewLess/unknownSortDirection
=== RUN   TestNewLess/size
=== RUN   TestNewLess/name
=== RUN   TestNewLess/modtime
=== RUN   TestNewLess/size,ascending
=== RUN   TestNewLess/name,asc
=== RUN   TestNewLess/modtime,ascending
=== RUN   TestNewLess/size,descending
=== RUN   TestNewLess/name,desc
=== RUN   TestNewLess/modtime,descending
=== RUN   TestNewLess/modtime,mixed
=== RUN   TestNewLess/modtime,mixed,30
--- PASS: TestNewLess (0.00s)
    --- PASS: TestNewLess/blankOK (0.00s)
    --- PASS: TestNewLess/tooManyParts (0.00s)
    --- PASS: TestNewLess/tooManyParts2 (0.00s)
    --- PASS: TestNewLess/badMixed (0.00s)
    --- PASS: TestNewLess/unknownComparison (0.00s)
    --- PASS: TestNewLess/unknownSortDirection (0.00s)
    --- PASS: TestNewLess/size (0.00s)
    --- PASS: TestNewLess/name (0.00s)
    --- PASS: TestNewLess/modtime (0.00s)
    --- PASS: TestNewLess/size,ascending (0.00s)
    --- PASS: TestNewLess/name,asc (0.00s)
    --- PASS: TestNewLess/modtime,ascending (0.00s)
    --- PASS: TestNewLess/size,descending (0.00s)
    --- PASS: TestNewLess/name,desc (0.00s)
    --- PASS: TestNewLess/modtime,descending (0.00s)
    --- PASS: TestNewLess/modtime,mixed (0.00s)
    --- PASS: TestNewLess/modtime,mixed,30 (0.00s)
=== RUN   TestRcCopy
    rc_test.go:16: Skipping test on non local remote
--- SKIP: TestRcCopy (0.00s)
=== RUN   TestRcMove
    rc_test.go:16: Skipping test on non local remote
--- SKIP: TestRcMove (0.00s)
=== RUN   TestRcSync
    rc_test.go:16: Skipping test on non local remote
--- SKIP: TestRcSync (0.00s)
=== RUN   TestCopyWithDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:11:59 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/05 02:11:59 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/05 02:11:59 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2024/11/05 02:11:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:11:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:11:59 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.70s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:12:00 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/05 02:12:00 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/05 02:12:00 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/05 02:12:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:12:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:12:03 DEBUG : sub dir/hello world: md5 = 4b57c93e89bc90fc3aff2762ef47209d OK
2024/11/05 02:12:03 INFO  : sub dir/hello world: Copied (new)
2024/11/05 02:12:04 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:12:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (7.84s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:12:08 DEBUG : metadata sub dir: Making directory with metadata
2024/11/05 02:12:08 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/05 02:12:08 DEBUG : empty metadata sub dir: Making directory with metadata
2024/11/05 02:12:08 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/05 02:12:08 DEBUG : Local file system at /tmp/rclone770401715: File to upload is small (21 bytes), uploading instead of streaming
2024/11/05 02:12:08 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/11/05 02:12:08 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/11/05 02:12:08 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/11/05 02:12:08 DEBUG : Google drive root 'crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0': Skipping btime metadata as can't update it on an existing file: 2024-11-05T02:12:08.31597146Z
2024/11/05 02:12:09 INFO  : empty metadata sub dir: Updated directory metadata
2024/11/05 02:12:10 DEBUG : Google drive root 'crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0': Skipping btime metadata as can't update it on an existing file: 2024-11-05T02:12:08.31597146Z
2024/11/05 02:12:11 INFO  : metadata sub dir: Updated directory metadata
2024/11/05 02:12:11 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/11/05 02:12:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:12:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:12:12 DEBUG : metadata sub dir/hello metadata world: md5 = cff03ece40ba1cab30d0e781fd2d2c65 OK
2024/11/05 02:12:12 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:12:16 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (10.28s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:12:18 DEBUG : metadata sub dir: Making directory with metadata
2024/11/05 02:12:18 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/05 02:12:18 DEBUG : empty metadata sub dir: Making directory with metadata
2024/11/05 02:12:18 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/05 02:12:18 DEBUG : Local file system at /tmp/rclone770401715: File to upload is small (21 bytes), uploading instead of streaming
2024/11/05 02:12:18 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/11/05 02:12:18 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/11/05 02:12:18 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/11/05 02:12:18 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2024/11/05 02:12:18 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2024/11/05 02:12:18 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/11/05 02:12:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:12:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:12:21 DEBUG : metadata sub dir/hello metadata world: md5 = 34831c74fe062821ed2b0f7311de749e OK
2024/11/05 02:12:21 INFO  : metadata sub dir/hello metadata world: Copied (new)
2024/11/05 02:12:21 DEBUG : Google drive root 'crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0': Skipping btime metadata as can't update it on an existing file: 2024-11-05T02:12:18.595910854Z
2024/11/05 02:12:22 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:12:25 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (8.67s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:12:27 DEBUG : Creating backend with remote "/non-existing"
2024/11/05 02:12:27 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2024/11/05 02:12:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:12:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.26s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:12:28 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/05 02:12:28 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/05 02:12:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:12:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:12:31 DEBUG : sub dir/hello world: md5 = e906552791062cfafc8bf0a2c2d5fb18 OK
2024/11/05 02:12:31 INFO  : sub dir/hello world: Copied (new)
2024/11/05 02:12:32 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:12:34 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (7.65s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:12:36 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Running all checks before starting transfers
2024/11/05 02:12:36 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/05 02:12:36 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/05 02:12:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:12:36 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Checks finished, now starting transfers
2024/11/05 02:12:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:12:39 DEBUG : sub dir/hello world: md5 = e225c5d1dfef773dd0b08df60153c3ad OK
2024/11/05 02:12:39 INFO  : sub dir/hello world: Copied (new)
2024/11/05 02:12:40 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:12:42 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (7.62s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:12:43 ERROR : Ignoring --no-traverse with sync
2024/11/05 02:12:44 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/05 02:12:44 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/05 02:12:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:12:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:12:47 DEBUG : sub dir/hello world: md5 = cb4223e3f763e5635bbf06661ea14103 OK
2024/11/05 02:12:47 INFO  : sub dir/hello world: Copied (new)
2024/11/05 02:12:47 DEBUG : Waiting for deletions to finish
2024/11/05 02:12:47 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:12:49 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (7.42s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:12:51 DEBUG : hello world2: Need to transfer - File not found at Destination
2024/11/05 02:12:51 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/05 02:12:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:12:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:12:53 DEBUG : hello world2: md5 = 3a49d83a2c87cb4fe9777158cb746e22 OK
2024/11/05 02:12:53 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestCopyWithDepth (4.36s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:12:55 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/05 02:12:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:12:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:12:57 DEBUG : potato2: md5 = 6052d1a5321058ae745fee948333fa38 OK
2024/11/05 02:12:57 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.90s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:12:59 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/05 02:12:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:12:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:13:01 DEBUG : potato2: md5 = e677b6bda5441f81ed2786a96558cc80 OK
2024/11/05 02:13:01 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.97s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:13:03 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/05 02:13:03 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/05 02:13:03 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/05 02:13:03 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/05 02:13:03 DEBUG : sub dir: Making directory with metadata
2024/11/05 02:13:04 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/05 02:13:04 DEBUG : sub dir2: Making directory with metadata
2024/11/05 02:13:06 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/05 02:13:06 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/05 02:13:06 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/05 02:13:07 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/05 02:13:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:13:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:13:08 DEBUG : sub dir/hello world: md5 = 58cf3ab3d214b5392aee84a827f496b5 OK
2024/11/05 02:13:08 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:13:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2024/11/05 02:13:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (11.58s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:13:15 DEBUG : sub dir2: Making directory
2024/11/05 02:13:15 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/05 02:13:15 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/05 02:13:15 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/05 02:13:15 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/05 02:13:15 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/05 02:13:15 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2024/11/05 02:13:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:13:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:13:18 DEBUG : sub dir/hello world: md5 = c582b42240e7e9e3f2d521c193ee1fff OK
2024/11/05 02:13:18 INFO  : sub dir/hello world: Copied (new)
2024/11/05 02:13:18 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/05 02:13:21 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (7.02s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:13:22 DEBUG : sub dir2: Making directory with metadata
2024/11/05 02:13:22 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/05 02:13:22 DEBUG : sub dir: Making directory with metadata
2024/11/05 02:13:23 INFO  : sub dir: Made directory with metadata (mtime=2024-11-05T02:13:22.047536731Z)
2024/11/05 02:13:23 DEBUG : sub dir2: Making directory with metadata
2024/11/05 02:13:25 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/05 02:13:25 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/05 02:13:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:13:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:13:27 DEBUG : sub dir/hello world: md5 = ee1c8e574a1b89b9b70e8b6ab7fabc07 OK
2024/11/05 02:13:27 INFO  : sub dir/hello world: Copied (new)
2024/11/05 02:13:27 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:13:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (10.12s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:13:32 DEBUG : sub dir no update dir modtime: Making directory with metadata
2024/11/05 02:13:32 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/05 02:13:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:13:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:13:34 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (5.03s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:13:37 DEBUG : sub dir2: Making directory
2024/11/05 02:13:37 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/05 02:13:37 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/05 02:13:37 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/05 02:13:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:13:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:13:40 DEBUG : sub dir/hello world: md5 = d200e1da12df2effc57e8dffc8131aae OK
2024/11/05 02:13:40 INFO  : sub dir/hello world: Copied (new)
2024/11/05 02:13:40 INFO  : sub dir/hello world: Deleted
2024/11/05 02:13:40 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/05 02:13:42 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (6.71s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:13:43 DEBUG : sub dir2: Making directory with metadata
2024/11/05 02:13:43 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/05 02:13:43 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/05 02:13:44 DEBUG : sub dir: Making directory with metadata
2024/11/05 02:13:45 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/05 02:13:45 DEBUG : sub dir2: Making directory with metadata
2024/11/05 02:13:46 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/05 02:13:46 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/05 02:13:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:13:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:13:48 DEBUG : sub dir/hello world: md5 = d3fd818c3c8409c1215e9426697ff7ad OK
2024/11/05 02:13:48 INFO  : sub dir/hello world: Copied (new)
2024/11/05 02:13:48 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:13:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (9.54s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", 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-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:13:53 DEBUG : sub dir2: Making directory
2024/11/05 02:13:54 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/05 02:13:54 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/05 02:13:54 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/05 02:13:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:13:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:13:57 DEBUG : sub dir/hello world: md5 = 33b2075da9ff631b86bb819fd244641e OK
2024/11/05 02:13:57 INFO  : sub dir/hello world: Copied (new)
2024/11/05 02:13:57 DEBUG : Waiting for deletions to finish
2024/11/05 02:13:57 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/05 02:13:59 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (6.91s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:14:03 DEBUG : sub dir/hello world: md5 = 5d2dce48f314bedfdbfa87aaa658e5a4 OK
2024/11/05 02:14:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tosayuc2covo"
2024/11/05 02:14:04 DEBUG : Creating backend with remote "TestDrive:crypt/tiovartbbnh6jq6i5ltvrquvdjiu1m3qk2jcj0mmofm3k89iiun0"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco' -> Encrypted drive 'TestCryptDrive:rclone-test-tosayuc2covo'
2024/11/05 02:14:05 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/05 02:14:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/05 02:14:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tosayuc2covo': Waiting for checks to finish
2024/11/05 02:14:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tosayuc2covo': Waiting for transfers to finish
2024/11/05 02:14:09 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/05 02:14:10 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:14:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tosayuc2covo': Purge remote
2024/11/05 02:14:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (14.10s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:14:18 DEBUG : sub dir/hello world: md5 = 2437adc11e00f501083b4b66f0b24e0d OK
2024/11/05 02:14:19 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/05 02:14:19 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/05 02:14:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:14:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:14:20 DEBUG : sub dir/hello world: md5 = f3a8ef5b1d41de9ccedcd36f64e14e1b OK
2024/11/05 02:14:20 INFO  : sub dir/hello world: Copied (replaced existing)
2024/11/05 02:14:21 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:14:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (10.03s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:14:27 DEBUG : sub dir/hello world: md5 = e638584055cb0f5a6eae6c8d9094d2cb OK
2024/11/05 02:14:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kifofab7puyu"
2024/11/05 02:14:28 DEBUG : Creating backend with remote "TestDrive:crypt/5s48h1js7pu6408mmo3bfnf5go1kkuruc0tq4l9k9t7f5s1fl9q0"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco' -> Encrypted drive 'TestCryptDrive:rclone-test-kifofab7puyu'
2024/11/05 02:14:30 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/05 02:14:30 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/05 02:14:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kifofab7puyu': Waiting for checks to finish
2024/11/05 02:14:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kifofab7puyu': Waiting for transfers to finish
2024/11/05 02:14:33 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/05 02:14:34 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:14:36 DEBUG : sub dir/hello world: md5 = 5947fc995a35d722c2006653cf95391f OK
2024/11/05 02:14:37 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/05 02:14:37 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/05 02:14:37 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/05 02:14:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kifofab7puyu': Waiting for checks to finish
2024/11/05 02:14:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kifofab7puyu': Waiting for transfers to finish
2024/11/05 02:14:40 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/05 02:14:40 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:14:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kifofab7puyu': Purge remote
2024/11/05 02:14:43 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (20.54s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:14:48 DEBUG : sub dir/hello world: md5 = 0a3d4e2e4a400103eadc87425c13a272 OK
2024/11/05 02:14:49 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/05 02:14:49 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/05 02:14:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:14:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:14:51 DEBUG : sub dir/hello world: md5 = c3e677d8809828e4d77a0d218df563f1 OK
2024/11/05 02:14:51 INFO  : sub dir/hello world: Copied (replaced existing)
2024/11/05 02:14:51 INFO  : sub dir/hello world: Deleted
2024/11/05 02:14:51 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:14:53 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (9.73s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:14:58 DEBUG : sub dir/hello world: md5 = edf06f82f93138646867c0696cee07ff OK
2024/11/05 02:14:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wibomas5buzi"
2024/11/05 02:14:58 DEBUG : Creating backend with remote "TestDrive:crypt/a57vnf2klcl92dsrfe0la6j8ahsv91vt2dao1vhticr01cl69pl0"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco' -> Encrypted drive 'TestCryptDrive:rclone-test-wibomas5buzi'
2024/11/05 02:15:00 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/05 02:15:00 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/05 02:15:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wibomas5buzi': Waiting for checks to finish
2024/11/05 02:15:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wibomas5buzi': Waiting for transfers to finish
2024/11/05 02:15:04 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/05 02:15:04 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:15:06 DEBUG : sub dir/hello world: md5 = 046837bf9f78e844ad20ebbbbf5042da OK
2024/11/05 02:15:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wibomas5buzi': Using server-side directory move
2024/11/05 02:15:07 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-wibomas5buzi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/05 02:15:07 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/05 02:15:07 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/05 02:15:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wibomas5buzi': Waiting for checks to finish
2024/11/05 02:15:07 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/05 02:15:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wibomas5buzi': Waiting for transfers to finish
2024/11/05 02:15:08 INFO  : sub dir/hello world: Deleted
2024/11/05 02:15:09 INFO  : sub dir/hello world: Moved (server-side)
2024/11/05 02:15:10 INFO  : sub dir: Set directory modification time (using SetModTime)
2024/11/05 02:15:13 DEBUG : sub dir/hello world: md5 = b444831f5da8ab845101363826c69c12 OK
2024/11/05 02:15:14 DEBUG : testing file moves
2024/11/05 02:15:14 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/05 02:15:14 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/05 02:15:14 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2024/11/05 02:15:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wibomas5buzi': Waiting for checks to finish
2024/11/05 02:15:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wibomas5buzi': Waiting for transfers to finish
2024/11/05 02:15:15 INFO  : sub dir/hello world: Deleted
2024/11/05 02:15:16 INFO  : sub dir/hello world: Moved (server-side)
2024/11/05 02:15:16 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:15:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wibomas5buzi': Purge remote
--- PASS: TestServerSideMoveOverSelf (26.18s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:15:24 DEBUG : sub dir/hello world: md5 = 157d1b280957005a177e5c01d5e49988 OK
2024/11/05 02:15:24 ERROR : : error listing: directory not found
2024/11/05 02:15:24 DEBUG : Local file system at /tmp/rclone770401715: Making directory
2024/11/05 02:15:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:15:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:15:27 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (7.52s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:15:31 DEBUG : sub dir/hello world: md5 = 7eb967297422e48861f0e2e6fc67c65d OK
2024/11/05 02:15:32 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/05 02:15:32 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/05 02:15:32 DEBUG : Local file system at /tmp/rclone770401715: Waiting for checks to finish
2024/11/05 02:15:32 DEBUG : Local file system at /tmp/rclone770401715: Waiting for transfers to finish
2024/11/05 02:15:33 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2024/11/05 02:15:33 INFO  : sub dir/hello world: Copied (new)
2024/11/05 02:15:33 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:15:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (7.81s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:15:36 DEBUG : check sum: Need to transfer - File not found at Destination
2024/11/05 02:15:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:15:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:15:38 DEBUG : check sum: md5 = c4c3bcb6bb7b8df247dfdf894afc5c60 OK
2024/11/05 02:15:38 INFO  : check sum: Copied (new)
2024/11/05 02:15:38 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:15:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:15:39 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2024/11/05 02:15:39 DEBUG : check sum: Size of src and dst objects identical
2024/11/05 02:15:39 DEBUG : check sum: Unchanged skipping
2024/11/05 02:15:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:15:39 DEBUG : Waiting for deletions to finish
2024/11/05 02:15:39 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (4.99s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:15:41 DEBUG : sizeonly: Need to transfer - File not found at Destination
2024/11/05 02:15:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:15:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:15:43 DEBUG : sizeonly: md5 = 3db094878c511413001a86e35d40f6d0 OK
2024/11/05 02:15:43 INFO  : sizeonly: Copied (new)
2024/11/05 02:15:43 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:15:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:15:44 DEBUG : sizeonly: Sizes identical
2024/11/05 02:15:44 DEBUG : sizeonly: Unchanged skipping
2024/11/05 02:15:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:15:44 DEBUG : Waiting for deletions to finish
2024/11/05 02:15:44 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (4.95s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:15:46 DEBUG : ignore-size: Need to transfer - File not found at Destination
2024/11/05 02:15:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:15:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:15:48 DEBUG : ignore-size: md5 = 55de9622d4d79ef6fe95ac2c4264f7ac OK
2024/11/05 02:15:48 INFO  : ignore-size: Copied (new)
2024/11/05 02:15:48 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:15:49 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:15:49 DEBUG : ignore-size: Unchanged skipping
2024/11/05 02:15:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:15:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:15:49 DEBUG : Waiting for deletions to finish
2024/11/05 02:15:49 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (4.87s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:15:53 DEBUG : existing: md5 = 634f5e20fcaf9ebf24096f44a1d0807f OK
2024/11/05 02:15:53 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:15:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:15:53 DEBUG : existing: Unchanged skipping
2024/11/05 02:15:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:15:53 DEBUG : Waiting for deletions to finish
2024/11/05 02:15:53 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:15:54 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2024/11/05 02:15:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:15:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:15:55 DEBUG : existing: md5 = 5138cd56d955878e1ccb58f015faac80 OK
2024/11/05 02:15:55 INFO  : existing: Copied (replaced existing)
2024/11/05 02:15:55 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (6.56s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:15:58 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/05 02:15:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:15:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:16:00 DEBUG : existing: md5 = f648db6f89857218b0d09bfa06ee90ae OK
2024/11/05 02:16:00 INFO  : existing: Copied (new)
2024/11/05 02:16:00 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:16:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:16:00 DEBUG : existing: Destination exists, skipping
2024/11/05 02:16:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:16:00 DEBUG : Waiting for deletions to finish
2024/11/05 02:16:00 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (4.93s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:16:06 DEBUG : b/potato: md5 = 01c3839d07f5782fe9d0f505b586605c OK
2024/11/05 02:16:08 DEBUG : c/non empty space: md5 = 2dad4083b0c90ed2c7eaa0bdd2548f05 OK
2024/11/05 02:16:08 DEBUG : d: Making directory
2024/11/05 02:16:11 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/05 02:16:11 DEBUG : Added delayed dir = "c", newDst=c
2024/11/05 02:16:11 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:16:11 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/05 02:16:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:16:11 DEBUG : c/non empty space: Unchanged skipping
2024/11/05 02:16:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:16:14 DEBUG : a/potato2: md5 = cfe6792c0206a83874869930159f680f OK
2024/11/05 02:16:14 INFO  : a/potato2: Copied (new)
2024/11/05 02:16:14 DEBUG : Waiting for deletions to finish
2024/11/05 02:16:14 INFO  : b/potato: Deleted
2024/11/05 02:16:15 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/05 02:16:15 INFO  : d: Removing directory
2024/11/05 02:16:16 INFO  : b: Removing directory
2024/11/05 02:16:16 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/05 02:16:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:16:20 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/05 02:16:21 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (19.47s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:16:24 DEBUG : empty space: md5 = e2e668a116950337be34b20cc6a3595a OK
2024/11/05 02:16:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:16:24 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/05 02:16:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:16:24 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2024/11/05 02:16:24 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:16:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:16:25 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/05 02:16:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:16:27 DEBUG : empty space: md5 = cb2b4cb077695e5234e4a9c5bfb419d9 OK
2024/11/05 02:16:27 INFO  : empty space: Copied (replaced existing)
2024/11/05 02:16:27 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (7.06s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.49s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:16:32 DEBUG : foo: md5 = 5e8ebcaf7e4453bbb08b0cf5e8478e8e OK
2024/11/05 02:16:32 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/05 02:16:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:16:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:16:34 DEBUG : foo: md5 = 1781be725dda006341f7f0f275800e34 OK
2024/11/05 02:16:34 INFO  : foo: Copied (replaced existing)
2024/11/05 02:16:34 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (5.83s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:16:37 DEBUG : empty space: md5 = d79f7a777bbc43ee79daa106ee760ff7 OK
2024/11/05 02:16:38 DEBUG : potato: Need to transfer - File not found at Destination
2024/11/05 02:16:38 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:16:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:16:38 DEBUG : empty space: Unchanged skipping
2024/11/05 02:16:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:16:40 DEBUG : potato: md5 = 1ab03ee60dcff4c56b328afac608b94a OK
2024/11/05 02:16:40 INFO  : potato: Copied (new)
2024/11/05 02:16:40 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (6.78s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:16:44 DEBUG : potato: md5 = 69be28fe21fd785a066b3a45f9126dcc OK
2024/11/05 02:16:45 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2024/11/05 02:16:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:16:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:16:46 DEBUG : potato: md5 = 4dbc80add9211dca82ab68a547e20ae2 OK
2024/11/05 02:16:46 INFO  : potato: Copied (replaced existing)
2024/11/05 02:16:46 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (5.85s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:16:50 DEBUG : potato: md5 = 4fc92f8e9acf443c45c12b55416ea0e3 OK
2024/11/05 02:16:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:16:50 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/05 02:16:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:16:52 DEBUG : potato: md5 = 1407b86140ac64af5e1eb749987082b5 OK
2024/11/05 02:16:52 INFO  : potato: Copied (replaced existing)
2024/11/05 02:16:52 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (5.74s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:16:56 DEBUG : potato: md5 = f230d7c2e444972a2da52b8b0fef3b85 OK
2024/11/05 02:16:57 DEBUG : empty space: md5 = 5b1ebf1b3ae230194e43c5a30bd9b348 OK
2024/11/05 02:16:58 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/05 02:16:58 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2024/11/05 02:16:58 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:16:58 DEBUG : empty space: Unchanged skipping
2024/11/05 02:16:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:16:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:16:58 DEBUG : Waiting for deletions to finish
2024/11/05 02:16:58 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (6.31s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:17:02 DEBUG : potato: md5 = 4e93016e95511067d91020eeae31e006 OK
2024/11/05 02:17:04 DEBUG : empty space: md5 = 72747eb91171239e776839e7f6987ad4 OK
2024/11/05 02:17:05 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/05 02:17:05 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:17:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:17:05 DEBUG : empty space: Unchanged skipping
2024/11/05 02:17:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:17:06 DEBUG : potato2: md5 = 404e38a42ad3c605e202628d3a92676e OK
2024/11/05 02:17:06 INFO  : potato2: Copied (new)
2024/11/05 02:17:06 DEBUG : Waiting for deletions to finish
2024/11/05 02:17:07 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (9.82s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:17:13 DEBUG : b/potato: md5 = ede26b0aad5f68cd71a2cd3918212949 OK
2024/11/05 02:17:16 DEBUG : c/non empty space: md5 = 9bf14efea6f2f02b6de883ac6bf4ac90 OK
2024/11/05 02:17:16 DEBUG : d: Making directory
2024/11/05 02:17:17 DEBUG : d/e: Making directory
2024/11/05 02:17:20 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/05 02:17:20 DEBUG : Added delayed dir = "c", newDst=c
2024/11/05 02:17:20 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:17:20 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/05 02:17:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:17:20 DEBUG : c/non empty space: Unchanged skipping
2024/11/05 02:17:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:17:22 DEBUG : a/potato2: md5 = d87bde207572ec2c409ebc6cbd70317e OK
2024/11/05 02:17:22 INFO  : a/potato2: Copied (new)
2024/11/05 02:17:22 DEBUG : Waiting for deletions to finish
2024/11/05 02:17:23 INFO  : b/potato: Deleted
2024/11/05 02:17:24 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/05 02:17:24 INFO  : d/e: Removing directory
2024/11/05 02:17:25 INFO  : d: Removing directory
2024/11/05 02:17:25 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2024/11/05 02:17:26 INFO  : b: Removing directory
2024/11/05 02:17:26 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/05 02:17:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:17:29 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/05 02:17:30 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (21.66s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:17:35 DEBUG : b/potato: md5 = 07c1e5884bede3f3e85035e564de4eb9 OK
2024/11/05 02:17:38 DEBUG : c/non empty space: md5 = 9f28e938a4074a7648766acdf628bf54 OK
2024/11/05 02:17:38 DEBUG : d: Making directory
2024/11/05 02:17:40 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/05 02:17:40 DEBUG : Added delayed dir = "c", newDst=c
2024/11/05 02:17:40 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:17:40 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/05 02:17:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:17:40 DEBUG : c/non empty space: Unchanged skipping
2024/11/05 02:17:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:17:43 DEBUG : a/potato2: md5 = aba6d562990a66ecceee2069b8801e1d OK
2024/11/05 02:17:43 INFO  : a/potato2: Copied (new)
2024/11/05 02:17:43 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': not deleting files as there were IO errors
2024/11/05 02:17:43 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/05 02:17:43 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:17:47 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/05 02:17:48 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/05 02:17:49 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (19.15s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:17:52 DEBUG : potato: md5 = ab1d28f1ec098f9ab513205e03bb3816 OK
2024/11/05 02:17:54 DEBUG : empty space: md5 = 29f7f4751ddff01f46e2975711c370e1 OK
2024/11/05 02:17:55 DEBUG : Waiting for deletions to finish
2024/11/05 02:17:55 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/05 02:17:55 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:17:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:17:55 DEBUG : empty space: Unchanged skipping
2024/11/05 02:17:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:17:56 INFO  : potato: Deleted
2024/11/05 02:17:57 DEBUG : potato2: md5 = 6f6b53243d024c3e7dfcf6dca873c324 OK
2024/11/05 02:17:57 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (8.74s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:18:01 DEBUG : potato: md5 = e9700aff16e7a585aa56033ea9d2c275 OK
2024/11/05 02:18:03 DEBUG : empty space: md5 = 55503359a70ea547256a2cd30b5f2692 OK
2024/11/05 02:18:03 DEBUG : Waiting for deletions to finish
2024/11/05 02:18:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:18:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:18:04 INFO  : potato: Deleted
2024/11/05 02:18:05 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/05 02:18:05 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:18:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:18:05 DEBUG : empty space: Unchanged skipping
2024/11/05 02:18:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:18:06 DEBUG : potato2: md5 = cc02b3ccf0761dbc875f5a5d5b06dd27 OK
2024/11/05 02:18:06 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (9.59s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:18:11 DEBUG : potato: md5 = 874e2444be54a9ab48746c42a228d05a OK
2024/11/05 02:18:11 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/05 02:18:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:18:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:18:13 DEBUG : potato2: md5 = 136788359715d2a3c87b32bf6a82aab8 OK
2024/11/05 02:18:13 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (7.31s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:18:18 DEBUG : potato2: md5 = 5d84db9821a7268226709727facecd94 OK
2024/11/05 02:18:20 DEBUG : empty space: md5 = 49bfba43b496a6381be1d246d35b4aaf OK
2024/11/05 02:18:20 DEBUG : enormous: Excluded (Size Filter)
2024/11/05 02:18:20 DEBUG : enormous: Excluded
2024/11/05 02:18:20 DEBUG : potato2: Excluded (Size Filter)
2024/11/05 02:18:20 DEBUG : potato2: Excluded
2024/11/05 02:18:21 DEBUG : potato2: Excluded (Size Filter)
2024/11/05 02:18:21 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:18:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:18:21 DEBUG : empty space: Unchanged skipping
2024/11/05 02:18:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:18:21 DEBUG : Waiting for deletions to finish
2024/11/05 02:18:21 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:18:21 DEBUG : enormous: Excluded (Size Filter)
2024/11/05 02:18:21 DEBUG : enormous: Excluded
2024/11/05 02:18:21 DEBUG : potato2: Excluded (Size Filter)
2024/11/05 02:18:21 DEBUG : potato2: Excluded
2024/11/05 02:18:21 DEBUG : potato2: Excluded (Size Filter)
2024/11/05 02:18:21 DEBUG : Local file system at /tmp/rclone770401715: Waiting for checks to finish
2024/11/05 02:18:21 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/11/05 02:18:21 DEBUG : empty space: Unchanged skipping
2024/11/05 02:18:21 DEBUG : Local file system at /tmp/rclone770401715: Waiting for transfers to finish
2024/11/05 02:18:21 DEBUG : Waiting for deletions to finish
2024/11/05 02:18:21 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncWithExclude (7.68s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:18:26 DEBUG : potato2: md5 = da9eb1b4f782e66f81d200b5fe2efa3c OK
2024/11/05 02:18:28 DEBUG : empty space: md5 = 1812cc73084f4d41c3b4ff5b45dc1803 OK
2024/11/05 02:18:29 DEBUG : enormous: md5 = c7754f3de07dfb830292f561b6e051f8 OK
2024/11/05 02:18:30 DEBUG : enormous: Excluded (Size Filter)
2024/11/05 02:18:30 DEBUG : enormous: Excluded
2024/11/05 02:18:30 DEBUG : potato2: Excluded (Size Filter)
2024/11/05 02:18:30 DEBUG : potato2: Excluded
2024/11/05 02:18:30 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:18:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:18:30 DEBUG : empty space: Unchanged skipping
2024/11/05 02:18:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:18:30 DEBUG : Waiting for deletions to finish
2024/11/05 02:18:31 INFO  : enormous: Deleted
2024/11/05 02:18:31 INFO  : potato2: Deleted
2024/11/05 02:18:31 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:18:31 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/11/05 02:18:31 DEBUG : Local file system at /tmp/rclone770401715: Waiting for checks to finish
2024/11/05 02:18:31 DEBUG : empty space: Unchanged skipping
2024/11/05 02:18:31 DEBUG : Local file system at /tmp/rclone770401715: Waiting for transfers to finish
2024/11/05 02:18:31 DEBUG : Waiting for deletions to finish
2024/11/05 02:18:31 INFO  : enormous: Deleted
2024/11/05 02:18:31 INFO  : potato2: Deleted
2024/11/05 02:18:31 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (9.42s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:18:35 DEBUG : one: md5 = a0348671976472e8472b35157570eb64 OK
2024/11/05 02:18:37 DEBUG : two: md5 = f3ad64fc14ae5822960c2a27b864b3fe OK
2024/11/05 02:18:39 DEBUG : three: md5 = 5f462a71452cc502757ddb8c4eef8a22 OK
2024/11/05 02:18:41 DEBUG : four: md5 = 2742d8127961936fe62873c35e66bbba OK
2024/11/05 02:18:41 DEBUG : five: Need to transfer - File not found at Destination
2024/11/05 02:18:41 DEBUG : four: Sizes differ (src 4 vs dst 8)
2024/11/05 02:18:41 DEBUG : one: Destination is newer than source, skipping
2024/11/05 02:18:41 DEBUG : three: Sizes identical
2024/11/05 02:18:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:18:41 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2024/11/05 02:18:41 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2024/11/05 02:18:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:18:43 DEBUG : two: md5 = f3ec8d6eb604bc40cb4fb03d0f7fdf82 OK
2024/11/05 02:18:43 INFO  : two: Copied (replaced existing)
2024/11/05 02:18:43 DEBUG : five: md5 = d4f9c894d5629fdac4fb3346c6e425e5 OK
2024/11/05 02:18:43 INFO  : five: Copied (new)
2024/11/05 02:18:43 DEBUG : four: md5 = 18331a4ffb6b0b80740223a31242063b OK
2024/11/05 02:18:43 INFO  : four: Copied (replaced existing)
2024/11/05 02:18:43 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (13.68s)
=== 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-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2024/11/05 02:18:47 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Ignoring --track-renames as the source and destination do not have a common hash
2024/11/05 02:18:47 DEBUG : potato: Need to transfer - File not found at Destination
2024/11/05 02:18:47 DEBUG : yam: Need to transfer - File not found at Destination
2024/11/05 02:18:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:18:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:18:49 DEBUG : potato: md5 = f6a713044813e9b46bbd32fc2512977e OK
2024/11/05 02:18:49 INFO  : potato: Copied (new)
2024/11/05 02:18:50 DEBUG : yam: md5 = d65cf8533c1b3a37e9d296dc48c68de1 OK
2024/11/05 02:18:50 INFO  : yam: Copied (new)
2024/11/05 02:18:50 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:18:50 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Ignoring --track-renames as the source and destination do not have a common hash
2024/11/05 02:18:50 DEBUG : yaml: Need to transfer - File not found at Destination
2024/11/05 02:18:50 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:18:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:18:50 DEBUG : potato: Unchanged skipping
2024/11/05 02:18:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:18:52 DEBUG : yaml: md5 = 7987c3beca0f2adcc6b8c5feaf3a7f4e OK
2024/11/05 02:18:52 INFO  : yaml: Copied (new)
2024/11/05 02:18:52 DEBUG : Waiting for deletions to finish
2024/11/05 02:18:52 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (8.49s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2024/11/05 02:18:56 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Making map for --track-renames
2024/11/05 02:18:56 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Finished making map for --track-renames
2024/11/05 02:18:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:18:56 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/11/05 02:18:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for renames to finish
2024/11/05 02:18:56 DEBUG : yam: Need to transfer - No matching file found at Destination
2024/11/05 02:18:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:18:58 DEBUG : yam: md5 = a11936f3c5e43d72937fde662492049c OK
2024/11/05 02:18:58 INFO  : yam: Copied (new)
2024/11/05 02:18:58 DEBUG : potato: md5 = 071c0ae38c3d57579d3be2c5508d141b OK
2024/11/05 02:18:58 INFO  : potato: Copied (new)
2024/11/05 02:18:58 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:18:58 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:18:58 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Making map for --track-renames
2024/11/05 02:18:58 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Finished making map for --track-renames
2024/11/05 02:18:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:18:58 DEBUG : potato: Unchanged skipping
2024/11/05 02:18:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for renames to finish
2024/11/05 02:18:59 INFO  : yam: Moved (server-side) to: yaml
2024/11/05 02:18:59 INFO  : yaml: Renamed from "yam"
2024/11/05 02:18:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:18:59 DEBUG : Waiting for deletions to finish
2024/11/05 02:18:59 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (6.65s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2024/11/05 02:19:02 DEBUG : Added delayed dir = "sub", newDst=<nil>
2024/11/05 02:19:02 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Making map for --track-renames
2024/11/05 02:19:02 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Finished making map for --track-renames
2024/11/05 02:19:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:19:02 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/11/05 02:19:02 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2024/11/05 02:19:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for renames to finish
2024/11/05 02:19:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:19:05 DEBUG : potato: md5 = 723dd04e8f3705e0419e55b54ba09c81 OK
2024/11/05 02:19:05 INFO  : potato: Copied (new)
2024/11/05 02:19:06 DEBUG : sub/yam: md5 = 6e8b1cd560e8f6a33fe6e1211db954cb OK
2024/11/05 02:19:06 INFO  : sub/yam: Copied (new)
2024/11/05 02:19:06 DEBUG : Waiting for deletions to finish
2024/11/05 02:19:06 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:19:08 DEBUG : Added delayed dir = "sub", newDst=sub
2024/11/05 02:19:08 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:19:08 DEBUG : potato: Unchanged skipping
2024/11/05 02:19:08 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Making map for --track-renames
2024/11/05 02:19:08 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Finished making map for --track-renames
2024/11/05 02:19:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:19:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for renames to finish
2024/11/05 02:19:09 INFO  : sub/yam: Moved (server-side) to: yam
2024/11/05 02:19:09 INFO  : yam: Renamed from "sub/yam"
2024/11/05 02:19:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:19:09 DEBUG : Waiting for deletions to finish
2024/11/05 02:19:09 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (11.35s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:19:14 DEBUG : Creating backend with remote "/tmp/rclone770401715/dir1"
2024/11/05 02:19:14 DEBUG : Creating backend with remote "/tmp/rclone770401715/dir2"
2024/11/05 02:19:14 DEBUG : Local file system at /tmp/rclone770401715/dir2: Using server-side directory move
2024/11/05 02:19:14 INFO  : Local file system at /tmp/rclone770401715/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/05 02:19:14 DEBUG : file1.txt: Need to transfer - File not found at Destination
2024/11/05 02:19:14 DEBUG : Local file system at /tmp/rclone770401715/dir2: Waiting for checks to finish
2024/11/05 02:19:14 DEBUG : Local file system at /tmp/rclone770401715/dir2: Waiting for transfers to finish
2024/11/05 02:19:14 INFO  : file1.txt: Moved (server-side)
--- PASS: TestServerSideMoveLocal (0.51s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:19:14 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/11/05 02:19:14 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/05 02:19:14 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/05 02:19:14 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/11/05 02:19:14 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/11/05 02:19:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:19:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:19:17 DEBUG : sub dir/hello world: md5 = 9c3641fa7c1f313e6de4d56a059aa96f OK
2024/11/05 02:19:17 INFO  : sub dir/hello world: Copied (new)
2024/11/05 02:19:17 INFO  : sub dir/hello world: Deleted
2024/11/05 02:19:20 DEBUG : nested/sub dir/file: md5 = 91528a184b9695ef45a681f69bc47a67 OK
2024/11/05 02:19:20 INFO  : nested/sub dir/file: Copied (new)
2024/11/05 02:19:20 INFO  : nested/sub dir/file: Deleted
2024/11/05 02:19:20 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/11/05 02:19:21 INFO  : nested: Set directory modification time (using DirSetModTime)
2024/11/05 02:19:21 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/05 02:19:21 INFO  : sub dir: Removing directory
2024/11/05 02:19:21 INFO  : nested/sub dir: Removing directory
2024/11/05 02:19:21 INFO  : nested: Removing directory
2024/11/05 02:19:21 DEBUG : Local file system at /tmp/rclone770401715: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:19:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/05 02:19:25 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/11/05 02:19:26 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (13.56s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:19:28 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/11/05 02:19:28 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/05 02:19:28 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/05 02:19:28 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/11/05 02:19:28 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/11/05 02:19:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:19:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:19:31 DEBUG : sub dir/hello world: md5 = 7006785c69a366aea7f7cb63fbb3ca39 OK
2024/11/05 02:19:31 INFO  : sub dir/hello world: Copied (new)
2024/11/05 02:19:31 INFO  : sub dir/hello world: Deleted
2024/11/05 02:19:33 DEBUG : nested/sub dir/file: md5 = 402945416d6a4b6e6cdaa62436a90bcf OK
2024/11/05 02:19:33 INFO  : nested/sub dir/file: Copied (new)
2024/11/05 02:19:33 INFO  : nested/sub dir/file: Deleted
2024/11/05 02:19:34 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/11/05 02:19:35 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/05 02:19:35 INFO  : nested: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:19:38 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/05 02:19:39 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/11/05 02:19:40 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (13.70s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:19:42 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/05 02:19:42 DEBUG : existing-b: Need to transfer - File not found at Destination
2024/11/05 02:19:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:19:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:19:43 DEBUG : existing-b: md5 = 9d58c9252d35c56dda57a5e11bb94f90 OK
2024/11/05 02:19:43 INFO  : existing-b: Copied (new)
2024/11/05 02:19:43 INFO  : existing-b: Deleted
2024/11/05 02:19:44 DEBUG : existing: md5 = 5d60367567b77216d39831b29b6d63e5 OK
2024/11/05 02:19:44 INFO  : existing: Copied (new)
2024/11/05 02:19:44 INFO  : existing: Deleted
2024/11/05 02:19:44 DEBUG : existing: Destination exists, skipping
2024/11/05 02:19:44 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2024/11/05 02:19:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:19:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:19:44 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (5.38s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:19:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mivekim8wuzo"
2024/11/05 02:19:47 DEBUG : Creating backend with remote "TestDrive:crypt/c92vio8unks7ptg5tcr9jsbg9adng6u9ml9pbhrvf2mbl4gplr60"
2024/11/05 02:19:50 DEBUG : potato2: md5 = 8bc789813a9652aa0dd20ed431f8932a OK
2024/11/05 02:19:52 DEBUG : empty space: md5 = 243d96345dbad4a1675ab7242082f265 OK
2024/11/05 02:19:53 DEBUG : potato3: md5 = 88c4d01622cd8fdca972f00dfc795923 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco' -> Encrypted drive 'TestCryptDrive:rclone-test-mivekim8wuzo'
2024/11/05 02:19:57 DEBUG : empty space: md5 = 08a34f9630b50c0e30026ef1f236f6aa OK
2024/11/05 02:19:58 DEBUG : potato3: md5 = 8ef1b545697645f128a046060524795b OK
2024/11/05 02:19:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mivekim8wuzo': Using server-side directory move
2024/11/05 02:19:59 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-mivekim8wuzo': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/05 02:19:59 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/05 02:19:59 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/11/05 02:19:59 DEBUG : empty space: Unchanged skipping
2024/11/05 02:19:59 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/05 02:19:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mivekim8wuzo': Waiting for checks to finish
2024/11/05 02:20:00 INFO  : empty space: Deleted
2024/11/05 02:20:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mivekim8wuzo': Waiting for transfers to finish
2024/11/05 02:20:00 INFO  : potato3: Deleted
2024/11/05 02:20:00 INFO  : potato2: Moved (server-side)
2024/11/05 02:20:01 INFO  : potato3: Moved (server-side)
2024/11/05 02:20:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xicuwen7neze"
2024/11/05 02:20:01 DEBUG : Creating backend with remote "TestDrive:crypt/ipedvrimi5r6gqa4o6ei76vb0vhsqjm4o6tptls6c26f5prnt08g"
2024/11/05 02:20:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xicuwen7neze': Using server-side directory move
2024/11/05 02:20:03 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-xicuwen7neze': Server side directory move succeeded
2024/11/05 02:20:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xicuwen7neze': Purge remote
2024/11/05 02:20:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mivekim8wuzo': Purge remote
2024/11/05 02:20:05 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (19.07s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:20:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xalesiq5kize"
2024/11/05 02:20:06 DEBUG : Creating backend with remote "TestDrive:crypt/824u6ec7oe4386bdrufcr298kaauuth8igrbvos6rp1a0eclqjp0"
2024/11/05 02:20:09 DEBUG : potato2: md5 = b423fef841e9fb8c6b7139d0f7f10d29 OK
2024/11/05 02:20:11 DEBUG : empty space: md5 = bd7290279bb97ef79c1a43d796c60c38 OK
2024/11/05 02:20:13 DEBUG : potato3: md5 = f73f2ba159c35ec2be2a5d5009037f98 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco' -> Encrypted drive 'TestCryptDrive:rclone-test-xalesiq5kize'
2024/11/05 02:20:16 DEBUG : empty space: md5 = 4bea4274cc2420115aa4c8e25fdf8aa0 OK
2024/11/05 02:20:18 DEBUG : potato3: md5 = 170091b87eb67c72808ca43ed7c6fbe5 OK
2024/11/05 02:20:18 DEBUG : empty space: Excluded (Size Filter)
2024/11/05 02:20:18 DEBUG : empty space: Excluded (Size Filter)
2024/11/05 02:20:18 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/05 02:20:18 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/05 02:20:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xalesiq5kize': Waiting for checks to finish
2024/11/05 02:20:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xalesiq5kize': Waiting for transfers to finish
2024/11/05 02:20:19 INFO  : potato2: Moved (server-side)
2024/11/05 02:20:20 INFO  : potato3: Deleted
2024/11/05 02:20:21 INFO  : potato3: Moved (server-side)
2024/11/05 02:20:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nawukuc2yidu"
2024/11/05 02:20:21 DEBUG : Creating backend with remote "TestDrive:crypt/66orv4v7ds1caskkdesa3jqqnhi18hu2r3bb0bc4iqiadj6em24g"
2024/11/05 02:20:23 DEBUG : empty space: Excluded (Size Filter)
2024/11/05 02:20:23 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/05 02:20:23 DEBUG : potato3: Need to transfer - File not found at Destination
2024/11/05 02:20:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nawukuc2yidu': Waiting for checks to finish
2024/11/05 02:20:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nawukuc2yidu': Waiting for transfers to finish
2024/11/05 02:20:25 INFO  : potato2: Moved (server-side)
2024/11/05 02:20:25 INFO  : potato3: Moved (server-side)
2024/11/05 02:20:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nawukuc2yidu': Purge remote
2024/11/05 02:20:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xalesiq5kize': Purge remote
--- PASS: TestServerSideMoveWithFilter (22.60s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:20:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nivogax8xexo"
2024/11/05 02:20:28 DEBUG : Creating backend with remote "TestDrive:crypt/r1koct73fp1jh69o11q2rbcub1j1rn991eafoflkaq1aa8jta4pg"
2024/11/05 02:20:31 DEBUG : potato2: md5 = 9187d45d3a9b165103472a6a7b754280 OK
2024/11/05 02:20:33 DEBUG : empty space: md5 = 73885fea04cf08936f4a1bbfd2fee138 OK
2024/11/05 02:20:35 DEBUG : potato3: md5 = 1d5920e47904cc96181af264ed943a28 OK
2024/11/05 02:20:35 DEBUG : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco' -> Encrypted drive 'TestCryptDrive:rclone-test-nivogax8xexo'
2024/11/05 02:20:40 DEBUG : empty space: md5 = a97cdf7d2d621e4d39187132872a8f66 OK
2024/11/05 02:20:42 DEBUG : potato3: md5 = 3ea7efc528b7963a358e819c00e4b93c OK
2024/11/05 02:20:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nivogax8xexo': Using server-side directory move
2024/11/05 02:20:42 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-nivogax8xexo': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/05 02:20:42 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/05 02:20:42 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2024/11/05 02:20:42 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/11/05 02:20:42 DEBUG : empty space: Unchanged skipping
2024/11/05 02:20:42 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/05 02:20:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nivogax8xexo': Waiting for checks to finish
2024/11/05 02:20:43 INFO  : potato3: Deleted
2024/11/05 02:20:43 INFO  : empty space: Deleted
2024/11/05 02:20:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nivogax8xexo': Waiting for transfers to finish
2024/11/05 02:20:43 INFO  : potato2: Moved (server-side)
2024/11/05 02:20:44 INFO  : potato3: Moved (server-side)
2024/11/05 02:20:44 INFO  : tomatoDir: Removing directory
2024/11/05 02:20:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': deleted 1 directories
2024/11/05 02:20:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gamiroh7wadu"
2024/11/05 02:20:46 DEBUG : Creating backend with remote "TestDrive:crypt/s81vvdl3skm185jiq7s24r8qf0j9utfh03anp8oiipov4munvl50"
2024/11/05 02:20:47 DEBUG : tomatoDir: Making directory
2024/11/05 02:20:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gamiroh7wadu': Using server-side directory move
2024/11/05 02:20:49 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gamiroh7wadu': Server side directory move succeeded
2024/11/05 02:20:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gamiroh7wadu': Purge remote
2024/11/05 02:20:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nivogax8xexo': Purge remote
2024/11/05 02:20:51 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (23.53s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.50s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:20:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/rclone-sync-test"
2024/11/05 02:20:53 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncOverlap (4.21s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:20:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/rclone-sync-test"
2024/11/05 02:20:57 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2024/11/05 02:21:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/rclone-sync-test-include/layer2"
2024/11/05 02:21:00 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2024/11/05 02:21:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/rclone-sync-test-ignore-file"
2024/11/05 02:21:04 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2024/11/05 02:21:09 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 230267aeb48b807304056091d589acba OK
2024/11/05 02:21:11 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/05 02:21:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/rclone-sync-test': Waiting for checks to finish
2024/11/05 02:21:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/rclone-sync-test': Waiting for transfers to finish
2024/11/05 02:21:11 DEBUG : Waiting for deletions to finish
2024/11/05 02:21:11 INFO  : There was nothing to transfer
2024/11/05 02:21:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:21:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:21:13 DEBUG : Waiting for deletions to finish
2024/11/05 02:21:13 INFO  : rclone-sync-test-include: Removing directory
2024/11/05 02:21:13 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/05 02:21:13 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/11/05 02:21:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': failed to delete 1 directories
2024/11/05 02:21:13 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:21:15 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/05 02:21:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/rclone-sync-test-include/layer2': Waiting for checks to finish
2024/11/05 02:21:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/rclone-sync-test-include/layer2': Waiting for transfers to finish
2024/11/05 02:21:15 DEBUG : Waiting for deletions to finish
2024/11/05 02:21:15 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:21:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:21:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:21:17 DEBUG : Waiting for deletions to finish
2024/11/05 02:21:17 INFO  : rclone-sync-test-include: Removing directory
2024/11/05 02:21:18 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/05 02:21:18 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/11/05 02:21:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': failed to delete 1 directories
2024/11/05 02:21:18 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:21:20 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/05 02:21:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/rclone-sync-test-ignore-file': Waiting for checks to finish
2024/11/05 02:21:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/rclone-sync-test-ignore-file': Waiting for transfers to finish
2024/11/05 02:21:20 DEBUG : Waiting for deletions to finish
2024/11/05 02:21:20 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:21:22 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/05 02:21:23 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (36.90s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:21:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/dst"
2024/11/05 02:21:34 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/05 02:21:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/CompareDest"
2024/11/05 02:21:35 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/gveqi14airsml4bgu7krj116o8"
2024/11/05 02:21:37 DEBUG : one: Need to transfer - File not found at Destination
2024/11/05 02:21:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:21:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:21:40 DEBUG : one: md5 = f80e4adb82b2c7608571639a7cf8eb9f OK
2024/11/05 02:21:40 INFO  : one: Copied (new)
2024/11/05 02:21:40 DEBUG : Waiting for deletions to finish
2024/11/05 02:21:41 DEBUG : TestDrive: Loaded invalid token from config file - ignoring
2024/11/05 02:21:41 DEBUG : Saving config "token" in section "TestDrive" of the config file
2024/11/05 02:21:41 DEBUG : TestDrive: Saved new token in config file
2024/11/05 02:21:42 DEBUG : TestDrive: Loaded fresh token from config file
2024/11/05 02:21:42 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/05 02:21:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:21:42 DEBUG : TestDrive: Loaded fresh token from config file
2024/11/05 02:21:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:21:44 DEBUG : one: md5 = 0aa3ebcf0bbe55a12dd8ba45c59938f1 OK
2024/11/05 02:21:44 INFO  : one: Copied (replaced existing)
2024/11/05 02:21:44 DEBUG : Waiting for deletions to finish
2024/11/05 02:21:46 DEBUG : dst/one: md5 = ef940120cc1aee3892506b54676f89df OK
2024/11/05 02:21:49 DEBUG : CompareDest/one: md5 = b6b8776cd67465149262b612c3f35ebf OK
2024/11/05 02:21:50 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/05 02:21:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:21:51 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:21:51 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/05 02:21:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:21:51 DEBUG : Waiting for deletions to finish
2024/11/05 02:21:51 INFO  : There was nothing to transfer
2024/11/05 02:21:53 DEBUG : CompareDest/two: md5 = ac60b08192c82d56bdc84da9a2141d20 OK
2024/11/05 02:21:54 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:21:54 DEBUG : two: Destination found in --compare-dest, skipping
2024/11/05 02:21:54 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/05 02:21:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:21:55 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:21:55 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/05 02:21:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:21:55 DEBUG : Waiting for deletions to finish
2024/11/05 02:21:55 INFO  : There was nothing to transfer
2024/11/05 02:21:56 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:21:56 DEBUG : two: Destination found in --compare-dest, skipping
2024/11/05 02:21:56 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/05 02:21:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:21:56 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:21:56 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/05 02:21:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:21:56 DEBUG : Waiting for deletions to finish
2024/11/05 02:21:56 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2024/11/05 02:21:58 DEBUG : two: Sizes differ (src 5 vs dst 3)
2024/11/05 02:21:58 DEBUG : two: Need to transfer - File not found at Destination
2024/11/05 02:21:58 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/05 02:21:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:21:58 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:21:58 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/05 02:21:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:21:59 DEBUG : two: md5 = 080bf4e22f44086e0729add15e7d82df OK
2024/11/05 02:21:59 INFO  : two: Copied (new)
2024/11/05 02:21:59 DEBUG : Waiting for deletions to finish
2024/11/05 02:22:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/05 02:22:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/05 02:22:05 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/05 02:22:05 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncCompareDest (31.85s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:22:09 DEBUG : pre-dest1/1: md5 = 3926d5106f5108c67b21b4053f5c8f5d OK
2024/11/05 02:22:11 DEBUG : pre-dest2/2: md5 = ba37e5909cc223f40831377955bcc989 OK
2024/11/05 02:22:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/dest"
2024/11/05 02:22:12 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/rg03c1jvnehrrc617i0lnqjddc"
2024/11/05 02:22:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/pre-dest1"
2024/11/05 02:22:14 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/bbnblvh6k061ssopqrp18kd7gc"
2024/11/05 02:22:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/pre-dest2"
2024/11/05 02:22:14 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/dgicm1h6b5ejvlltm8eeif0bnk"
2024/11/05 02:22:16 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:22:16 DEBUG : 1: Destination found in --compare-dest, skipping
2024/11/05 02:22:16 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:22:16 DEBUG : 2: Destination found in --compare-dest, skipping
2024/11/05 02:22:17 DEBUG : 3: Need to transfer - File not found at Destination
2024/11/05 02:22:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dest': Waiting for checks to finish
2024/11/05 02:22:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dest': Waiting for transfers to finish
2024/11/05 02:22:20 DEBUG : 3: md5 = 6248b13b9b4caed227cea84b74a9cc1b OK
2024/11/05 02:22:20 INFO  : 3: Copied (new)
2024/11/05 02:22:20 DEBUG : Waiting for deletions to finish
2024/11/05 02:22:24 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2024/11/05 02:22:25 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2024/11/05 02:22:26 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (21.45s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:22:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/dst"
2024/11/05 02:22:27 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/05 02:22:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/CopyDest"
2024/11/05 02:22:29 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/d09o6po3f7bm6ce32vdgs8h9ls"
2024/11/05 02:22:31 DEBUG : one: Need to transfer - File not found at Destination
2024/11/05 02:22:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:22:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:22:34 DEBUG : one: md5 = 1699b102e4cf894bfc14d7f4f9c3efcd OK
2024/11/05 02:22:34 INFO  : one: Copied (new)
2024/11/05 02:22:34 DEBUG : Waiting for deletions to finish
2024/11/05 02:22:35 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/05 02:22:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:22:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:22:37 DEBUG : one: md5 = 029bd5c4f4fff5f6dac4e9e7a13e4919 OK
2024/11/05 02:22:37 INFO  : one: Copied (replaced existing)
2024/11/05 02:22:37 DEBUG : Waiting for deletions to finish
2024/11/05 02:22:39 DEBUG : dst/one: md5 = a5b355bd978979a92f7d3dad87d38be9 OK
2024/11/05 02:22:42 DEBUG : CopyDest/one: md5 = 38385fe1643f1e8d03743f315e01b69e OK
2024/11/05 02:22:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/BackupDir"
2024/11/05 02:22:43 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/s6dbk3lfi7c9kfvo6j7bla9m0g"
2024/11/05 02:22:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:22:45 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/05 02:22:45 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:22:45 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/05 02:22:48 INFO  : one: Moved (server-side)
2024/11/05 02:22:49 INFO  : one: Copied (server-side copy)
2024/11/05 02:22:49 DEBUG : one: Destination found in --copy-dest, using server-side copy
2024/11/05 02:22:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:22:49 DEBUG : Waiting for deletions to finish
2024/11/05 02:22:52 DEBUG : CopyDest/two: md5 = c6150d0e56ec8a68432fb7221bde8a63 OK
2024/11/05 02:22:53 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:22:54 INFO  : two: Copied (server-side copy)
2024/11/05 02:22:54 DEBUG : two: Destination found in --copy-dest, using server-side copy
2024/11/05 02:22:54 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:22:54 DEBUG : one: Unchanged skipping
2024/11/05 02:22:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:22:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:22:54 DEBUG : Waiting for deletions to finish
2024/11/05 02:22:55 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:22:55 DEBUG : one: Unchanged skipping
2024/11/05 02:22:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:22:55 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:22:55 DEBUG : two: Unchanged skipping
2024/11/05 02:22:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:22:55 DEBUG : Waiting for deletions to finish
2024/11/05 02:22:55 INFO  : There was nothing to transfer
2024/11/05 02:22:57 DEBUG : CopyDest/three: md5 = a32d7cc4b91f9fd929dd8fd469c36985 OK
2024/11/05 02:22:58 DEBUG : three: Sizes differ (src 7 vs dst 5)
2024/11/05 02:22:58 DEBUG : three: Destination not found in --copy-dest
2024/11/05 02:22:58 DEBUG : three: Need to transfer - File not found at Destination
2024/11/05 02:22:58 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:22:58 DEBUG : one: Unchanged skipping
2024/11/05 02:22:58 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/05 02:22:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:22:58 DEBUG : two: Unchanged skipping
2024/11/05 02:22:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:23:00 DEBUG : three: md5 = cb3d3f6885d9366c02cb19bc0ee0799b OK
2024/11/05 02:23:00 INFO  : three: Copied (new)
2024/11/05 02:23:00 DEBUG : Waiting for deletions to finish
2024/11/05 02:23:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/11/05 02:23:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/05 02:23:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/05 02:23:07 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/05 02:23:07 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/05 02:23:07 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/11/05 02:23:08 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (41.89s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:23:12 DEBUG : dst/one: md5 = 2b7088c338a70fb681d795c222a613f2 OK
2024/11/05 02:23:14 DEBUG : dst/two: md5 = 045c0b823d0f84828273f6122f1f13d3 OK
2024/11/05 02:23:16 DEBUG : dst/three.txt: md5 = 09e0d9a44b89d2558ef8069040dfca8b OK
2024/11/05 02:23:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/dst"
2024/11/05 02:23:16 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/05 02:23:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/backup"
2024/11/05 02:23:17 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/1nrff024r7pq65ecp72fc28jb0"
2024/11/05 02:23:19 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/05 02:23:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:23:19 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:23:19 DEBUG : two: Unchanged skipping
2024/11/05 02:23:21 INFO  : one: Moved (server-side)
2024/11/05 02:23:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:23:23 DEBUG : one: md5 = 7f444cb199f323977c457d97131fdd22 OK
2024/11/05 02:23:23 INFO  : one: Copied (new)
2024/11/05 02:23:23 DEBUG : Waiting for deletions to finish
2024/11/05 02:23:24 INFO  : three.txt: Moved (server-side)
2024/11/05 02:23:24 INFO  : three.txt: Moved into backup dir
2024/11/05 02:23:27 DEBUG : dst/three.txt: md5 = 3c099d06a4720db75b59212144506404 OK
2024/11/05 02:23:27 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/05 02:23:27 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:23:27 DEBUG : two: Unchanged skipping
2024/11/05 02:23:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:23:28 INFO  : one: Deleted
2024/11/05 02:23:29 INFO  : one: Moved (server-side)
2024/11/05 02:23:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:23:31 DEBUG : one: md5 = 96f73eaa1b5f53da0c229082533ed7e8 OK
2024/11/05 02:23:31 INFO  : one: Copied (new)
2024/11/05 02:23:31 DEBUG : Waiting for deletions to finish
2024/11/05 02:23:32 INFO  : three.txt: Deleted
2024/11/05 02:23:33 INFO  : three.txt: Moved (server-side)
2024/11/05 02:23:33 INFO  : three.txt: Moved into backup dir
2024/11/05 02:23:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/05 02:23:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/05 02:23:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/05 02:23:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/05 02:23:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/05 02:23:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncBackupDir (30.17s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:23:42 DEBUG : dst/one: md5 = 5b91dd06767f52171b3dc7f2c1b232c7 OK
2024/11/05 02:23:44 DEBUG : dst/two: md5 = dd9829eb66d398d020f5465c06e6f02b OK
2024/11/05 02:23:46 DEBUG : dst/three.txt: md5 = feaf02d0ad117e22c2e54eb35cda8aac OK
2024/11/05 02:23:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/dst"
2024/11/05 02:23:46 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/05 02:23:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/backup"
2024/11/05 02:23:47 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/1nrff024r7pq65ecp72fc28jb0"
2024/11/05 02:23:49 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/05 02:23:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:23:49 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:23:49 DEBUG : two: Unchanged skipping
2024/11/05 02:23:51 INFO  : one: Moved (server-side) to: one.bak
2024/11/05 02:23:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:23:53 DEBUG : one: md5 = 4a981d8ae323f0ac38442cf124b771a8 OK
2024/11/05 02:23:53 INFO  : one: Copied (new)
2024/11/05 02:23:53 DEBUG : Waiting for deletions to finish
2024/11/05 02:23:55 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/05 02:23:55 INFO  : three.txt: Moved into backup dir
2024/11/05 02:23:57 DEBUG : dst/three.txt: md5 = 870a53ec65859265535dd6798801c6bc OK
2024/11/05 02:23:58 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/05 02:23:58 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:23:58 DEBUG : two: Unchanged skipping
2024/11/05 02:23:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:23:59 INFO  : one.bak: Deleted
2024/11/05 02:24:00 INFO  : one: Moved (server-side) to: one.bak
2024/11/05 02:24:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:24:02 DEBUG : one: md5 = 02644111eebc44dbd9b92a06306ff505 OK
2024/11/05 02:24:02 INFO  : one: Copied (new)
2024/11/05 02:24:02 DEBUG : Waiting for deletions to finish
2024/11/05 02:24:03 INFO  : three.txt.bak: Deleted
2024/11/05 02:24:04 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/05 02:24:04 INFO  : three.txt: Moved into backup dir
2024/11/05 02:24:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/05 02:24:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/05 02:24:09 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/05 02:24:09 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/05 02:24:09 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/05 02:24:09 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirWithSuffix (30.86s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:24:13 DEBUG : dst/one: md5 = c36e3ad1bfaecdd5d4cc115051a50848 OK
2024/11/05 02:24:14 DEBUG : dst/two: md5 = 24b45d848601184087ea319e145d337b OK
2024/11/05 02:24:16 DEBUG : dst/three.txt: md5 = 0990346d502d40eae9d40ee7b97384b9 OK
2024/11/05 02:24:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/dst"
2024/11/05 02:24:17 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/05 02:24:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/backup"
2024/11/05 02:24:18 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/1nrff024r7pq65ecp72fc28jb0"
2024/11/05 02:24:20 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/05 02:24:20 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:24:20 DEBUG : two: Unchanged skipping
2024/11/05 02:24:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:24:22 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/05 02:24:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:24:24 DEBUG : one: md5 = 61a58e092537fd2a83af80c13812cd74 OK
2024/11/05 02:24:24 INFO  : one: Copied (new)
2024/11/05 02:24:24 DEBUG : Waiting for deletions to finish
2024/11/05 02:24:25 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/05 02:24:25 INFO  : three.txt: Moved into backup dir
2024/11/05 02:24:28 DEBUG : dst/three.txt: md5 = 753ab5fd420cca7b57117b3e317482ba OK
2024/11/05 02:24:29 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/05 02:24:29 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:24:29 DEBUG : two: Unchanged skipping
2024/11/05 02:24:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:24:30 INFO  : one-2019-01-01: Deleted
2024/11/05 02:24:31 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/05 02:24:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:24:32 DEBUG : one: md5 = cdb25061b4c50d2b22203411445816af OK
2024/11/05 02:24:32 INFO  : one: Copied (new)
2024/11/05 02:24:32 DEBUG : Waiting for deletions to finish
2024/11/05 02:24:34 INFO  : three-2019-01-01.txt: Deleted
2024/11/05 02:24:35 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/05 02:24:35 INFO  : three.txt: Moved into backup dir
2024/11/05 02:24:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/05 02:24:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/05 02:24:40 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/05 02:24:40 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/05 02:24:40 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/05 02:24:40 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (30.61s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:24:44 DEBUG : dst/one: md5 = 5e5e75db1858ebd16c3131340ae01111 OK
2024/11/05 02:24:46 DEBUG : dst/two: md5 = 135dc02b58fa81590790e493e4e1261d OK
2024/11/05 02:24:48 DEBUG : dst/three.txt: md5 = 7f882d72c74927590c9eefa0a6011fce OK
2024/11/05 02:24:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/dst"
2024/11/05 02:24:49 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/05 02:24:50 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/05 02:24:50 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:24:50 DEBUG : two: Unchanged skipping
2024/11/05 02:24:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:24:51 INFO  : one: Moved (server-side) to: one.bak
2024/11/05 02:24:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:24:53 DEBUG : one: md5 = f7417cc57ff70ce2b87a25e84a3ba0cf OK
2024/11/05 02:24:53 INFO  : one: Copied (new)
2024/11/05 02:24:53 DEBUG : Waiting for deletions to finish
2024/11/05 02:24:54 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/05 02:24:54 INFO  : three.txt: Moved into backup dir
2024/11/05 02:24:57 DEBUG : dst/three.txt: md5 = ce7423cab3e0583fe77d12534d4cc232 OK
2024/11/05 02:24:57 DEBUG : one.bak: Excluded (Path Filter)
2024/11/05 02:24:57 DEBUG : three.txt.bak: Excluded (Path Filter)
2024/11/05 02:24:57 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/05 02:24:57 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:24:57 DEBUG : two: Unchanged skipping
2024/11/05 02:24:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for checks to finish
2024/11/05 02:24:58 INFO  : one.bak: Deleted
2024/11/05 02:24:59 INFO  : one: Moved (server-side) to: one.bak
2024/11/05 02:24:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco/dst': Waiting for transfers to finish
2024/11/05 02:25:01 DEBUG : one: md5 = 6124ba5cdab0a06c47b90676689d3690 OK
2024/11/05 02:25:01 INFO  : one: Copied (new)
2024/11/05 02:25:01 DEBUG : Waiting for deletions to finish
2024/11/05 02:25:02 INFO  : three.txt.bak: Deleted
2024/11/05 02:25:03 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/05 02:25:03 INFO  : three.txt: Moved into backup dir
2024/11/05 02:25:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/05 02:25:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/05 02:25:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/05 02:25:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/05 02:25:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/05 02:25:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncBackupDirSuffixOnly (27.32s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:25:11 DEBUG : dst/one: md5 = a488c143e7d9439f60fefd82d61bef35 OK
2024/11/05 02:25:13 DEBUG : dst/two: md5 = acb1fe66f815e1564c4c6f786aec6dfd OK
2024/11/05 02:25:14 DEBUG : dst/three.txt: md5 = 2a155df94cda2212785ebe82fbd5d932 OK
2024/11/05 02:25:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/dst"
2024/11/05 02:25:15 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/05 02:25:16 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/05 02:25:17 INFO  : one: Moved (server-side) to: one.bak
2024/11/05 02:25:19 DEBUG : one: md5 = 549defbb44ddc8cc18e70dc2cd3418f8 OK
2024/11/05 02:25:19 INFO  : one: Copied (new)
2024/11/05 02:25:19 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:25:19 DEBUG : two: Unchanged skipping
2024/11/05 02:25:19 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/11/05 02:25:20 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/05 02:25:22 DEBUG : three.txt: md5 = 85b7153e029aa19e7105176f66fdad1e OK
2024/11/05 02:25:22 INFO  : three.txt: Copied (new)
2024/11/05 02:25:24 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/05 02:25:24 INFO  : one.bak: Deleted
2024/11/05 02:25:25 INFO  : one: Moved (server-side) to: one.bak
2024/11/05 02:25:27 DEBUG : one: md5 = 9ad86e0eae6a7a38420771c7dfe2bfed OK
2024/11/05 02:25:27 INFO  : one: Copied (new)
2024/11/05 02:25:27 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:25:27 DEBUG : two: Unchanged skipping
2024/11/05 02:25:27 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/11/05 02:25:28 INFO  : three.txt.bak: Deleted
2024/11/05 02:25:29 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/05 02:25:31 DEBUG : three.txt: md5 = e861b82de9c0d8c2a9a22c86a81a6449 OK
2024/11/05 02:25:31 INFO  : three.txt: Copied (new)
2024/11/05 02:25:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/05 02:25:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/05 02:25:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/05 02:25:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/05 02:25:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/05 02:25:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/05 02:25:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncSuffix (28.86s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:25:39 DEBUG : dst/one: md5 = ecb5a696ffd75e3ae8dfc5b3b96389be OK
2024/11/05 02:25:42 DEBUG : dst/two: md5 = 77a50c9d53282b6b8246c937db5efb5c OK
2024/11/05 02:25:43 DEBUG : dst/three.txt: md5 = 72d4cddbaf6ffe804250c451b5c0429d OK
2024/11/05 02:25:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rinukop9qaco/dst"
2024/11/05 02:25:44 DEBUG : Creating backend with remote "TestDrive:crypt/tno762gk16jpe263rof6j2uqmj53g701kdfj8p00qdb503bvrbt0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/05 02:25:45 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/05 02:25:46 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/05 02:25:48 DEBUG : one: md5 = aaf6d559dfe66524636657cc9953fa31 OK
2024/11/05 02:25:48 INFO  : one: Copied (new)
2024/11/05 02:25:48 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:25:48 DEBUG : two: Unchanged skipping
2024/11/05 02:25:49 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/11/05 02:25:50 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/05 02:25:51 DEBUG : three.txt: md5 = 870081f0e738d895f9879a3d17f9227a OK
2024/11/05 02:25:51 INFO  : three.txt: Copied (new)
2024/11/05 02:25:53 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/05 02:25:54 INFO  : one-2019-01-01: Deleted
2024/11/05 02:25:54 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/05 02:25:56 DEBUG : one: md5 = 612bf20f1c8d876209d28062617f18f2 OK
2024/11/05 02:25:56 INFO  : one: Copied (new)
2024/11/05 02:25:56 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:25:56 DEBUG : two: Unchanged skipping
2024/11/05 02:25:57 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/11/05 02:25:57 INFO  : three-2019-01-01.txt: Deleted
2024/11/05 02:25:58 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/05 02:26:00 DEBUG : three.txt: md5 = efae05ef1bc11d3afc6875a8b66763a5 OK
2024/11/05 02:26:00 INFO  : three.txt: Copied (new)
2024/11/05 02:26:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/05 02:26:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/05 02:26:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/05 02:26:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/05 02:26:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/05 02:26:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/05 02:26:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncSuffixKeepExtension (29.12s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:26:07 DEBUG : Testêé: md5 = c06d7695008c37829893ea51de932a2f OK
2024/11/05 02:26:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:26:08 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2024/11/05 02:26:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:26:10 DEBUG : Testêé: md5 = 76dfc353e7f46d1e888a34ca8f4c6583 OK
2024/11/05 02:26:10 INFO  : Testêé: Copied (replaced existing) to: Testêé
2024/11/05 02:26:10 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (5.41s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:26:12 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/05 02:26:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:26:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:26:13 DEBUG : existing: md5 = 8e37d39a57a4383cb5b1ecc10ef53405 OK
2024/11/05 02:26:13 INFO  : existing: Copied (new)
2024/11/05 02:26:13 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:26:14 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2024/11/05 02:26:14 ERROR : existing: Source and destination exist but do not match: immutable file modified
2024/11/05 02:26:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:26:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:26:14 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': not deleting files as there were IO errors
2024/11/05 02:26:14 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncImmutable (5.74s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:26:19 DEBUG : EXISTING: md5 = e74080a1ac3939212971179309b78be9 OK
2024/11/05 02:26:19 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:26:19 DEBUG : existing: Unchanged skipping
2024/11/05 02:26:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:26:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:26:19 DEBUG : Waiting for deletions to finish
2024/11/05 02:26:19 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (3.95s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.52s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", 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-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", 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-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.48s)
    --- SKIP: TestMaxTransfer/Hard (0.53s)
    --- SKIP: TestMaxTransfer/Soft (0.45s)
    --- SKIP: TestMaxTransfer/Cautious (0.49s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:26:25 DEBUG : both0: md5 = 51f7e6e3e8027aaabb54b58a91bc1582 OK
2024/11/05 02:26:27 DEBUG : only0: md5 = e23ced7f8ccb3c7078374491ce0c5903 OK
2024/11/05 02:26:28 DEBUG : both1: md5 = 69ed701a8138d8914c47a7435d61ba0f OK
2024/11/05 02:26:30 DEBUG : only1: md5 = 0c58a19effbf315f43737ae2ac0ed716 OK
2024/11/05 02:26:32 DEBUG : both2: md5 = 939238301b72c7e6a6405725b3363b66 OK
2024/11/05 02:26:34 DEBUG : only2: md5 = 9786db7b05d357d28b608bd42957cb45 OK
2024/11/05 02:26:36 DEBUG : both3: md5 = 168e89acc7e644da92499b2beb010606 OK
2024/11/05 02:26:38 DEBUG : only3: md5 = c9e0da1e211288835c07d002bd0e6af5 OK
2024/11/05 02:26:40 DEBUG : both4: md5 = df24f868521083db225ddfbed0f68ea9 OK
2024/11/05 02:26:41 DEBUG : only4: md5 = 254ddce4336377a5e1c4179a31788e1e OK
2024/11/05 02:26:43 DEBUG : both5: md5 = 92ca257d22987305bc2820c50c474d68 OK
2024/11/05 02:26:45 DEBUG : only5: md5 = a5f5e8ddc390d013f71a815a801fa658 OK
2024/11/05 02:26:47 DEBUG : both6: md5 = a3626a12f5b788e1824ba561cdd46e3f OK
2024/11/05 02:26:49 DEBUG : only6: md5 = fadffce9327439df74338757a6babe20 OK
2024/11/05 02:26:51 DEBUG : both7: md5 = 4672182470297b7e3a53bc24b13ef44b OK
2024/11/05 02:26:53 DEBUG : only7: md5 = 3a51d6d2c4065fbb95e7fdbc4940e87a OK
2024/11/05 02:26:54 DEBUG : both8: md5 = 3da0c834289da4fc888c2884913e7f68 OK
2024/11/05 02:26:56 DEBUG : only8: md5 = 9025cbcabfadd20a8fd94a914080e804 OK
2024/11/05 02:26:58 DEBUG : both9: md5 = f9d31c620de1d9a46736a105fe425100 OK
2024/11/05 02:27:00 DEBUG : only9: md5 = 9c4f0576e88665e8031daccf95962f8e OK
2024/11/05 02:27:02 DEBUG : both10: md5 = 7fb9e3936acc3e3f2a41d54d27dbfa60 OK
2024/11/05 02:27:04 DEBUG : only10: md5 = 8df6317940108630234a121d84236411 OK
2024/11/05 02:27:06 DEBUG : both11: md5 = d263147e94d61d887d9a93a438f4caa8 OK
2024/11/05 02:27:07 DEBUG : only11: md5 = b5d9c62705dfe4c17dba18b921f5cac2 OK
2024/11/05 02:27:09 DEBUG : both12: md5 = d784ca0921a61010fecbac4f5f2b8525 OK
2024/11/05 02:27:11 DEBUG : only12: md5 = 5083a4d8b7fb19f24309749ea6a3e3f4 OK
2024/11/05 02:27:13 DEBUG : both13: md5 = e3a3dec76dd3ad3fd552274ace4c2e39 OK
2024/11/05 02:27:15 DEBUG : only13: md5 = 6d731624759438c865ce992b8d7a9e5b OK
2024/11/05 02:27:16 DEBUG : both14: md5 = 88f16e1552d10b962f325f22c3bf99ab OK
2024/11/05 02:27:18 DEBUG : only14: md5 = 9c8663637dc553019b86fe969c8fb579 OK
2024/11/05 02:27:20 DEBUG : both15: md5 = 275d572dd34f6eb5f5225710df699e7f OK
2024/11/05 02:27:22 DEBUG : only15: md5 = 64d81705b4e2089fc9039605d2b02069 OK
2024/11/05 02:27:24 DEBUG : both16: md5 = c9a876f7397ba839e9e4e6d183764a83 OK
2024/11/05 02:27:26 DEBUG : only16: md5 = e503de4adbf370e3ec56384ae9a85742 OK
2024/11/05 02:27:28 DEBUG : both17: md5 = ac456edf6ee7508b4ff0e558e70ac500 OK
2024/11/05 02:27:29 DEBUG : only17: md5 = ef461ae0d74a2a93ddb98af6e3fc2c0c OK
2024/11/05 02:27:31 DEBUG : both18: md5 = 512f4bc6b69eeb9af0f3e7fca62c5423 OK
2024/11/05 02:27:33 DEBUG : only18: md5 = 4a71f3f9ddf303e90971d173e3a0176c OK
2024/11/05 02:27:35 DEBUG : both19: md5 = 2daddd2052c831eb47712c0a8df62576 OK
2024/11/05 02:27:37 DEBUG : only19: md5 = a1a037c89b6f69f03412926f35dde5ae OK
2024/11/05 02:27:38 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:27:38 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both0: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both12: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both1: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both11: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both15: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both16: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both10: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both14: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both13: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both19: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both3: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both2: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both5: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both6: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both18: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both17: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:27:38 DEBUG : both4: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both7: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both8: Unchanged skipping
2024/11/05 02:27:38 DEBUG : both9: Unchanged skipping
2024/11/05 02:27:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:27:38 DEBUG : Waiting for deletions to finish
2024/11/05 02:27:38 INFO  : only1: Deleted
2024/11/05 02:27:38 INFO  : only14: Deleted
2024/11/05 02:27:38 INFO  : only2: Deleted
2024/11/05 02:27:38 INFO  : only5: Deleted
2024/11/05 02:27:39 INFO  : only19: Deleted
2024/11/05 02:27:39 INFO  : only9: Deleted
2024/11/05 02:27:39 INFO  : only18: Deleted
2024/11/05 02:27:39 INFO  : only0: Deleted
2024/11/05 02:27:39 INFO  : only11: Deleted
2024/11/05 02:27:40 INFO  : only12: Deleted
2024/11/05 02:27:40 INFO  : only15: Deleted
2024/11/05 02:27:40 INFO  : only3: Deleted
2024/11/05 02:27:40 INFO  : only6: Deleted
2024/11/05 02:27:40 INFO  : only8: Deleted
2024/11/05 02:27:40 INFO  : only10: Deleted
2024/11/05 02:27:40 INFO  : only13: Deleted
2024/11/05 02:27:41 INFO  : only16: Deleted
2024/11/05 02:27:41 INFO  : only17: Deleted
2024/11/05 02:27:41 INFO  : only4: Deleted
2024/11/05 02:27:41 INFO  : only7: Deleted
2024/11/05 02:27:41 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (92.49s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:27:57 DEBUG : both0: md5 = e7ef17435ae7c72ae495aa91de1b0935 OK
2024/11/05 02:27:59 DEBUG : only0: md5 = 7dc2caa0d47bdbb97c05fa6c141a9b5b OK
2024/11/05 02:28:01 DEBUG : both1: md5 = a25c30388be76702bc576ac0099e7dad OK
2024/11/05 02:28:03 DEBUG : only1: md5 = 8bd44cd4db1f4f36a124362982dc41aa OK
2024/11/05 02:28:05 DEBUG : both2: md5 = ba586325854313e74ee3faf906e46ea3 OK
2024/11/05 02:28:07 DEBUG : only2: md5 = a14e0e16a3405a1d389024b29605dbc3 OK
2024/11/05 02:28:09 DEBUG : both3: md5 = 2424d088643a19c884295f37dbb641ac OK
2024/11/05 02:28:11 DEBUG : only3: md5 = d3b4cc84ce4bee75162b231b2bb41a09 OK
2024/11/05 02:28:13 DEBUG : both4: md5 = 163698e08c51f166bc13b53320e1c65b OK
2024/11/05 02:28:15 DEBUG : only4: md5 = 685a5127551327e4760965b4ba066674 OK
2024/11/05 02:28:17 DEBUG : both5: md5 = fa5181878f72b3310fefb30f437d2e6f OK
2024/11/05 02:28:18 DEBUG : only5: md5 = 76f9cc4a26bb351e8d5fde7b8b2a51ff OK
2024/11/05 02:28:20 DEBUG : both6: md5 = d8520cd18f40d596ec238aa7c5016de5 OK
2024/11/05 02:28:22 DEBUG : only6: md5 = d6ee27c26af9accbac984303a0be88d4 OK
2024/11/05 02:28:24 DEBUG : both7: md5 = 207fc7d8f2369c501c8f21be7f19e4c9 OK
2024/11/05 02:28:26 DEBUG : only7: md5 = 3bd83e6ede16ccc6a20291c419c35a4f OK
2024/11/05 02:28:27 DEBUG : both8: md5 = 90dc11d318ecd0f571af22753d5ef72b OK
2024/11/05 02:28:29 DEBUG : only8: md5 = ab6c75dc6b33ca735f3a48b1450258c9 OK
2024/11/05 02:28:31 DEBUG : both9: md5 = 676f6177f641f6ad59445131cb3931a4 OK
2024/11/05 02:28:33 DEBUG : only9: md5 = e2f8478bdd8a9e1233c37dc477606006 OK
2024/11/05 02:28:34 DEBUG : both10: md5 = edfc9bdeb0db50ba7dcbe953ba77a9c5 OK
2024/11/05 02:28:36 DEBUG : only10: md5 = 03f7bdd5945174c8e5a9bcdd5cb0ea79 OK
2024/11/05 02:28:39 DEBUG : both11: md5 = c542c1d99b933c5b3373bfa0215a2bf2 OK
2024/11/05 02:28:40 DEBUG : only11: md5 = c199e4560dbf14f90de569617d391c28 OK
2024/11/05 02:28:42 DEBUG : both12: md5 = 8997430727aa86352ad5910081e0ee36 OK
2024/11/05 02:28:44 DEBUG : only12: md5 = f0c08b15349443b532d928cc34f54bf8 OK
2024/11/05 02:28:46 DEBUG : both13: md5 = 12e5671c12c1075c8353e87814082414 OK
2024/11/05 02:28:48 DEBUG : only13: md5 = 5b58b90d478c06039fef4840f2d32328 OK
2024/11/05 02:28:49 DEBUG : both14: md5 = 2743f4afa0734901e19d878e0d38112a OK
2024/11/05 02:28:51 DEBUG : only14: md5 = 7e6092f204a970e0b57e6c013e3ccc1d OK
2024/11/05 02:28:53 DEBUG : both15: md5 = 097d26e83bd8b82db3d080f2d1e323b8 OK
2024/11/05 02:28:55 DEBUG : only15: md5 = 50c3e8bce091256f925da0fb24f6e3eb OK
2024/11/05 02:28:57 DEBUG : both16: md5 = 3f738abb824e3ef5255e3c1f3202d792 OK
2024/11/05 02:28:58 DEBUG : only16: md5 = 253a8c2fab5e8004df2cdbd578815af9 OK
2024/11/05 02:29:00 DEBUG : both17: md5 = cfe68f86f0fdb254b53f7bdd0f092687 OK
2024/11/05 02:29:02 DEBUG : only17: md5 = 348e7957f04a29a6ab9d06c2e72ad79d OK
2024/11/05 02:29:05 DEBUG : both18: md5 = 6e9396d455cccec3210924c3280bee6a OK
2024/11/05 02:29:07 DEBUG : only18: md5 = d940edf6255e4daae31c5db5b6309958 OK
2024/11/05 02:29:08 DEBUG : both19: md5 = 27b0d7442e1aa2367d22c403883a1ded OK
2024/11/05 02:29:10 DEBUG : only19: md5 = 96873a7d3c3e96bb674d5a056bb0c708 OK
2024/11/05 02:29:11 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for checks to finish
2024/11/05 02:29:11 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both0: Unchanged skipping
2024/11/05 02:29:11 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both1: Unchanged skipping
2024/11/05 02:29:11 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both13: Unchanged skipping
2024/11/05 02:29:11 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both14: Unchanged skipping
2024/11/05 02:29:11 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both15: Unchanged skipping
2024/11/05 02:29:11 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both16: Unchanged skipping
2024/11/05 02:29:11 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both17: Unchanged skipping
2024/11/05 02:29:11 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both11: Unchanged skipping
2024/11/05 02:29:11 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both12: Unchanged skipping
2024/11/05 02:29:11 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both10: Unchanged skipping
2024/11/05 02:29:11 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both2: Unchanged skipping
2024/11/05 02:29:11 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both4: Unchanged skipping
2024/11/05 02:29:11 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both5: Unchanged skipping
2024/11/05 02:29:11 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both6: Unchanged skipping
2024/11/05 02:29:11 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both3: Unchanged skipping
2024/11/05 02:29:11 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both19: Unchanged skipping
2024/11/05 02:29:11 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/05 02:29:11 DEBUG : both18: Unchanged skipping
2024/11/05 02:29:11 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : both7: Unchanged skipping
2024/11/05 02:29:11 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : both8: Unchanged skipping
2024/11/05 02:29:11 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : both9: Unchanged skipping
2024/11/05 02:29:11 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2024/11/05 02:29:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Waiting for transfers to finish
2024/11/05 02:29:12 DEBUG : only1: md5 = 7672601b874ea0eff539da4f03745d08 OK
2024/11/05 02:29:12 INFO  : only1: Copied (replaced existing)
2024/11/05 02:29:12 DEBUG : only11: md5 = c912817980369f84f599e9672959ef01 OK
2024/11/05 02:29:12 INFO  : only11: Copied (replaced existing)
2024/11/05 02:29:12 DEBUG : only13: md5 = f91937ec6daecff81b9db0a0023782e9 OK
2024/11/05 02:29:12 INFO  : only13: Copied (replaced existing)
2024/11/05 02:29:13 DEBUG : only12: md5 = 2e862f8a151450c7c6368bfb943762bb OK
2024/11/05 02:29:13 INFO  : only12: Copied (replaced existing)
2024/11/05 02:29:14 DEBUG : only15: md5 = ba944dd7958c6a70ef03adc7cda0f18b OK
2024/11/05 02:29:14 INFO  : only15: Copied (replaced existing)
2024/11/05 02:29:14 DEBUG : only14: md5 = 7c44137b18e739ac1202d719f35da196 OK
2024/11/05 02:29:14 INFO  : only14: Copied (replaced existing)
2024/11/05 02:29:14 DEBUG : only17: md5 = 76b5d32407552d5a66d93cb4a463b00a OK
2024/11/05 02:29:14 INFO  : only17: Copied (replaced existing)
2024/11/05 02:29:14 DEBUG : only16: md5 = a64acc80defe4f905f17249bb776d462 OK
2024/11/05 02:29:14 INFO  : only16: Copied (replaced existing)
2024/11/05 02:29:15 DEBUG : only19: md5 = c3c9a29ce4dd3c3d841abbc72a707820 OK
2024/11/05 02:29:15 INFO  : only19: Copied (replaced existing)
2024/11/05 02:29:15 DEBUG : only0: md5 = a38b151acbb2b7e38d3c181ecc997d79 OK
2024/11/05 02:29:15 INFO  : only0: Copied (replaced existing)
2024/11/05 02:29:15 DEBUG : only2: md5 = 3c53d4bf3259966f7f7359199a2dfdb8 OK
2024/11/05 02:29:15 INFO  : only2: Copied (replaced existing)
2024/11/05 02:29:16 DEBUG : only3: md5 = a6c6029831c26d9a99c67cc2c2bba0ee OK
2024/11/05 02:29:16 INFO  : only3: Copied (replaced existing)
2024/11/05 02:29:17 DEBUG : only4: md5 = 41d09f039b5a8608033976318903c253 OK
2024/11/05 02:29:17 INFO  : only4: Copied (replaced existing)
2024/11/05 02:29:17 DEBUG : only5: md5 = 84b5ea844482ca276b9528feb705bef4 OK
2024/11/05 02:29:17 INFO  : only5: Copied (replaced existing)
2024/11/05 02:29:17 DEBUG : only18: md5 = c226cf849bd6e499ba1f3091a694cb7d OK
2024/11/05 02:29:17 INFO  : only18: Copied (replaced existing)
2024/11/05 02:29:17 DEBUG : only6: md5 = a6c008a7df133a96120f195202cc391f OK
2024/11/05 02:29:17 INFO  : only6: Copied (replaced existing)
2024/11/05 02:29:18 DEBUG : only9: md5 = e9599a81a0cb7a2f98811cb3e0c676c6 OK
2024/11/05 02:29:18 INFO  : only9: Copied (replaced existing)
2024/11/05 02:29:18 DEBUG : only8: md5 = 40477554ddee04c8b3521c1ef40efddd OK
2024/11/05 02:29:18 INFO  : only8: Copied (replaced existing)
2024/11/05 02:29:18 DEBUG : only10: md5 = 93b05bd708bcf13577ef2eebdeef37c7 OK
2024/11/05 02:29:18 INFO  : only10: Copied (replaced existing)
2024/11/05 02:29:18 DEBUG : only7: md5 = 99475556080f7cda8c07eb02dfb0d88a OK
2024/11/05 02:29:18 INFO  : only7: Copied (replaced existing)
2024/11/05 02:29:18 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (111.42s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:29:47 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/05 02:29:47 DEBUG : sub dir: Making directory with metadata
2024/11/05 02:29:48 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:30:10 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/05 02:30:11 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/05 02:30:11 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/05 02:30:11 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:30:28 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2024/11/05 02:30:29 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/05 02:30:30 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/11/05 02:30:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/11/05 02:30:32 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/05 02:30:33 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/05 02:30:34 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/05 02:30:35 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/05 02:30:35 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/05 02:30:36 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/11/05 02:30:36 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/05 02:30:38 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (53.31s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:30:40 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/05 02:30:40 DEBUG : sub dir: Making directory with metadata
2024/11/05 02:30:41 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:31:08 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/05 02:31:08 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/05 02:31:08 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/05 02:31:08 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco'", Local "Local file system at /tmp/rclone770401715", Modify Window "1ms"
2024/11/05 02:31:23 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/05 02:31:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/11/05 02:31:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/11/05 02:31:26 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/05 02:31:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/05 02:31:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/05 02:31:29 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/05 02:31:30 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/05 02:31:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/11/05 02:31:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/05 02:31:32 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (55.23s)
PASS
2024/11/05 02:31:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rinukop9qaco': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 19m39.927591254s (try 1/5)