"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5)
2024/11/20 01:10:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa"
2024/11/20 01:10:30 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/11/20 01:10:30 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0"
2024/11/20 01:10:31 DEBUG : Creating backend with remote "/tmp/rclone2810207766"
=== 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-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:10:33 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/20 01:10:33 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/20 01:10:33 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2024/11/20 01:10:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:10:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:10:33 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.66s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:10:34 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/20 01:10:34 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/20 01:10:34 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/20 01:10:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:10:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:10:37 DEBUG : sub dir/hello world: md5 = a6264466654634d0ef79e2eecc9d3523 OK
2024/11/20 01:10:37 INFO  : sub dir/hello world: Copied (new)
2024/11/20 01:10:38 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:10:40 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (7.53s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:10:41 DEBUG : metadata sub dir: Making directory with metadata
2024/11/20 01:10:41 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/20 01:10:41 DEBUG : empty metadata sub dir: Making directory with metadata
2024/11/20 01:10:41 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/20 01:10:41 DEBUG : Local file system at /tmp/rclone2810207766: File to upload is small (21 bytes), uploading instead of streaming
2024/11/20 01:10:41 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/11/20 01:10:41 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/11/20 01:10:41 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/11/20 01:10:42 DEBUG : Google drive root 'crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0': Skipping btime metadata as can't update it on an existing file: 2024-11-20T01:10:41.870811058Z
2024/11/20 01:10:43 INFO  : empty metadata sub dir: Updated directory metadata
2024/11/20 01:10:43 DEBUG : Google drive root 'crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0': Skipping btime metadata as can't update it on an existing file: 2024-11-20T01:10:41.870811058Z
2024/11/20 01:10:44 INFO  : metadata sub dir: Updated directory metadata
2024/11/20 01:10:44 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/11/20 01:10:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:10:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:10:45 DEBUG : metadata sub dir/hello metadata world: md5 = fb4b350dffb245c77c6f0b7d02969bd6 OK
2024/11/20 01:10:45 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:10:49 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (9.52s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:10:51 DEBUG : metadata sub dir: Making directory with metadata
2024/11/20 01:10:51 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/20 01:10:51 DEBUG : empty metadata sub dir: Making directory with metadata
2024/11/20 01:10:51 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/20 01:10:51 DEBUG : Local file system at /tmp/rclone2810207766: File to upload is small (21 bytes), uploading instead of streaming
2024/11/20 01:10:51 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/11/20 01:10:51 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/11/20 01:10:51 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/11/20 01:10:51 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2024/11/20 01:10:51 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2024/11/20 01:10:51 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/11/20 01:10:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:10:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:10:54 DEBUG : metadata sub dir/hello metadata world: md5 = cb9678d4f15d6b04fbbc0c08eb9c1882 OK
2024/11/20 01:10:54 INFO  : metadata sub dir/hello metadata world: Copied (new)
2024/11/20 01:10:54 DEBUG : Google drive root 'crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0': Skipping btime metadata as can't update it on an existing file: 2024-11-20T01:10:51.394752277Z
2024/11/20 01:10:55 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:10:57 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (8.00s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:10:59 DEBUG : Creating backend with remote "/non-existing"
2024/11/20 01:10:59 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2024/11/20 01:10:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:10:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.24s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:11:00 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/20 01:11:00 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/20 01:11:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:11:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:11:03 DEBUG : sub dir/hello world: md5 = 28a333b23631e1005b893d61f602527c OK
2024/11/20 01:11:03 INFO  : sub dir/hello world: Copied (new)
2024/11/20 01:11:04 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:11:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (6.99s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:11:07 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Running all checks before starting transfers
2024/11/20 01:11:07 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/20 01:11:07 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/20 01:11:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:11:07 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Checks finished, now starting transfers
2024/11/20 01:11:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:11:10 DEBUG : sub dir/hello world: md5 = b5e4be5e5329579d525817b7966cf851 OK
2024/11/20 01:11:10 INFO  : sub dir/hello world: Copied (new)
2024/11/20 01:11:11 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:11:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (6.99s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:11:14 ERROR : Ignoring --no-traverse with sync
2024/11/20 01:11:14 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/20 01:11:14 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/20 01:11:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:11:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:11:17 DEBUG : sub dir/hello world: md5 = abd16b39ab76fb2b7cac6095ed0423f5 OK
2024/11/20 01:11:17 INFO  : sub dir/hello world: Copied (new)
2024/11/20 01:11:17 DEBUG : Waiting for deletions to finish
2024/11/20 01:11:18 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:11:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (7.00s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:11:21 DEBUG : hello world2: Need to transfer - File not found at Destination
2024/11/20 01:11:21 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/20 01:11:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:11:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:11:23 DEBUG : hello world2: md5 = 144ae5dc79f52195ab85be45c21be8a3 OK
2024/11/20 01:11:23 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestCopyWithDepth (3.87s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:11:25 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/20 01:11:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:11:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:11:27 DEBUG : potato2: md5 = dca801b9d2a328d57bee068836eaeee9 OK
2024/11/20 01:11:27 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.78s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:11:29 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/20 01:11:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:11:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:11:31 DEBUG : potato2: md5 = 75e248995e4bf951d5de79ce89248127 OK
2024/11/20 01:11:31 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.73s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:11:32 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/20 01:11:32 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/20 01:11:32 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/20 01:11:32 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/20 01:11:33 DEBUG : sub dir: Making directory with metadata
2024/11/20 01:11:34 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/20 01:11:34 DEBUG : sub dir2: Making directory with metadata
2024/11/20 01:11:35 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/20 01:11:35 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/20 01:11:35 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/20 01:11:36 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/20 01:11:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:11:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:11:37 DEBUG : sub dir/hello world: md5 = 194b3672ac0993182f3d0c2e3887a16f OK
2024/11/20 01:11:37 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:11:41 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2024/11/20 01:11:42 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (10.67s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:11:43 DEBUG : sub dir2: Making directory
2024/11/20 01:11:43 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/20 01:11:43 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/20 01:11:43 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/20 01:11:43 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/20 01:11:43 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2024/11/20 01:11:43 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/20 01:11:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:11:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:11:46 DEBUG : sub dir/hello world: md5 = 55b3bb39d5be9c66a81935e532c918de OK
2024/11/20 01:11:46 INFO  : sub dir/hello world: Copied (new)
2024/11/20 01:11:47 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/20 01:11:49 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (6.40s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:11:50 DEBUG : sub dir2: Making directory with metadata
2024/11/20 01:11:50 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/20 01:11:50 DEBUG : sub dir: Making directory with metadata
2024/11/20 01:11:51 INFO  : sub dir: Made directory with metadata (mtime=2024-11-20T01:11:50.058389526Z)
2024/11/20 01:11:51 DEBUG : sub dir2: Making directory with metadata
2024/11/20 01:11:52 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/20 01:11:52 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/20 01:11:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:11:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:11:54 DEBUG : sub dir/hello world: md5 = 0c114cf2a3b00ddc36d13df5cdd5f4a9 OK
2024/11/20 01:11:54 INFO  : sub dir/hello world: Copied (new)
2024/11/20 01:11:54 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:11:57 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (8.76s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:11:58 DEBUG : sub dir no update dir modtime: Making directory with metadata
2024/11/20 01:11:58 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/20 01:12:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:12:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:12:00 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (4.83s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:12:03 DEBUG : sub dir2: Making directory
2024/11/20 01:12:03 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/20 01:12:03 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/20 01:12:03 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/20 01:12:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:12:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:12:06 DEBUG : sub dir/hello world: md5 = 4cc7b8a59cf532d2aedd57903f7e6e98 OK
2024/11/20 01:12:06 INFO  : sub dir/hello world: Copied (new)
2024/11/20 01:12:06 INFO  : sub dir/hello world: Deleted
2024/11/20 01:12:07 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/20 01:12:09 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (6.56s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:12:10 DEBUG : sub dir2: Making directory with metadata
2024/11/20 01:12:10 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/20 01:12:10 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/20 01:12:10 DEBUG : sub dir: Making directory with metadata
2024/11/20 01:12:11 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/20 01:12:11 DEBUG : sub dir2: Making directory with metadata
2024/11/20 01:12:12 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/20 01:12:12 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/20 01:12:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:12:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:12:14 DEBUG : sub dir/hello world: md5 = f202f320ca857e3cd63860fdf5b52f9e OK
2024/11/20 01:12:14 INFO  : sub dir/hello world: Copied (new)
2024/11/20 01:12:14 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:12:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (8.66s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.43s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:12:19 DEBUG : sub dir2: Making directory
2024/11/20 01:12:19 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/20 01:12:19 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/20 01:12:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/20 01:12:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:12:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:12:22 DEBUG : sub dir/hello world: md5 = 03070323d692042518925db541783bdf OK
2024/11/20 01:12:22 INFO  : sub dir/hello world: Copied (new)
2024/11/20 01:12:22 DEBUG : Waiting for deletions to finish
2024/11/20 01:12:23 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/20 01:12:25 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (6.65s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:12:29 DEBUG : sub dir/hello world: md5 = a6c1c03e5f858b53c5c87598c4c313d3 OK
2024/11/20 01:12:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biyunet0qejo"
2024/11/20 01:12:29 DEBUG : Creating backend with remote "TestDrive:crypt/i5543t05vv6mdgpb81mlvqqut67fb2v1q2o4pv3b4f02hc5ko6j0"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa' -> Encrypted drive 'TestCryptDrive:rclone-test-biyunet0qejo'
2024/11/20 01:12:31 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/20 01:12:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/20 01:12:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biyunet0qejo': Waiting for checks to finish
2024/11/20 01:12:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biyunet0qejo': Waiting for transfers to finish
2024/11/20 01:12:34 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/20 01:12:35 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:12:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biyunet0qejo': Purge remote
2024/11/20 01:12:38 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (13.41s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:12:41 DEBUG : sub dir/hello world: md5 = c5093c8be64a39b35ec6e5146a1b9b0b OK
2024/11/20 01:12:42 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/20 01:12:42 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/20 01:12:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:12:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:12:44 DEBUG : sub dir/hello world: md5 = 1fa6c8671223efdb3739e8caf91c3657 OK
2024/11/20 01:12:44 INFO  : sub dir/hello world: Copied (replaced existing)
2024/11/20 01:12:45 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:12:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (8.92s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:12:50 DEBUG : sub dir/hello world: md5 = 021993bffa11ee34ed1766ca928f9468 OK
2024/11/20 01:12:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-maroqut1ruco"
2024/11/20 01:12:51 DEBUG : Creating backend with remote "TestDrive:crypt/atm8qms63jqa9mfg7i3tt12qjqcsk24vsn3g3duv0c4utuo6i1gg"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa' -> Encrypted drive 'TestCryptDrive:rclone-test-maroqut1ruco'
2024/11/20 01:12:53 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/20 01:12:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/20 01:12:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-maroqut1ruco': Waiting for checks to finish
2024/11/20 01:12:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-maroqut1ruco': Waiting for transfers to finish
2024/11/20 01:12:56 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/20 01:12:57 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:12:59 DEBUG : sub dir/hello world: md5 = 1a705d2a5e951330174256a96c2e5de2 OK
2024/11/20 01:13:00 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/20 01:13:00 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/20 01:13:00 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/20 01:13:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-maroqut1ruco': Waiting for checks to finish
2024/11/20 01:13:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-maroqut1ruco': Waiting for transfers to finish
2024/11/20 01:13:02 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/20 01:13:02 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:13:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-maroqut1ruco': Purge remote
2024/11/20 01:13:05 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (18.96s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:13:10 DEBUG : sub dir/hello world: md5 = 4a7e364e5850c5b879713f62bb137e8e OK
2024/11/20 01:13:11 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/20 01:13:11 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/20 01:13:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:13:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:13:12 DEBUG : sub dir/hello world: md5 = 239563a8a2771ca0782105fd3e51abf6 OK
2024/11/20 01:13:12 INFO  : sub dir/hello world: Copied (replaced existing)
2024/11/20 01:13:12 INFO  : sub dir/hello world: Deleted
2024/11/20 01:13:13 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:13:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (9.31s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:13:19 DEBUG : sub dir/hello world: md5 = 40e8e0bb83dbe605897a6ea757f4827a OK
2024/11/20 01:13:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zuxepif0jacu"
2024/11/20 01:13:19 DEBUG : Creating backend with remote "TestDrive:crypt/c787rf2jesn5e7pekkalpqu4ljda3uqhtue4me3odl4vr5jkq2eg"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa' -> Encrypted drive 'TestCryptDrive:rclone-test-zuxepif0jacu'
2024/11/20 01:13:21 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/20 01:13:21 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/20 01:13:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuxepif0jacu': Waiting for checks to finish
2024/11/20 01:13:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuxepif0jacu': Waiting for transfers to finish
2024/11/20 01:13:25 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/20 01:13:25 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:13:28 DEBUG : sub dir/hello world: md5 = 42ca39282f6e3e3ec1d5190558522e1f OK
2024/11/20 01:13:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuxepif0jacu': Using server-side directory move
2024/11/20 01:13:28 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-zuxepif0jacu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/20 01:13:28 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/20 01:13:28 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/20 01:13:29 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/20 01:13:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuxepif0jacu': Waiting for checks to finish
2024/11/20 01:13:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuxepif0jacu': Waiting for transfers to finish
2024/11/20 01:13:29 INFO  : sub dir/hello world: Deleted
2024/11/20 01:13:30 INFO  : sub dir/hello world: Moved (server-side)
2024/11/20 01:13:31 INFO  : sub dir: Set directory modification time (using SetModTime)
2024/11/20 01:13:34 DEBUG : sub dir/hello world: md5 = 8cbd554f901468880a47799a834135e4 OK
2024/11/20 01:13:34 DEBUG : testing file moves
2024/11/20 01:13:35 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/20 01:13:35 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/20 01:13:35 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2024/11/20 01:13:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuxepif0jacu': Waiting for checks to finish
2024/11/20 01:13:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuxepif0jacu': Waiting for transfers to finish
2024/11/20 01:13:35 INFO  : sub dir/hello world: Deleted
2024/11/20 01:13:36 INFO  : sub dir/hello world: Moved (server-side)
2024/11/20 01:13:37 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:13:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuxepif0jacu': Purge remote
--- PASS: TestServerSideMoveOverSelf (24.90s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:13:44 DEBUG : sub dir/hello world: md5 = 93e52f78be9c52a8f63a1e5e573b91ca OK
2024/11/20 01:13:44 ERROR : : error listing: directory not found
2024/11/20 01:13:44 DEBUG : Local file system at /tmp/rclone2810207766: Making directory
2024/11/20 01:13:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:13:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:13:47 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (7.06s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:13:51 DEBUG : sub dir/hello world: md5 = 29984418e2e4a4f796fc33364d1e4f8a OK
2024/11/20 01:13:52 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/20 01:13:52 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/20 01:13:52 DEBUG : Local file system at /tmp/rclone2810207766: Waiting for checks to finish
2024/11/20 01:13:52 DEBUG : Local file system at /tmp/rclone2810207766: Waiting for transfers to finish
2024/11/20 01:13:53 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2024/11/20 01:13:53 INFO  : sub dir/hello world: Copied (new)
2024/11/20 01:13:53 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:13:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (8.38s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:13:57 DEBUG : check sum: Need to transfer - File not found at Destination
2024/11/20 01:13:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:13:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:13:58 DEBUG : check sum: md5 = 753179baf8c0de94f441d8ecabf5677c OK
2024/11/20 01:13:58 INFO  : check sum: Copied (new)
2024/11/20 01:13:58 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:13:59 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2024/11/20 01:13:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:13:59 DEBUG : check sum: Size of src and dst objects identical
2024/11/20 01:13:59 DEBUG : check sum: Unchanged skipping
2024/11/20 01:13:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:13:59 DEBUG : Waiting for deletions to finish
2024/11/20 01:13:59 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (4.94s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:14:02 DEBUG : sizeonly: Need to transfer - File not found at Destination
2024/11/20 01:14:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:14:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:14:03 DEBUG : sizeonly: md5 = af077bc2179e4dccfcbf7a57d5465ac6 OK
2024/11/20 01:14:03 INFO  : sizeonly: Copied (new)
2024/11/20 01:14:03 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:14:04 DEBUG : sizeonly: Sizes identical
2024/11/20 01:14:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:14:04 DEBUG : sizeonly: Unchanged skipping
2024/11/20 01:14:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:14:04 DEBUG : Waiting for deletions to finish
2024/11/20 01:14:04 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (4.66s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:14:06 DEBUG : ignore-size: Need to transfer - File not found at Destination
2024/11/20 01:14:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:14:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:14:08 DEBUG : ignore-size: md5 = ca84d9e16a4d20784f391e2e059cb70b OK
2024/11/20 01:14:08 INFO  : ignore-size: Copied (new)
2024/11/20 01:14:08 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:14:08 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:14:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:14:08 DEBUG : ignore-size: Unchanged skipping
2024/11/20 01:14:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:14:08 DEBUG : Waiting for deletions to finish
2024/11/20 01:14:08 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (4.63s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:14:13 DEBUG : existing: md5 = df016df1db2a7ab177441255b0643466 OK
2024/11/20 01:14:13 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:14:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:14:13 DEBUG : existing: Unchanged skipping
2024/11/20 01:14:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:14:13 DEBUG : Waiting for deletions to finish
2024/11/20 01:14:13 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:14:13 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2024/11/20 01:14:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:14:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:14:15 DEBUG : existing: md5 = cc49fe3bc24fc86832dacaa5173b3763 OK
2024/11/20 01:14:15 INFO  : existing: Copied (replaced existing)
2024/11/20 01:14:15 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (6.26s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:14:17 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/20 01:14:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:14:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:14:19 DEBUG : existing: md5 = a8ca3071f84a9bf618f2b9d30b3acc3f OK
2024/11/20 01:14:19 INFO  : existing: Copied (new)
2024/11/20 01:14:19 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:14:19 DEBUG : existing: Destination exists, skipping
2024/11/20 01:14:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:14:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:14:19 DEBUG : Waiting for deletions to finish
2024/11/20 01:14:19 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (4.81s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:14:25 DEBUG : b/potato: md5 = 149d1512aac1b5bb060bca9ce52b9cc7 OK
2024/11/20 01:14:28 DEBUG : c/non empty space: md5 = 92a4bccdee4da969904b648051c60098 OK
2024/11/20 01:14:28 DEBUG : d: Making directory
2024/11/20 01:14:30 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/20 01:14:30 DEBUG : Added delayed dir = "c", newDst=c
2024/11/20 01:14:30 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:14:30 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/20 01:14:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:14:30 DEBUG : c/non empty space: Unchanged skipping
2024/11/20 01:14:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:14:33 DEBUG : a/potato2: md5 = d75455080dfab9ab99d7ab071fcf0d98 OK
2024/11/20 01:14:33 INFO  : a/potato2: Copied (new)
2024/11/20 01:14:33 DEBUG : Waiting for deletions to finish
2024/11/20 01:14:34 INFO  : b/potato: Deleted
2024/11/20 01:14:35 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/20 01:14:35 INFO  : d: Removing directory
2024/11/20 01:14:35 INFO  : b: Removing directory
2024/11/20 01:14:36 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/20 01:14:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:14:39 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/20 01:14:40 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (19.29s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:14:43 DEBUG : empty space: md5 = 96034d91d4330522b7a2b0516e887a3a OK
2024/11/20 01:14:43 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/20 01:14:43 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2024/11/20 01:14:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:14:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:14:43 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:14:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:14:44 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/20 01:14:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:14:45 DEBUG : empty space: md5 = fad7b270b0b1ace98294a3a3bd288969 OK
2024/11/20 01:14:45 INFO  : empty space: Copied (replaced existing)
2024/11/20 01:14:45 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (6.57s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.45s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:14:50 DEBUG : foo: md5 = 8c013e869c5a5003836f3fd0f35a2ab4 OK
2024/11/20 01:14:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:14:50 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/20 01:14:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:14:52 DEBUG : foo: md5 = 26b90d7b8b53d44d4c5efe62042d17bb OK
2024/11/20 01:14:52 INFO  : foo: Copied (replaced existing)
2024/11/20 01:14:52 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (5.55s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:14:55 DEBUG : empty space: md5 = 18236e062847353164d57435f33a1eff OK
2024/11/20 01:14:56 DEBUG : potato: Need to transfer - File not found at Destination
2024/11/20 01:14:56 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:14:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:14:56 DEBUG : empty space: Unchanged skipping
2024/11/20 01:14:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:14:58 DEBUG : potato: md5 = e910656483584b65896639a011c31f77 OK
2024/11/20 01:14:58 INFO  : potato: Copied (new)
2024/11/20 01:14:58 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (6.59s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:15:02 DEBUG : potato: md5 = 0d51a5ceab81b4d0f23b9d247905dcd8 OK
2024/11/20 01:15:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:15:02 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2024/11/20 01:15:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:15:04 DEBUG : potato: md5 = d7583afa33632f2a96116cc18cd1c534 OK
2024/11/20 01:15:04 INFO  : potato: Copied (replaced existing)
2024/11/20 01:15:04 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (5.42s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:15:07 DEBUG : potato: md5 = aa6cfba26cbd7b6c09b3648587630663 OK
2024/11/20 01:15:08 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/20 01:15:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:15:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:15:09 DEBUG : potato: md5 = a11b877547fb82109cea0a86448b3641 OK
2024/11/20 01:15:09 INFO  : potato: Copied (replaced existing)
2024/11/20 01:15:09 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (5.62s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:15:13 DEBUG : potato: md5 = 37a64330fb9377830ab90844e1440a92 OK
2024/11/20 01:15:15 DEBUG : empty space: md5 = 5b6e089496f06be5d1791bceffd1b533 OK
2024/11/20 01:15:15 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/20 01:15:15 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2024/11/20 01:15:15 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:15:15 DEBUG : empty space: Unchanged skipping
2024/11/20 01:15:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:15:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:15:15 DEBUG : Waiting for deletions to finish
2024/11/20 01:15:15 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.91s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:15:19 DEBUG : potato: md5 = 96d5ea0a47244bfbedf59e091aa605a1 OK
2024/11/20 01:15:21 DEBUG : empty space: md5 = 7075cc42e988ffb1ea35ee5cfaba11c5 OK
2024/11/20 01:15:21 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/20 01:15:21 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:15:21 DEBUG : empty space: Unchanged skipping
2024/11/20 01:15:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:15:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:15:23 DEBUG : potato2: md5 = 94e9e7dc5c75b1f21be6c909283a877c OK
2024/11/20 01:15:23 INFO  : potato2: Copied (new)
2024/11/20 01:15:23 DEBUG : Waiting for deletions to finish
2024/11/20 01:15:23 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.82s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:15:29 DEBUG : b/potato: md5 = c0a22db8657fa3b92f8c43858b1c2306 OK
2024/11/20 01:15:32 DEBUG : c/non empty space: md5 = b712b9061fba99fb3fc9fd7ed1da2240 OK
2024/11/20 01:15:32 DEBUG : d: Making directory
2024/11/20 01:15:33 DEBUG : d/e: Making directory
2024/11/20 01:15:35 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/20 01:15:35 DEBUG : Added delayed dir = "c", newDst=c
2024/11/20 01:15:35 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:15:35 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/20 01:15:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:15:35 DEBUG : c/non empty space: Unchanged skipping
2024/11/20 01:15:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:15:38 DEBUG : a/potato2: md5 = 0a1a6f2aa1691ac4d5c89effbfdf5af0 OK
2024/11/20 01:15:38 INFO  : a/potato2: Copied (new)
2024/11/20 01:15:38 DEBUG : Waiting for deletions to finish
2024/11/20 01:15:39 INFO  : b/potato: Deleted
2024/11/20 01:15:39 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/20 01:15:39 INFO  : d/e: Removing directory
2024/11/20 01:15:40 INFO  : d: Removing directory
2024/11/20 01:15:40 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2024/11/20 01:15:41 INFO  : b: Removing directory
2024/11/20 01:15:41 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/20 01:15:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:15:45 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/20 01:15:45 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (20.82s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:15:50 DEBUG : b/potato: md5 = a1bcf59fd5a5a82d95fb438949f1cbef OK
2024/11/20 01:15:52 DEBUG : c/non empty space: md5 = 4f3dc8d6c3e232c9cf7b06f74692ba0b OK
2024/11/20 01:15:52 DEBUG : d: Making directory
2024/11/20 01:15:55 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/20 01:15:55 DEBUG : Added delayed dir = "c", newDst=c
2024/11/20 01:15:55 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:15:55 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/20 01:15:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:15:55 DEBUG : c/non empty space: Unchanged skipping
2024/11/20 01:15:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:15:57 DEBUG : a/potato2: md5 = c987aaa3729eac17560136f2422f73ca OK
2024/11/20 01:15:57 INFO  : a/potato2: Copied (new)
2024/11/20 01:15:57 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': not deleting files as there were IO errors
2024/11/20 01:15:58 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/20 01:15:58 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:16:02 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/20 01:16:03 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/20 01:16:04 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (18.10s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:16:07 DEBUG : potato: md5 = a0bc1a24177b54c7002bb1391609cf57 OK
2024/11/20 01:16:08 DEBUG : empty space: md5 = e887169ef4b0d70e8bff6d1fe9c9512d OK
2024/11/20 01:16:09 DEBUG : Waiting for deletions to finish
2024/11/20 01:16:09 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/20 01:16:09 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:16:09 DEBUG : empty space: Unchanged skipping
2024/11/20 01:16:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:16:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:16:09 INFO  : potato: Deleted
2024/11/20 01:16:10 DEBUG : potato2: md5 = 486d6e10c22082afbeec16da103505d8 OK
2024/11/20 01:16:10 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (8.20s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:16:15 DEBUG : potato: md5 = 6b5650101e2b1eacf21a5b11deb893f8 OK
2024/11/20 01:16:17 DEBUG : empty space: md5 = 086ebf13d16ccf37bf8f366607fb96bb OK
2024/11/20 01:16:17 DEBUG : Waiting for deletions to finish
2024/11/20 01:16:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:16:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:16:18 INFO  : potato: Deleted
2024/11/20 01:16:18 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/20 01:16:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:16:18 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:16:18 DEBUG : empty space: Unchanged skipping
2024/11/20 01:16:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:16:20 DEBUG : potato2: md5 = 1780a5e1635ea266bdb1079b1c03db00 OK
2024/11/20 01:16:20 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (9.43s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:16:24 DEBUG : potato: md5 = 0c2e5ce6aa8e2014d35047f245f01672 OK
2024/11/20 01:16:25 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/20 01:16:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:16:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:16:26 DEBUG : potato2: md5 = a7e696ba1a5ec432de347f83ccf50660 OK
2024/11/20 01:16:26 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (6.34s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:16:31 DEBUG : potato2: md5 = fd4a0118b4cec8fadf8dbe69bcd167ef OK
2024/11/20 01:16:32 DEBUG : empty space: md5 = 8b5673b2ad77d9660ee8ad108a2ad3ef OK
2024/11/20 01:16:33 DEBUG : enormous: Excluded (Size Filter)
2024/11/20 01:16:33 DEBUG : enormous: Excluded
2024/11/20 01:16:33 DEBUG : potato2: Excluded (Size Filter)
2024/11/20 01:16:33 DEBUG : potato2: Excluded
2024/11/20 01:16:33 DEBUG : potato2: Excluded (Size Filter)
2024/11/20 01:16:33 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:16:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:16:33 DEBUG : empty space: Unchanged skipping
2024/11/20 01:16:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:16:33 DEBUG : Waiting for deletions to finish
2024/11/20 01:16:33 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:16:33 DEBUG : enormous: Excluded (Size Filter)
2024/11/20 01:16:33 DEBUG : enormous: Excluded
2024/11/20 01:16:33 DEBUG : potato2: Excluded (Size Filter)
2024/11/20 01:16:33 DEBUG : potato2: Excluded
2024/11/20 01:16:33 DEBUG : potato2: Excluded (Size Filter)
2024/11/20 01:16:33 DEBUG : Local file system at /tmp/rclone2810207766: Waiting for checks to finish
2024/11/20 01:16:33 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/11/20 01:16:33 DEBUG : empty space: Unchanged skipping
2024/11/20 01:16:33 DEBUG : Local file system at /tmp/rclone2810207766: Waiting for transfers to finish
2024/11/20 01:16:33 DEBUG : Waiting for deletions to finish
2024/11/20 01:16:33 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncWithExclude (7.23s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:16:38 DEBUG : potato2: md5 = e8522968ef6ef3b1396c023380bdd9e2 OK
2024/11/20 01:16:40 DEBUG : empty space: md5 = b30015484b55bc7d48bd4fad9a29d530 OK
2024/11/20 01:16:41 DEBUG : enormous: md5 = 1a65b8d007559ad7e85b86ba1d9a25f4 OK
2024/11/20 01:16:42 DEBUG : enormous: Excluded (Size Filter)
2024/11/20 01:16:42 DEBUG : enormous: Excluded
2024/11/20 01:16:42 DEBUG : potato2: Excluded (Size Filter)
2024/11/20 01:16:42 DEBUG : potato2: Excluded
2024/11/20 01:16:42 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:16:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:16:42 DEBUG : empty space: Unchanged skipping
2024/11/20 01:16:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:16:42 DEBUG : Waiting for deletions to finish
2024/11/20 01:16:43 INFO  : potato2: Deleted
2024/11/20 01:16:43 INFO  : enormous: Deleted
2024/11/20 01:16:43 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:16:43 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/11/20 01:16:43 DEBUG : empty space: Unchanged skipping
2024/11/20 01:16:43 DEBUG : Local file system at /tmp/rclone2810207766: Waiting for checks to finish
2024/11/20 01:16:43 DEBUG : Local file system at /tmp/rclone2810207766: Waiting for transfers to finish
2024/11/20 01:16:43 DEBUG : Waiting for deletions to finish
2024/11/20 01:16:43 INFO  : enormous: Deleted
2024/11/20 01:16:43 INFO  : potato2: Deleted
2024/11/20 01:16:43 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (9.20s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:16:47 DEBUG : one: md5 = 99885690c2043aef39b20635df06fc28 OK
2024/11/20 01:16:49 DEBUG : two: md5 = 3e57f52d6711b4b5774a8e43b8a1ef85 OK
2024/11/20 01:16:51 DEBUG : three: md5 = e90a75cb6dd35dff04c26726ddbdc09f OK
2024/11/20 01:16:53 DEBUG : four: md5 = e7e1712c377c7a1f76cc5692192b1b46 OK
2024/11/20 01:16:53 DEBUG : five: Need to transfer - File not found at Destination
2024/11/20 01:16:53 DEBUG : four: Sizes differ (src 4 vs dst 8)
2024/11/20 01:16:53 DEBUG : one: Destination is newer than source, skipping
2024/11/20 01:16:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:16:53 DEBUG : three: Sizes identical
2024/11/20 01:16:53 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2024/11/20 01:16:53 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2024/11/20 01:16:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:16:55 DEBUG : four: md5 = ebe4c5f3b25805f3015904545543fd68 OK
2024/11/20 01:16:55 INFO  : four: Copied (replaced existing)
2024/11/20 01:16:55 DEBUG : two: md5 = b5c37be55bafc95e75bd22832313937e OK
2024/11/20 01:16:55 INFO  : two: Copied (replaced existing)
2024/11/20 01:16:55 DEBUG : five: md5 = 1008f82b2f0c61cbd2404ad07cc27df0 OK
2024/11/20 01:16:55 INFO  : five: Copied (new)
2024/11/20 01:16:55 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (13.45s)
=== 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-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2024/11/20 01:16:59 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Ignoring --track-renames as the source and destination do not have a common hash
2024/11/20 01:16:59 DEBUG : potato: Need to transfer - File not found at Destination
2024/11/20 01:16:59 DEBUG : yam: Need to transfer - File not found at Destination
2024/11/20 01:16:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:16:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:17:01 DEBUG : potato: md5 = a9bcb7f727d0be44a842c46df591f60e OK
2024/11/20 01:17:01 INFO  : potato: Copied (new)
2024/11/20 01:17:01 DEBUG : yam: md5 = fe79d9b6f9d10933544a0086bd6af962 OK
2024/11/20 01:17:01 INFO  : yam: Copied (new)
2024/11/20 01:17:01 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:17:01 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Ignoring --track-renames as the source and destination do not have a common hash
2024/11/20 01:17:01 DEBUG : yaml: Need to transfer - File not found at Destination
2024/11/20 01:17:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:17:01 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:17:01 DEBUG : potato: Unchanged skipping
2024/11/20 01:17:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:17:03 DEBUG : yaml: md5 = 3e9e3298160798c635d1ba7afcad054b OK
2024/11/20 01:17:03 INFO  : yaml: Copied (new)
2024/11/20 01:17:03 DEBUG : Waiting for deletions to finish
2024/11/20 01:17:03 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (7.61s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2024/11/20 01:17:07 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Making map for --track-renames
2024/11/20 01:17:07 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Finished making map for --track-renames
2024/11/20 01:17:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:17:07 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/11/20 01:17:07 DEBUG : yam: Need to transfer - No matching file found at Destination
2024/11/20 01:17:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for renames to finish
2024/11/20 01:17:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:17:08 DEBUG : yam: md5 = f540a77be1da9510e5b238a5a418175b OK
2024/11/20 01:17:08 INFO  : yam: Copied (new)
2024/11/20 01:17:08 DEBUG : potato: md5 = 470b06491a89662118f17d9ddee95db8 OK
2024/11/20 01:17:08 INFO  : potato: Copied (new)
2024/11/20 01:17:08 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:17:09 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:17:09 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Making map for --track-renames
2024/11/20 01:17:09 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Finished making map for --track-renames
2024/11/20 01:17:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:17:09 DEBUG : potato: Unchanged skipping
2024/11/20 01:17:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for renames to finish
2024/11/20 01:17:10 INFO  : yam: Moved (server-side) to: yaml
2024/11/20 01:17:10 INFO  : yaml: Renamed from "yam"
2024/11/20 01:17:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:17:10 DEBUG : Waiting for deletions to finish
2024/11/20 01:17:10 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (6.58s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2024/11/20 01:17:13 DEBUG : Added delayed dir = "sub", newDst=<nil>
2024/11/20 01:17:13 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Making map for --track-renames
2024/11/20 01:17:13 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Finished making map for --track-renames
2024/11/20 01:17:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:17:13 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/11/20 01:17:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for renames to finish
2024/11/20 01:17:13 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2024/11/20 01:17:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:17:16 DEBUG : potato: md5 = 5bf16c6db0b4cb1420baa3aabae96891 OK
2024/11/20 01:17:16 INFO  : potato: Copied (new)
2024/11/20 01:17:16 DEBUG : sub/yam: md5 = 9a78e6f7dc23638d31432d0a27b3c92a OK
2024/11/20 01:17:16 INFO  : sub/yam: Copied (new)
2024/11/20 01:17:16 DEBUG : Waiting for deletions to finish
2024/11/20 01:17:17 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:17:18 DEBUG : Added delayed dir = "sub", newDst=sub
2024/11/20 01:17:18 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:17:18 DEBUG : potato: Unchanged skipping
2024/11/20 01:17:18 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Making map for --track-renames
2024/11/20 01:17:18 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Finished making map for --track-renames
2024/11/20 01:17:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:17:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for renames to finish
2024/11/20 01:17:19 INFO  : sub/yam: Moved (server-side) to: yam
2024/11/20 01:17:19 INFO  : yam: Renamed from "sub/yam"
2024/11/20 01:17:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:17:19 DEBUG : Waiting for deletions to finish
2024/11/20 01:17:19 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (10.32s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:17:23 DEBUG : Creating backend with remote "/tmp/rclone2810207766/dir1"
2024/11/20 01:17:23 DEBUG : Creating backend with remote "/tmp/rclone2810207766/dir2"
2024/11/20 01:17:23 DEBUG : Local file system at /tmp/rclone2810207766/dir2: Using server-side directory move
2024/11/20 01:17:23 INFO  : Local file system at /tmp/rclone2810207766/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/20 01:17:23 DEBUG : file1.txt: Need to transfer - File not found at Destination
2024/11/20 01:17:23 INFO  : file1.txt: Moved (server-side)
2024/11/20 01:17:23 DEBUG : Local file system at /tmp/rclone2810207766/dir2: Waiting for checks to finish
2024/11/20 01:17:23 DEBUG : Local file system at /tmp/rclone2810207766/dir2: Waiting for transfers to finish
--- PASS: TestServerSideMoveLocal (0.58s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:17:24 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/11/20 01:17:24 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/20 01:17:24 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/20 01:17:24 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/11/20 01:17:24 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/11/20 01:17:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:17:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:17:27 DEBUG : sub dir/hello world: md5 = e5da59e1d94f677742e76186feaba409 OK
2024/11/20 01:17:27 INFO  : sub dir/hello world: Copied (new)
2024/11/20 01:17:27 INFO  : sub dir/hello world: Deleted
2024/11/20 01:17:29 DEBUG : nested/sub dir/file: md5 = ec208d01c0e016fdc384c3d438ecda53 OK
2024/11/20 01:17:29 INFO  : nested/sub dir/file: Copied (new)
2024/11/20 01:17:29 INFO  : nested/sub dir/file: Deleted
2024/11/20 01:17:30 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/11/20 01:17:30 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/20 01:17:30 INFO  : nested: Set directory modification time (using DirSetModTime)
2024/11/20 01:17:30 INFO  : sub dir: Removing directory
2024/11/20 01:17:30 INFO  : nested/sub dir: Removing directory
2024/11/20 01:17:30 INFO  : nested: Removing directory
2024/11/20 01:17:30 DEBUG : Local file system at /tmp/rclone2810207766: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:17:33 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/20 01:17:34 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/11/20 01:17:35 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (12.74s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:17:37 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/11/20 01:17:37 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/20 01:17:37 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/20 01:17:37 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/11/20 01:17:37 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/11/20 01:17:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:17:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:17:40 DEBUG : sub dir/hello world: md5 = ae6ff751c2bd1faeca873dc54a06de73 OK
2024/11/20 01:17:40 INFO  : sub dir/hello world: Copied (new)
2024/11/20 01:17:40 INFO  : sub dir/hello world: Deleted
2024/11/20 01:17:42 DEBUG : nested/sub dir/file: md5 = 5e855845867060f79ee46bef21cbe056 OK
2024/11/20 01:17:42 INFO  : nested/sub dir/file: Copied (new)
2024/11/20 01:17:42 INFO  : nested/sub dir/file: Deleted
2024/11/20 01:17:43 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/11/20 01:17:43 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/20 01:17:43 INFO  : nested: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:17:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/20 01:17:47 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/11/20 01:17:48 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (12.90s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:17:50 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/20 01:17:50 DEBUG : existing-b: Need to transfer - File not found at Destination
2024/11/20 01:17:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:17:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:17:51 DEBUG : existing: md5 = 56a5f56afc970a5b5c692582f12dadb8 OK
2024/11/20 01:17:51 INFO  : existing: Copied (new)
2024/11/20 01:17:51 INFO  : existing: Deleted
2024/11/20 01:17:51 DEBUG : existing-b: md5 = ac7ccc1ad37eaf765a5a4fb2aba98a52 OK
2024/11/20 01:17:51 INFO  : existing-b: Copied (new)
2024/11/20 01:17:51 INFO  : existing-b: Deleted
2024/11/20 01:17:52 DEBUG : existing: Destination exists, skipping
2024/11/20 01:17:52 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2024/11/20 01:17:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:17:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:17:52 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (4.88s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:17:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bahojoq5meka"
2024/11/20 01:17:54 DEBUG : Creating backend with remote "TestDrive:crypt/tsou5m34041l670maurhnfu71lvu7gqqoimm9ibfcgh86c1lle3g"
2024/11/20 01:17:57 DEBUG : potato2: md5 = 67dcbfa61bf08da22ab1ffe5a470c8a4 OK
2024/11/20 01:17:59 DEBUG : empty space: md5 = 873624f9f5e75e30ea667300f9907dcf OK
2024/11/20 01:18:00 DEBUG : potato3: md5 = 63a0f5c519bf2a06181c32d455850302 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa' -> Encrypted drive 'TestCryptDrive:rclone-test-bahojoq5meka'
2024/11/20 01:18:03 DEBUG : empty space: md5 = 7ac3af3a50548f18afe48207870c4298 OK
2024/11/20 01:18:05 DEBUG : potato3: md5 = dfb32d4d6f1e324156a1b2b705ed333f OK
2024/11/20 01:18:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bahojoq5meka': Using server-side directory move
2024/11/20 01:18:05 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-bahojoq5meka': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/20 01:18:06 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/20 01:18:06 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/11/20 01:18:06 DEBUG : empty space: Unchanged skipping
2024/11/20 01:18:06 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/20 01:18:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bahojoq5meka': Waiting for checks to finish
2024/11/20 01:18:06 INFO  : potato3: Deleted
2024/11/20 01:18:06 INFO  : empty space: Deleted
2024/11/20 01:18:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bahojoq5meka': Waiting for transfers to finish
2024/11/20 01:18:07 INFO  : potato2: Moved (server-side)
2024/11/20 01:18:07 INFO  : potato3: Moved (server-side)
2024/11/20 01:18:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-miwavon2yoli"
2024/11/20 01:18:08 DEBUG : Creating backend with remote "TestDrive:crypt/qoj7vh7uddlvdquttaa9qgt3n7ige98tcr3rta8lj9notphimkfg"
2024/11/20 01:18:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-miwavon2yoli': Using server-side directory move
2024/11/20 01:18:10 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-miwavon2yoli': Server side directory move succeeded
2024/11/20 01:18:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-miwavon2yoli': Purge remote
2024/11/20 01:18:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bahojoq5meka': Purge remote
2024/11/20 01:18:12 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (17.81s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:18:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-birofit9zaju"
2024/11/20 01:18:12 DEBUG : Creating backend with remote "TestDrive:crypt/643ebnaffe9sa4vb4kniqhg84gkd7f57uu7oi4dueiofde7m9tr0"
2024/11/20 01:18:15 DEBUG : potato2: md5 = bfdaeeef2a1a6d854d0b40f76245c661 OK
2024/11/20 01:18:17 DEBUG : empty space: md5 = e77f16d4aa8a7e51dc6432e98a94e0d2 OK
2024/11/20 01:18:18 DEBUG : potato3: md5 = 0e6a4715c14cf3ad355bf86b7131509c OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa' -> Encrypted drive 'TestCryptDrive:rclone-test-birofit9zaju'
2024/11/20 01:18:21 DEBUG : empty space: md5 = 95d9e0783f6549bb8a273925e1e56375 OK
2024/11/20 01:18:23 DEBUG : potato3: md5 = aa23cf7fe6ce0329c0ff42ff138ef3b9 OK
2024/11/20 01:18:24 DEBUG : empty space: Excluded (Size Filter)
2024/11/20 01:18:24 DEBUG : empty space: Excluded (Size Filter)
2024/11/20 01:18:24 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/20 01:18:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-birofit9zaju': Waiting for checks to finish
2024/11/20 01:18:24 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/20 01:18:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-birofit9zaju': Waiting for transfers to finish
2024/11/20 01:18:24 INFO  : potato3: Deleted
2024/11/20 01:18:25 INFO  : potato2: Moved (server-side)
2024/11/20 01:18:25 INFO  : potato3: Moved (server-side)
2024/11/20 01:18:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bigeyex1tolo"
2024/11/20 01:18:26 DEBUG : Creating backend with remote "TestDrive:crypt/dimull9hk4gjg2sj795uvccsip4ava6jrji48ns4rr10l2c1pl5g"
2024/11/20 01:18:27 DEBUG : empty space: Excluded (Size Filter)
2024/11/20 01:18:27 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/20 01:18:27 DEBUG : potato3: Need to transfer - File not found at Destination
2024/11/20 01:18:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bigeyex1tolo': Waiting for checks to finish
2024/11/20 01:18:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bigeyex1tolo': Waiting for transfers to finish
2024/11/20 01:18:29 INFO  : potato2: Moved (server-side)
2024/11/20 01:18:30 INFO  : potato3: Moved (server-side)
2024/11/20 01:18:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bigeyex1tolo': Purge remote
2024/11/20 01:18:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-birofit9zaju': Purge remote
--- PASS: TestServerSideMoveWithFilter (20.20s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:18:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pubajev2fisi"
2024/11/20 01:18:32 DEBUG : Creating backend with remote "TestDrive:crypt/ieni55h559qgpfsi40g202ac1tecgjp6rq5ehbin18uoa6r65p90"
2024/11/20 01:18:35 DEBUG : potato2: md5 = 0d724c7b94886a88946c0f9ff286693a OK
2024/11/20 01:18:37 DEBUG : empty space: md5 = 5789052451d66705eaa175df386b478f OK
2024/11/20 01:18:38 DEBUG : potato3: md5 = 084ceed3664dd45713782417afed09e8 OK
2024/11/20 01:18:38 DEBUG : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa' -> Encrypted drive 'TestCryptDrive:rclone-test-pubajev2fisi'
2024/11/20 01:18:43 DEBUG : empty space: md5 = 389bea1f7a71e5ce33d588a218a80626 OK
2024/11/20 01:18:45 DEBUG : potato3: md5 = 4375e3b897a71b2ae1c1617576dabacd OK
2024/11/20 01:18:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pubajev2fisi': Using server-side directory move
2024/11/20 01:18:45 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pubajev2fisi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/20 01:18:45 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/20 01:18:45 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2024/11/20 01:18:45 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/11/20 01:18:45 DEBUG : empty space: Unchanged skipping
2024/11/20 01:18:45 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/20 01:18:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pubajev2fisi': Waiting for checks to finish
2024/11/20 01:18:46 INFO  : empty space: Deleted
2024/11/20 01:18:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pubajev2fisi': Waiting for transfers to finish
2024/11/20 01:18:46 INFO  : potato2: Moved (server-side)
2024/11/20 01:18:47 INFO  : potato3: Deleted
2024/11/20 01:18:48 INFO  : potato3: Moved (server-side)
2024/11/20 01:18:48 INFO  : tomatoDir: Removing directory
2024/11/20 01:18:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': deleted 1 directories
2024/11/20 01:18:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nexited0bonu"
2024/11/20 01:18:50 DEBUG : Creating backend with remote "TestDrive:crypt/gue4hbqk5h02712dt29kq1d51k1qdoa83mvkjmhcomogi514l600"
2024/11/20 01:18:51 DEBUG : tomatoDir: Making directory
2024/11/20 01:18:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nexited0bonu': Using server-side directory move
2024/11/20 01:18:53 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-nexited0bonu': Server side directory move succeeded
2024/11/20 01:18:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nexited0bonu': Purge remote
2024/11/20 01:18:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pubajev2fisi': Purge remote
2024/11/20 01:18:56 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (23.89s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.43s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:18:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/rclone-sync-test"
2024/11/20 01:18:57 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncOverlap (4.48s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:19:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/rclone-sync-test"
2024/11/20 01:19:01 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2024/11/20 01:19:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/rclone-sync-test-include/layer2"
2024/11/20 01:19:04 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2024/11/20 01:19:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/rclone-sync-test-ignore-file"
2024/11/20 01:19:07 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2024/11/20 01:19:12 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = a22be9180c23902390d96ffea3db8ae0 OK
2024/11/20 01:19:14 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/20 01:19:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/rclone-sync-test': Waiting for checks to finish
2024/11/20 01:19:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/rclone-sync-test': Waiting for transfers to finish
2024/11/20 01:19:14 DEBUG : Waiting for deletions to finish
2024/11/20 01:19:14 INFO  : There was nothing to transfer
2024/11/20 01:19:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:19:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:19:16 DEBUG : Waiting for deletions to finish
2024/11/20 01:19:16 INFO  : rclone-sync-test-include: Removing directory
2024/11/20 01:19:16 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/20 01:19:16 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/11/20 01:19:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': failed to delete 1 directories
2024/11/20 01:19:16 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:19:19 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/20 01:19:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/rclone-sync-test-include/layer2': Waiting for checks to finish
2024/11/20 01:19:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/rclone-sync-test-include/layer2': Waiting for transfers to finish
2024/11/20 01:19:19 DEBUG : Waiting for deletions to finish
2024/11/20 01:19:19 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:19:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:19:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:19:21 DEBUG : Waiting for deletions to finish
2024/11/20 01:19:21 INFO  : rclone-sync-test-include: Removing directory
2024/11/20 01:19:21 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/20 01:19:21 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/11/20 01:19:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': failed to delete 1 directories
2024/11/20 01:19:21 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:19:23 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/20 01:19:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/rclone-sync-test-ignore-file': Waiting for checks to finish
2024/11/20 01:19:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/rclone-sync-test-ignore-file': Waiting for transfers to finish
2024/11/20 01:19:23 DEBUG : Waiting for deletions to finish
2024/11/20 01:19:23 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:19:26 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/20 01:19:27 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (36.49s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:19:38 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/dst"
2024/11/20 01:19:38 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/20 01:19:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/CompareDest"
2024/11/20 01:19:39 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/gveqi14airsml4bgu7krj116o8"
2024/11/20 01:19:41 DEBUG : one: Need to transfer - File not found at Destination
2024/11/20 01:19:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:19:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:19:44 DEBUG : one: md5 = 2a12e71e04a3927fce359e0ec08b7c27 OK
2024/11/20 01:19:44 INFO  : one: Copied (new)
2024/11/20 01:19:44 DEBUG : Waiting for deletions to finish
2024/11/20 01:19:45 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/20 01:19:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:19:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:19:47 DEBUG : one: md5 = 51d7d08da5f7f71bb06ca7ba212b9383 OK
2024/11/20 01:19:47 INFO  : one: Copied (replaced existing)
2024/11/20 01:19:47 DEBUG : Waiting for deletions to finish
2024/11/20 01:19:49 DEBUG : dst/one: md5 = 388478f79b3e35c2d0998bbd865861df OK
2024/11/20 01:19:52 DEBUG : CompareDest/one: md5 = 4cb56d57378786fb508e3173ce07308f OK
2024/11/20 01:19:53 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/20 01:19:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:19:54 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:19:54 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/20 01:19:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:19:54 DEBUG : Waiting for deletions to finish
2024/11/20 01:19:54 INFO  : There was nothing to transfer
2024/11/20 01:19:56 DEBUG : CompareDest/two: md5 = 0e9ff6973037dbf06315fdd78b0201e0 OK
2024/11/20 01:19:57 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:19:57 DEBUG : two: Destination found in --compare-dest, skipping
2024/11/20 01:19:57 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/20 01:19:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:19:57 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:19:57 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/20 01:19:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:19:57 DEBUG : Waiting for deletions to finish
2024/11/20 01:19:57 INFO  : There was nothing to transfer
2024/11/20 01:19:58 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:19:58 DEBUG : two: Destination found in --compare-dest, skipping
2024/11/20 01:19:58 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/20 01:19:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:19:59 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:19:59 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/20 01:19:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:19:59 DEBUG : Waiting for deletions to finish
2024/11/20 01:19:59 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2024/11/20 01:20:01 DEBUG : two: Sizes differ (src 5 vs dst 3)
2024/11/20 01:20:01 DEBUG : two: Need to transfer - File not found at Destination
2024/11/20 01:20:01 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/20 01:20:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:20:01 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:20:01 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/20 01:20:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:20:03 DEBUG : two: md5 = 49c2d99eba81d5f5b6da1071f4641dee OK
2024/11/20 01:20:03 INFO  : two: Copied (new)
2024/11/20 01:20:03 DEBUG : Waiting for deletions to finish
2024/11/20 01:20:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/20 01:20:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/20 01:20:08 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/20 01:20:08 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCompareDest (30.91s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:20:11 DEBUG : pre-dest1/1: md5 = 6febec92042d37e2f5c52aad994f43eb OK
2024/11/20 01:20:14 DEBUG : pre-dest2/2: md5 = 82568670531886b17d72c2c80a7b5066 OK
2024/11/20 01:20:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/dest"
2024/11/20 01:20:15 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/rg03c1jvnehrrc617i0lnqjddc"
2024/11/20 01:20:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/pre-dest1"
2024/11/20 01:20:16 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/bbnblvh6k061ssopqrp18kd7gc"
2024/11/20 01:20:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/pre-dest2"
2024/11/20 01:20:18 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/dgicm1h6b5ejvlltm8eeif0bnk"
2024/11/20 01:20:19 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:20:19 DEBUG : 1: Destination found in --compare-dest, skipping
2024/11/20 01:20:19 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:20:19 DEBUG : 2: Destination found in --compare-dest, skipping
2024/11/20 01:20:20 DEBUG : 3: Need to transfer - File not found at Destination
2024/11/20 01:20:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dest': Waiting for checks to finish
2024/11/20 01:20:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dest': Waiting for transfers to finish
2024/11/20 01:20:23 DEBUG : 3: md5 = 8414c2aec1c16fab0e8e838f5d69a991 OK
2024/11/20 01:20:23 INFO  : 3: Copied (new)
2024/11/20 01:20:23 DEBUG : Waiting for deletions to finish
2024/11/20 01:20:26 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2024/11/20 01:20:27 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2024/11/20 01:20:28 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (20.63s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:20:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/dst"
2024/11/20 01:20:29 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/20 01:20:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/CopyDest"
2024/11/20 01:20:31 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/d09o6po3f7bm6ce32vdgs8h9ls"
2024/11/20 01:20:33 DEBUG : one: Need to transfer - File not found at Destination
2024/11/20 01:20:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:20:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:20:36 DEBUG : one: md5 = 5f7da7fe089d136d0f9f36502c90535b OK
2024/11/20 01:20:36 INFO  : one: Copied (new)
2024/11/20 01:20:36 DEBUG : Waiting for deletions to finish
2024/11/20 01:20:37 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/20 01:20:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:20:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:20:39 DEBUG : one: md5 = 26d086ca8a46f227ba66e33792b8fd35 OK
2024/11/20 01:20:39 INFO  : one: Copied (replaced existing)
2024/11/20 01:20:39 DEBUG : Waiting for deletions to finish
2024/11/20 01:20:41 DEBUG : dst/one: md5 = 151d130f35c401c9f915926bd57a2f44 OK
2024/11/20 01:20:44 DEBUG : CopyDest/one: md5 = a660723eb3f53917b270c10df9563af8 OK
2024/11/20 01:20:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/BackupDir"
2024/11/20 01:20:44 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/s6dbk3lfi7c9kfvo6j7bla9m0g"
2024/11/20 01:20:46 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/20 01:20:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:20:47 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:20:47 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/20 01:20:49 INFO  : one: Moved (server-side)
2024/11/20 01:20:50 INFO  : one: Copied (server-side copy)
2024/11/20 01:20:50 DEBUG : one: Destination found in --copy-dest, using server-side copy
2024/11/20 01:20:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:20:50 DEBUG : Waiting for deletions to finish
2024/11/20 01:20:52 DEBUG : CopyDest/two: md5 = 5ed01db8a0c8f5cd8de812174812b17a OK
2024/11/20 01:20:53 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:20:56 INFO  : two: Copied (server-side copy)
2024/11/20 01:20:56 DEBUG : two: Destination found in --copy-dest, using server-side copy
2024/11/20 01:20:56 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:20:56 DEBUG : one: Unchanged skipping
2024/11/20 01:20:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:20:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:20:56 DEBUG : Waiting for deletions to finish
2024/11/20 01:20:58 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:20:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:20:58 DEBUG : two: Unchanged skipping
2024/11/20 01:20:58 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:20:58 DEBUG : one: Unchanged skipping
2024/11/20 01:20:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:20:58 DEBUG : Waiting for deletions to finish
2024/11/20 01:20:58 INFO  : There was nothing to transfer
2024/11/20 01:21:01 DEBUG : CopyDest/three: md5 = 42130e586e5074fbd776076c16d52b3e OK
2024/11/20 01:21:03 DEBUG : three: Sizes differ (src 7 vs dst 5)
2024/11/20 01:21:03 DEBUG : three: Destination not found in --copy-dest
2024/11/20 01:21:03 DEBUG : three: Need to transfer - File not found at Destination
2024/11/20 01:21:03 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:21:03 DEBUG : one: Unchanged skipping
2024/11/20 01:21:03 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/20 01:21:03 DEBUG : two: Unchanged skipping
2024/11/20 01:21:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:21:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:21:05 DEBUG : three: md5 = f8ffc06575addcf9ac4a4077d18620c0 OK
2024/11/20 01:21:05 INFO  : three: Copied (new)
2024/11/20 01:21:05 DEBUG : Waiting for deletions to finish
2024/11/20 01:21:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/11/20 01:21:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/20 01:21:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/20 01:21:12 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/20 01:21:12 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/11/20 01:21:12 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/20 01:21:12 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (44.07s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:21:16 DEBUG : dst/one: md5 = bc28acd56ccbd609dac6a1bac9bb8b57 OK
2024/11/20 01:21:18 DEBUG : dst/two: md5 = f35dedc89846814efebb3200eb7acdc3 OK
2024/11/20 01:21:20 DEBUG : dst/three.txt: md5 = 4a4e2b31217dd7a7ee07f325d258ee72 OK
2024/11/20 01:21:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/dst"
2024/11/20 01:21:20 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/20 01:21:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/backup"
2024/11/20 01:21:21 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/1nrff024r7pq65ecp72fc28jb0"
2024/11/20 01:21:24 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/20 01:21:24 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:21:24 DEBUG : two: Unchanged skipping
2024/11/20 01:21:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:21:26 INFO  : one: Moved (server-side)
2024/11/20 01:21:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:21:28 DEBUG : one: md5 = 3523cdd4bc9eac827fa64f5541d10209 OK
2024/11/20 01:21:28 INFO  : one: Copied (new)
2024/11/20 01:21:28 DEBUG : Waiting for deletions to finish
2024/11/20 01:21:29 INFO  : three.txt: Moved (server-side)
2024/11/20 01:21:29 INFO  : three.txt: Moved into backup dir
2024/11/20 01:21:32 DEBUG : dst/three.txt: md5 = 0d7129e40916a5dd32f96542b0d83c2c OK
2024/11/20 01:21:33 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/20 01:21:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:21:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:21:33 DEBUG : two: Unchanged skipping
2024/11/20 01:21:34 INFO  : one: Deleted
2024/11/20 01:21:35 INFO  : one: Moved (server-side)
2024/11/20 01:21:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:21:37 DEBUG : one: md5 = 78c8dfd3662e765357905d0ca09987db OK
2024/11/20 01:21:37 INFO  : one: Copied (new)
2024/11/20 01:21:37 DEBUG : Waiting for deletions to finish
2024/11/20 01:21:38 INFO  : three.txt: Deleted
2024/11/20 01:21:39 INFO  : three.txt: Moved (server-side)
2024/11/20 01:21:39 INFO  : three.txt: Moved into backup dir
2024/11/20 01:21:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/20 01:21:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/20 01:21:45 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/20 01:21:45 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/20 01:21:45 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/20 01:21:45 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
--- PASS: TestSyncBackupDir (32.30s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:21:49 DEBUG : dst/one: md5 = e5e244d4eaa3064f8fe84413d51cdfb6 OK
2024/11/20 01:21:50 DEBUG : dst/two: md5 = e62078b6fdd546bfbce463bc27fb5f9e OK
2024/11/20 01:21:52 DEBUG : dst/three.txt: md5 = 9e276fe781a6aabcd21cbc5a0aad1132 OK
2024/11/20 01:21:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/dst"
2024/11/20 01:21:53 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/20 01:21:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/backup"
2024/11/20 01:21:54 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/1nrff024r7pq65ecp72fc28jb0"
2024/11/20 01:21:56 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/20 01:21:56 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:21:56 DEBUG : two: Unchanged skipping
2024/11/20 01:21:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:21:58 INFO  : one: Moved (server-side) to: one.bak
2024/11/20 01:21:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:22:00 DEBUG : one: md5 = 7e08e8d3e7c6d8e5d19f5aad52cc29f0 OK
2024/11/20 01:22:00 INFO  : one: Copied (new)
2024/11/20 01:22:00 DEBUG : Waiting for deletions to finish
2024/11/20 01:22:01 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/20 01:22:01 INFO  : three.txt: Moved into backup dir
2024/11/20 01:22:04 DEBUG : dst/three.txt: md5 = f9c461c33a5f6fc24ee8919705bcf094 OK
2024/11/20 01:22:05 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/20 01:22:05 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:22:05 DEBUG : two: Unchanged skipping
2024/11/20 01:22:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:22:05 INFO  : one.bak: Deleted
2024/11/20 01:22:06 INFO  : one: Moved (server-side) to: one.bak
2024/11/20 01:22:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:22:06 DEBUG : TestDrive: Loaded invalid token from config file - ignoring
2024/11/20 01:22:07 DEBUG : Saving config "token" in section "TestDrive" of the config file
2024/11/20 01:22:07 DEBUG : TestDrive: Saved new token in config file
2024/11/20 01:22:08 DEBUG : one: md5 = f6dbf48fba83a03b223e717b976605f9 OK
2024/11/20 01:22:08 INFO  : one: Copied (new)
2024/11/20 01:22:08 DEBUG : Waiting for deletions to finish
2024/11/20 01:22:08 DEBUG : TestDrive: Loaded fresh token from config file
2024/11/20 01:22:09 INFO  : three.txt.bak: Deleted
2024/11/20 01:22:10 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/20 01:22:10 INFO  : three.txt: Moved into backup dir
2024/11/20 01:22:10 DEBUG : TestDrive: Loaded fresh token from config file
2024/11/20 01:22:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/20 01:22:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/20 01:22:16 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/20 01:22:16 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/20 01:22:16 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/20 01:22:16 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirWithSuffix (31.42s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:22:19 DEBUG : dst/one: md5 = d1563f90a3ec8f72128bfd143354ae6c OK
2024/11/20 01:22:21 DEBUG : dst/two: md5 = 713eefe5dc24560d6f44e2b730b0f00b OK
2024/11/20 01:22:23 DEBUG : dst/three.txt: md5 = b5fd6fb1517efc8facfb74dfd4730e04 OK
2024/11/20 01:22:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/dst"
2024/11/20 01:22:24 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/20 01:22:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/backup"
2024/11/20 01:22:24 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/1nrff024r7pq65ecp72fc28jb0"
2024/11/20 01:22:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:22:27 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/20 01:22:27 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:22:27 DEBUG : two: Unchanged skipping
2024/11/20 01:22:29 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/20 01:22:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:22:31 DEBUG : one: md5 = 9482e0c7af0db10b216930489dec08d7 OK
2024/11/20 01:22:31 INFO  : one: Copied (new)
2024/11/20 01:22:31 DEBUG : Waiting for deletions to finish
2024/11/20 01:22:33 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/20 01:22:33 INFO  : three.txt: Moved into backup dir
2024/11/20 01:22:35 DEBUG : dst/three.txt: md5 = ba88e6bdaa817e52fbcb68aed4e2bdaf OK
2024/11/20 01:22:36 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/20 01:22:36 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:22:36 DEBUG : two: Unchanged skipping
2024/11/20 01:22:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:22:37 INFO  : one-2019-01-01: Deleted
2024/11/20 01:22:38 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/20 01:22:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:22:40 DEBUG : one: md5 = 945e4c7565935318c9a6fd081d8f3a8b OK
2024/11/20 01:22:40 INFO  : one: Copied (new)
2024/11/20 01:22:40 DEBUG : Waiting for deletions to finish
2024/11/20 01:22:41 INFO  : three-2019-01-01.txt: Deleted
2024/11/20 01:22:42 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/20 01:22:42 INFO  : three.txt: Moved into backup dir
2024/11/20 01:22:45 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/20 01:22:45 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/20 01:22:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/20 01:22:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/20 01:22:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/20 01:22:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (30.06s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:22:50 DEBUG : dst/one: md5 = 302c11a3e03eeff066db40bd6acf2530 OK
2024/11/20 01:22:51 DEBUG : dst/two: md5 = 5f7d8d6219f92480f67f5b4be52f2fec OK
2024/11/20 01:22:53 DEBUG : dst/three.txt: md5 = 6ff96ced27d539c79db2c069d6fce68e OK
2024/11/20 01:22:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/dst"
2024/11/20 01:22:54 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/20 01:22:55 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/20 01:22:55 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:22:55 DEBUG : two: Unchanged skipping
2024/11/20 01:22:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:22:56 INFO  : one: Moved (server-side) to: one.bak
2024/11/20 01:22:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:22:57 DEBUG : one: md5 = ee1988e520ed5c43e8a6649787eda1b6 OK
2024/11/20 01:22:57 INFO  : one: Copied (new)
2024/11/20 01:22:57 DEBUG : Waiting for deletions to finish
2024/11/20 01:22:58 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/20 01:22:58 INFO  : three.txt: Moved into backup dir
2024/11/20 01:23:00 DEBUG : dst/three.txt: md5 = fc0932382726cbff30012af4fd86ce3b OK
2024/11/20 01:23:01 DEBUG : three.txt.bak: Excluded (Path Filter)
2024/11/20 01:23:01 DEBUG : one.bak: Excluded (Path Filter)
2024/11/20 01:23:01 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/20 01:23:01 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:23:01 DEBUG : two: Unchanged skipping
2024/11/20 01:23:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for checks to finish
2024/11/20 01:23:02 INFO  : one.bak: Deleted
2024/11/20 01:23:03 INFO  : one: Moved (server-side) to: one.bak
2024/11/20 01:23:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa/dst': Waiting for transfers to finish
2024/11/20 01:23:04 DEBUG : one: md5 = 0ebce86bad90dbabba6a55c5645095fb OK
2024/11/20 01:23:04 INFO  : one: Copied (new)
2024/11/20 01:23:04 DEBUG : Waiting for deletions to finish
2024/11/20 01:23:05 INFO  : three.txt.bak: Deleted
2024/11/20 01:23:19 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/20 01:23:19 INFO  : three.txt: Moved into backup dir
2024/11/20 01:23:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/20 01:23:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/20 01:23:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/20 01:23:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/20 01:23:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/20 01:23:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirSuffixOnly (37.40s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:23:32 DEBUG : dst/one: md5 = facc4c6889ca161333394bd9eb6d7ea4 OK
2024/11/20 01:23:34 DEBUG : dst/two: md5 = d7baabbac34cd979eb29dfa3c659eb7c OK
2024/11/20 01:23:41 DEBUG : dst/three.txt: md5 = edae8c33f12cbde3067228c7f730f41f OK
2024/11/20 01:23:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/dst"
2024/11/20 01:23:42 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/20 01:23:43 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/20 01:23:44 INFO  : one: Moved (server-side) to: one.bak
2024/11/20 01:23:46 DEBUG : one: md5 = 9a2b42f5977c7d48d47150a9a63d8c4f OK
2024/11/20 01:23:46 INFO  : one: Copied (new)
2024/11/20 01:23:46 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:23:46 DEBUG : two: Unchanged skipping
2024/11/20 01:23:46 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/11/20 01:23:47 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/20 01:23:49 DEBUG : three.txt: md5 = cc45e9517d8c1118a77ce9f465f65913 OK
2024/11/20 01:23:49 INFO  : three.txt: Copied (new)
2024/11/20 01:23:50 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/20 01:23:51 INFO  : one.bak: Deleted
2024/11/20 01:23:51 INFO  : one: Moved (server-side) to: one.bak
2024/11/20 01:23:53 DEBUG : one: md5 = e0d7476d5970b079f2bc913c8e6f4f26 OK
2024/11/20 01:23:53 INFO  : one: Copied (new)
2024/11/20 01:23:53 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:23:53 DEBUG : two: Unchanged skipping
2024/11/20 01:23:54 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/11/20 01:23:54 INFO  : three.txt.bak: Deleted
2024/11/20 01:23:55 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/20 01:23:57 DEBUG : three.txt: md5 = 06bf11f505dadf56be4feec44b169064 OK
2024/11/20 01:23:57 INFO  : three.txt: Copied (new)
2024/11/20 01:24:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/20 01:24:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/20 01:24:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/20 01:24:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/20 01:24:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/20 01:24:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/20 01:24:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncSuffix (40.12s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:24:07 DEBUG : dst/one: md5 = 975cca25308693ca424a886d0d333efb OK
2024/11/20 01:24:09 DEBUG : dst/two: md5 = 5b429ca062aec907b6a4190a00ef9323 OK
2024/11/20 01:24:11 DEBUG : dst/three.txt: md5 = a0bd2b747c1b57cdd455a11e2bc2f417 OK
2024/11/20 01:24:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fakohox8mufa/dst"
2024/11/20 01:24:11 DEBUG : Creating backend with remote "TestDrive:crypt/dmd6i06agfd26nt60bjsnfm0fijmtal2tvtb2vq79t5cfvqdple0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/20 01:24:12 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/20 01:24:13 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/20 01:24:15 DEBUG : one: md5 = 1968df0b6d2602971a00fc5976a77d4e OK
2024/11/20 01:24:15 INFO  : one: Copied (new)
2024/11/20 01:24:15 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:24:15 DEBUG : two: Unchanged skipping
2024/11/20 01:24:16 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/11/20 01:24:16 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/20 01:24:18 DEBUG : three.txt: md5 = 003f2413f4e3d1e168698c316a98b5a9 OK
2024/11/20 01:24:18 INFO  : three.txt: Copied (new)
2024/11/20 01:24:20 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/20 01:24:20 INFO  : one-2019-01-01: Deleted
2024/11/20 01:24:21 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/20 01:24:23 DEBUG : one: md5 = 53c13e2407a031b2827dde70f5443436 OK
2024/11/20 01:24:23 INFO  : one: Copied (new)
2024/11/20 01:24:23 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:24:23 DEBUG : two: Unchanged skipping
2024/11/20 01:24:23 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/11/20 01:24:24 INFO  : three-2019-01-01.txt: Deleted
2024/11/20 01:24:25 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/20 01:24:27 DEBUG : three.txt: md5 = c59ab60aa827b8390ec21ed97e0220a9 OK
2024/11/20 01:24:27 INFO  : three.txt: Copied (new)
2024/11/20 01:24:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/20 01:24:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/20 01:24:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/20 01:24:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/20 01:24:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/20 01:24:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/20 01:24:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncSuffixKeepExtension (27.29s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:24:34 DEBUG : Testêé: md5 = c15570aeca8b65b8a4696e639ddefec3 OK
2024/11/20 01:24:34 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2024/11/20 01:24:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:24:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:24:36 DEBUG : Testêé: md5 = ca0b5886e81ece4a4593c6d9890991c9 OK
2024/11/20 01:24:36 INFO  : Testêé: Copied (replaced existing) to: Testêé
2024/11/20 01:24:36 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (5.01s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:24:37 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/20 01:24:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:24:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:24:39 DEBUG : existing: md5 = 90ee85b4f2fc1d75624fe33dafa4ece2 OK
2024/11/20 01:24:39 INFO  : existing: Copied (new)
2024/11/20 01:24:39 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:24:40 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2024/11/20 01:24:40 ERROR : existing: Source and destination exist but do not match: immutable file modified
2024/11/20 01:24:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:24:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:24:40 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': not deleting files as there were IO errors
2024/11/20 01:24:40 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncImmutable (5.33s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:24:44 DEBUG : EXISTING: md5 = 5c64a73565f7ee0fc8829e702dd865b2 OK
2024/11/20 01:24:44 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:24:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:24:44 DEBUG : existing: Unchanged skipping
2024/11/20 01:24:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:24:44 DEBUG : Waiting for deletions to finish
2024/11/20 01:24:44 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (3.50s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.47s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", 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-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", 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-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.40s)
    --- SKIP: TestMaxTransfer/Hard (0.47s)
    --- SKIP: TestMaxTransfer/Soft (0.46s)
    --- SKIP: TestMaxTransfer/Cautious (0.47s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:24:49 DEBUG : both0: md5 = f1a44421c63265e1a5ce248e676d0e09 OK
2024/11/20 01:24:51 DEBUG : only0: md5 = e7b5f123c8d7b10700b834787750cedf OK
2024/11/20 01:24:53 DEBUG : both1: md5 = cbcd21e3fe1762a59b467ee0d6de8818 OK
2024/11/20 01:24:55 DEBUG : only1: md5 = 919731f7a5f4a2170c828a935c201663 OK
2024/11/20 01:24:56 DEBUG : both2: md5 = 7919b9a193dd4dfaec5660d561c77b45 OK
2024/11/20 01:24:58 DEBUG : only2: md5 = c8f75f62f78563a2e73b26327d5f3484 OK
2024/11/20 01:25:00 DEBUG : both3: md5 = 36e67f76bb8813b143f534e4af1d64af OK
2024/11/20 01:25:02 DEBUG : only3: md5 = 59a4dc4b9a3d6a103ebd3f167026b99d OK
2024/11/20 01:25:03 DEBUG : both4: md5 = 1423ed8b69daad7d9e26ad327c5a2d1f OK
2024/11/20 01:25:05 DEBUG : only4: md5 = 85a6624ae5d750f7b4644bb4edf2900d OK
2024/11/20 01:25:07 DEBUG : both5: md5 = ab25fe4223d214860a240fee3946f9f1 OK
2024/11/20 01:25:08 DEBUG : only5: md5 = f7704ab16efc5daabf4f1d4a6abe7f0e OK
2024/11/20 01:25:10 DEBUG : both6: md5 = 17793c6cebb7506b3964a5b18efd8b50 OK
2024/11/20 01:25:12 DEBUG : only6: md5 = 88b7f3bb45cad9e090c724a77b9421fb OK
2024/11/20 01:25:14 DEBUG : both7: md5 = ccc53bfe8f60a8b3f9ebd12eb706e151 OK
2024/11/20 01:25:15 DEBUG : only7: md5 = 43cf71b6aa11ef7ea39e8a73ce3ba7fc OK
2024/11/20 01:25:17 DEBUG : both8: md5 = 0d87e7d69f6b423c254760b0852b4ff4 OK
2024/11/20 01:25:19 DEBUG : only8: md5 = 805f868ebe0c031943c46a9025b013ce OK
2024/11/20 01:25:21 DEBUG : both9: md5 = e75aabc808275dc06b2fc085e126d577 OK
2024/11/20 01:25:22 DEBUG : only9: md5 = 57231d0c81748f1e30d5c1a1910b354f OK
2024/11/20 01:25:24 DEBUG : both10: md5 = f2c3816a524375d2d5277249c4fa5f3a OK
2024/11/20 01:25:25 DEBUG : only10: md5 = 9b75222642a2b178ce23f1d020e5f063 OK
2024/11/20 01:25:27 DEBUG : both11: md5 = 0ddaee2c797895103566c688e15830b3 OK
2024/11/20 01:25:29 DEBUG : only11: md5 = 93ccb23a45961d5b31cfbaf666cb1130 OK
2024/11/20 01:25:31 DEBUG : both12: md5 = f9a9e0a21a7b8869f744425d1d62f0e8 OK
2024/11/20 01:25:33 DEBUG : only12: md5 = c1b843ed83fe6c500f43e710dc7492a8 OK
2024/11/20 01:25:34 DEBUG : both13: md5 = 4d8611ac06bab9b3e9f4b07ba8a2831c OK
2024/11/20 01:25:36 DEBUG : only13: md5 = df8f7f7d79099f38e476f3b873b7ecae OK
2024/11/20 01:25:38 DEBUG : both14: md5 = 379da7a54a1cb05c9347bac25564e9cd OK
2024/11/20 01:25:39 DEBUG : only14: md5 = 0a6abeed0c0e657b8f3f54805724f429 OK
2024/11/20 01:25:41 DEBUG : both15: md5 = 1ec3fb9f024df35075cb6105377729b3 OK
2024/11/20 01:25:43 DEBUG : only15: md5 = 22a5b19d96a1a2641a98ff6f7c065b9c OK
2024/11/20 01:25:44 DEBUG : both16: md5 = c3567828df9157565aec576494949920 OK
2024/11/20 01:25:46 DEBUG : only16: md5 = b69a62d8f2a2768f4f7005651262e0a5 OK
2024/11/20 01:25:48 DEBUG : both17: md5 = 6bd3845088520fc2e9433d64a36c4eb8 OK
2024/11/20 01:25:49 DEBUG : only17: md5 = 68b3cf7e654e8ac1d3bf7ec3fe182641 OK
2024/11/20 01:25:51 DEBUG : both18: md5 = e6c849efefe8b8aa10ba3df0954d8f7f OK
2024/11/20 01:25:53 DEBUG : only18: md5 = ae914b22c5b21491958f4e9e14d199cd OK
2024/11/20 01:25:54 DEBUG : both19: md5 = 36f09b2d02e8394cba8249c19088876a OK
2024/11/20 01:25:56 DEBUG : only19: md5 = dfc4a1e35895ee967a2b42148d947ca9 OK
2024/11/20 01:25:57 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:25:57 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both0: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both12: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both13: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both14: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both15: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both16: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both17: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both18: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both10: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both1: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both3: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both11: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both19: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both2: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both7: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both8: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:25:57 DEBUG : both4: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both5: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both6: Unchanged skipping
2024/11/20 01:25:57 DEBUG : both9: Unchanged skipping
2024/11/20 01:25:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:25:57 DEBUG : Waiting for deletions to finish
2024/11/20 01:25:57 INFO  : only4: Deleted
2024/11/20 01:25:57 INFO  : only16: Deleted
2024/11/20 01:25:57 INFO  : only18: Deleted
2024/11/20 01:25:57 INFO  : only5: Deleted
2024/11/20 01:25:58 INFO  : only7: Deleted
2024/11/20 01:25:58 INFO  : only12: Deleted
2024/11/20 01:25:58 INFO  : only2: Deleted
2024/11/20 01:25:58 INFO  : only9: Deleted
2024/11/20 01:25:59 INFO  : only0: Deleted
2024/11/20 01:25:59 INFO  : only1: Deleted
2024/11/20 01:25:59 INFO  : only13: Deleted
2024/11/20 01:25:59 INFO  : only14: Deleted
2024/11/20 01:25:59 INFO  : only17: Deleted
2024/11/20 01:25:59 INFO  : only15: Deleted
2024/11/20 01:25:59 INFO  : only19: Deleted
2024/11/20 01:25:59 INFO  : only6: Deleted
2024/11/20 01:26:00 INFO  : only3: Deleted
2024/11/20 01:26:00 INFO  : only11: Deleted
2024/11/20 01:26:00 INFO  : only10: Deleted
2024/11/20 01:26:00 INFO  : only8: Deleted
2024/11/20 01:26:00 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (85.50s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:26:15 DEBUG : both0: md5 = d0d7aa1a589462348045ad9600b16877 OK
2024/11/20 01:26:16 DEBUG : only0: md5 = 09bc4b02cb1e420f418f23d37eb5dba7 OK
2024/11/20 01:26:18 DEBUG : both1: md5 = 734124ed79178cf678fd4621b54806ae OK
2024/11/20 01:26:20 DEBUG : only1: md5 = bc5c1e53b7d9f83d897d404a03b5e85b OK
2024/11/20 01:26:21 DEBUG : both2: md5 = 3a6cfc34523339d3f1f8d1998ad80131 OK
2024/11/20 01:26:23 DEBUG : only2: md5 = 7ac0d7e813216e6ca45b5ed7f005141e OK
2024/11/20 01:26:25 DEBUG : both3: md5 = 15b08783cfdb8c20bfabc7fbd6ac8985 OK
2024/11/20 01:26:27 DEBUG : only3: md5 = 53067e0c69375fe1fa67f96b71da47cc OK
2024/11/20 01:26:29 DEBUG : both4: md5 = 93b7bf9012025928d258273e21a0b8c0 OK
2024/11/20 01:26:30 DEBUG : only4: md5 = 2b9bba022e863666e1156fcf2b8bf7bd OK
2024/11/20 01:26:32 DEBUG : both5: md5 = de5840801b90bcd9a64eb5beaea786c6 OK
2024/11/20 01:26:34 DEBUG : only5: md5 = 4cd76241235162bcbd38b6a546cd2d61 OK
2024/11/20 01:26:35 DEBUG : both6: md5 = ce37f5ae3192898f9b884a55d14b2f86 OK
2024/11/20 01:26:37 DEBUG : only6: md5 = 5dcb121cf3ad9c79a5056361b2717912 OK
2024/11/20 01:26:39 DEBUG : both7: md5 = 342030709c3e75c29e1b1684f1badb09 OK
2024/11/20 01:26:41 DEBUG : only7: md5 = 57434d1d20cca21b1dd80cf181295d23 OK
2024/11/20 01:26:42 DEBUG : both8: md5 = ee84ad9acdbdc02ed58e0b4be89f047e OK
2024/11/20 01:26:45 DEBUG : only8: md5 = 366022674ec2dcd4cbafd2899a0ab2f0 OK
2024/11/20 01:26:46 DEBUG : both9: md5 = 6702f6fe877e398e7240c28baf2c74e2 OK
2024/11/20 01:26:48 DEBUG : only9: md5 = c1ff5c7c6b0a235e89efbb9df95887b8 OK
2024/11/20 01:26:50 DEBUG : both10: md5 = 70ca67b4b59a31128a4ee393a212f39b OK
2024/11/20 01:26:51 DEBUG : only10: md5 = cb03b575aeb9728dae91b8059735e9df OK
2024/11/20 01:26:53 DEBUG : both11: md5 = 034b1f9e19ebca91d49fec313d163991 OK
2024/11/20 01:26:55 DEBUG : only11: md5 = c07837c4212db0cfcef7139b71d8f60e OK
2024/11/20 01:26:56 DEBUG : both12: md5 = 3043570c81f220ecbfa5ff1fe85825fb OK
2024/11/20 01:26:58 DEBUG : only12: md5 = 6c434d6b6ee4da6b4ae2d5276dc3eb7a OK
2024/11/20 01:27:00 DEBUG : both13: md5 = 11fb04d087604af22520a2e96edbe16d OK
2024/11/20 01:27:04 DEBUG : only13: md5 = f81789438931cb09770066e6db0436a5 OK
2024/11/20 01:27:08 DEBUG : both14: md5 = 30a2405c20de9e840728c4c4b3a9af17 OK
2024/11/20 01:27:10 DEBUG : only14: md5 = 4e8a7210d55a04d7c22138e6bf335cf2 OK
2024/11/20 01:27:11 DEBUG : both15: md5 = ff7411fee888654a42c5f8d7cbc8485b OK
2024/11/20 01:27:16 DEBUG : only15: md5 = c317199991e876eb0d7f45e019824801 OK
2024/11/20 01:27:18 DEBUG : both16: md5 = c443a6680fb765d93e2f36227de30f67 OK
2024/11/20 01:27:20 DEBUG : only16: md5 = 7cbc9b01c4366f106fbccc8d3ca61dcc OK
2024/11/20 01:27:22 DEBUG : both17: md5 = 05ea575d9d76974b89ea2b3b06cbaa1b OK
2024/11/20 01:27:23 DEBUG : only17: md5 = 24cbf88fb236c2bde308efacb5a82127 OK
2024/11/20 01:27:25 DEBUG : both18: md5 = 4b92b70160f12a22574a76c56d5d6d26 OK
2024/11/20 01:27:27 DEBUG : only18: md5 = 4db6919205f33cd5829f0767f0c8c331 OK
2024/11/20 01:27:29 DEBUG : both19: md5 = 6ee95b736468aaa81199680307098ca6 OK
2024/11/20 01:27:30 DEBUG : only19: md5 = 6c7b85ce84de893e4cffa79ea9078e77 OK
2024/11/20 01:27:31 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for checks to finish
2024/11/20 01:27:31 DEBUG : both0: Unchanged skipping
2024/11/20 01:27:31 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both1: Unchanged skipping
2024/11/20 01:27:31 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both13: Unchanged skipping
2024/11/20 01:27:31 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both14: Unchanged skipping
2024/11/20 01:27:31 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both10: Unchanged skipping
2024/11/20 01:27:31 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both12: Unchanged skipping
2024/11/20 01:27:31 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both11: Unchanged skipping
2024/11/20 01:27:31 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both17: Unchanged skipping
2024/11/20 01:27:31 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both18: Unchanged skipping
2024/11/20 01:27:31 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both2: Unchanged skipping
2024/11/20 01:27:31 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both16: Unchanged skipping
2024/11/20 01:27:31 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both4: Unchanged skipping
2024/11/20 01:27:31 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both15: Unchanged skipping
2024/11/20 01:27:31 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both6: Unchanged skipping
2024/11/20 01:27:31 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both19: Unchanged skipping
2024/11/20 01:27:31 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both3: Unchanged skipping
2024/11/20 01:27:31 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/20 01:27:31 DEBUG : both9: Unchanged skipping
2024/11/20 01:27:31 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : both5: Unchanged skipping
2024/11/20 01:27:31 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : both7: Unchanged skipping
2024/11/20 01:27:31 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : both8: Unchanged skipping
2024/11/20 01:27:31 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2024/11/20 01:27:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Waiting for transfers to finish
2024/11/20 01:27:32 DEBUG : only10: md5 = cfeb94e7ff47b3470605bac3210dc168 OK
2024/11/20 01:27:32 INFO  : only10: Copied (replaced existing)
2024/11/20 01:27:32 DEBUG : only13: md5 = 9f2af58985b164ea39f612788c449e9f OK
2024/11/20 01:27:32 INFO  : only13: Copied (replaced existing)
2024/11/20 01:27:32 DEBUG : only12: md5 = 381682d7c431212c4d522d6031c933d9 OK
2024/11/20 01:27:32 INFO  : only12: Copied (replaced existing)
2024/11/20 01:27:32 DEBUG : only0: md5 = 35e4a8116a3bc603254cf52493556153 OK
2024/11/20 01:27:32 INFO  : only0: Copied (replaced existing)
2024/11/20 01:27:34 DEBUG : only14: md5 = 4a1f0e841bab533a6f765a00b8869075 OK
2024/11/20 01:27:34 INFO  : only14: Copied (replaced existing)
2024/11/20 01:27:34 DEBUG : only15: md5 = 9843da690e5965ebdb9aaec774c2a21b OK
2024/11/20 01:27:34 INFO  : only15: Copied (replaced existing)
2024/11/20 01:27:34 DEBUG : only17: md5 = fe324055b00494d1eb720677a3f0db70 OK
2024/11/20 01:27:34 INFO  : only17: Copied (replaced existing)
2024/11/20 01:27:34 DEBUG : only16: md5 = 988ccb3327ff992d12b94da1bba10393 OK
2024/11/20 01:27:34 INFO  : only16: Copied (replaced existing)
2024/11/20 01:27:35 DEBUG : only19: md5 = 6068a965bdbf3f26c99338849421d6ca OK
2024/11/20 01:27:35 INFO  : only19: Copied (replaced existing)
2024/11/20 01:27:35 DEBUG : only4: md5 = ac4182de226c9ab201b5aab15d6fb202 OK
2024/11/20 01:27:35 INFO  : only4: Copied (replaced existing)
2024/11/20 01:27:35 DEBUG : only2: md5 = 55cf6c3d3f4cc6b8fb7d69febf39a7e6 OK
2024/11/20 01:27:35 INFO  : only2: Copied (replaced existing)
2024/11/20 01:27:35 DEBUG : only18: md5 = cd55bb6f41f2a02710a660d920fcd0d1 OK
2024/11/20 01:27:35 INFO  : only18: Copied (replaced existing)
2024/11/20 01:27:36 DEBUG : only5: md5 = f8d5c0b85aa1bbf653812dbceee32b4b OK
2024/11/20 01:27:36 INFO  : only5: Copied (replaced existing)
2024/11/20 01:27:36 DEBUG : only1: md5 = f9fba58fc0d5d73c916f7ef327257719 OK
2024/11/20 01:27:36 INFO  : only1: Copied (replaced existing)
2024/11/20 01:27:36 DEBUG : only3: md5 = 41936986ed80ee8d980531813c307a44 OK
2024/11/20 01:27:36 INFO  : only3: Copied (replaced existing)
2024/11/20 01:27:37 DEBUG : only8: md5 = 3ffd2aa2b6a5a158dcd5d1600b6729c1 OK
2024/11/20 01:27:37 INFO  : only8: Copied (replaced existing)
2024/11/20 01:27:38 DEBUG : only9: md5 = 9c0428d3c199cad3556cba79b86bdb54 OK
2024/11/20 01:27:38 INFO  : only9: Copied (replaced existing)
2024/11/20 01:27:38 DEBUG : only11: md5 = bad4ad62b8bee24473bd57825d062bd0 OK
2024/11/20 01:27:38 INFO  : only11: Copied (replaced existing)
2024/11/20 01:27:38 DEBUG : only6: md5 = 5a4a5c6ca8334f0477330123d1803a1a OK
2024/11/20 01:27:38 INFO  : only6: Copied (replaced existing)
2024/11/20 01:27:38 DEBUG : only7: md5 = a0d502219a9c03f838aa38ff6198bb2a OK
2024/11/20 01:27:38 INFO  : only7: Copied (replaced existing)
2024/11/20 01:27:38 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (111.26s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:28:04 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/20 01:28:04 DEBUG : sub dir: Making directory with metadata
2024/11/20 01:28:05 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:28:26 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/20 01:28:27 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/20 01:28:27 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/20 01:28:27 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:28:43 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2024/11/20 01:28:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/20 01:28:45 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/11/20 01:28:46 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/11/20 01:28:47 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/20 01:28:48 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/20 01:28:49 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/20 01:28:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/20 01:28:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/20 01:28:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/11/20 01:28:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/20 01:28:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (50.50s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:28:55 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/20 01:28:55 DEBUG : sub dir: Making directory with metadata
2024/11/20 01:28:56 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:29:22 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/20 01:29:23 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/20 01:29:23 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/20 01:29:23 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa'", Local "Local file system at /tmp/rclone2810207766", Modify Window "1ms"
2024/11/20 01:29:38 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/20 01:29:39 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/11/20 01:29:39 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/11/20 01:29:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/20 01:29:41 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/20 01:29:42 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/20 01:29:43 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/20 01:29:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/20 01:29:45 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/11/20 01:29:45 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/20 01:29:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (53.23s)
PASS
2024/11/20 01:29:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fakohox8mufa': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 19m18.472928428s (try 1/5)