"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5) 2025/02/09 04:04:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca" 2025/02/09 04:04:11 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/02/09 04:04:11 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80" 2025/02/09 04:04:12 DEBUG : Creating backend with remote "/tmp/rclone2478755479" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.02s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:04:13 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/09 04:04:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/09 04:04:13 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/02/09 04:04:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:04:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:04:13 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.22s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:04:14 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/09 04:04:15 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/09 04:04:15 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/09 04:04:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:04:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:04:17 DEBUG : sub dir/hello world: md5 = 7d9310cbd927931bb85d16c43066dc5d OK 2025/02/09 04:04:17 INFO : sub dir/hello world: Copied (new) 2025/02/09 04:04:18 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:04:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (6.38s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:04:21 DEBUG : metadata sub dir: Making directory with metadata 2025/02/09 04:04:21 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/09 04:04:21 DEBUG : empty metadata sub dir: Making directory with metadata 2025/02/09 04:04:21 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/09 04:04:21 DEBUG : Local file system at /tmp/rclone2478755479: File to upload is small (21 bytes), uploading instead of streaming 2025/02/09 04:04:21 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/02/09 04:04:21 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/02/09 04:04:21 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/02/09 04:04:21 DEBUG : Google drive root 'crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80': Skipping btime metadata as can't update it on an existing file: 2025-02-09T04:04:21.375832662Z 2025/02/09 04:04:22 INFO : empty metadata sub dir: Updated directory metadata 2025/02/09 04:04:22 DEBUG : Google drive root 'crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80': Skipping btime metadata as can't update it on an existing file: 2025-02-09T04:04:21.37183269Z 2025/02/09 04:04:23 INFO : metadata sub dir: Updated directory metadata 2025/02/09 04:04:23 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/02/09 04:04:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:04:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:04:24 DEBUG : metadata sub dir/hello metadata world: md5 = b87491dc9377dcc608b1fa8f57100494 OK 2025/02/09 04:04:24 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:04:27 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (8.14s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:04:29 DEBUG : metadata sub dir: Making directory with metadata 2025/02/09 04:04:29 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/09 04:04:29 DEBUG : empty metadata sub dir: Making directory with metadata 2025/02/09 04:04:29 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/09 04:04:29 DEBUG : Local file system at /tmp/rclone2478755479: File to upload is small (21 bytes), uploading instead of streaming 2025/02/09 04:04:29 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/02/09 04:04:29 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/02/09 04:04:29 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/02/09 04:04:29 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/02/09 04:04:29 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/02/09 04:04:29 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/02/09 04:04:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:04:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:04:31 DEBUG : metadata sub dir/hello metadata world: md5 = cac99f911d112c7bf4322ab318bc5e96 OK 2025/02/09 04:04:31 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/02/09 04:04:31 DEBUG : Google drive root 'crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80': Skipping btime metadata as can't update it on an existing file: 2025-02-09T04:04:29.515773918Z 2025/02/09 04:04:32 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:04:35 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (6.95s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:04:36 DEBUG : Creating backend with remote "/non-existing" 2025/02/09 04:04:36 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/02/09 04:04:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:04:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.18s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:04:37 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/09 04:04:37 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/09 04:04:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:04:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:04:40 DEBUG : sub dir/hello world: md5 = 3cc0bfdb6801266637d86ff2a055f6ad OK 2025/02/09 04:04:40 INFO : sub dir/hello world: Copied (new) 2025/02/09 04:04:40 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:04:42 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (6.08s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:04:43 INFO : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Running all checks before starting transfers 2025/02/09 04:04:43 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/09 04:04:43 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/09 04:04:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:04:43 INFO : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Checks finished, now starting transfers 2025/02/09 04:04:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:04:46 DEBUG : sub dir/hello world: md5 = 85e05b7f7669a70b7d45de3306b46684 OK 2025/02/09 04:04:46 INFO : sub dir/hello world: Copied (new) 2025/02/09 04:04:46 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:04:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (5.92s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:04:49 ERROR : Ignoring --no-traverse with sync 2025/02/09 04:04:49 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/09 04:04:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/09 04:04:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:04:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:04:52 DEBUG : sub dir/hello world: md5 = 0767b2dc8bba7253374a8aea21d5956d OK 2025/02/09 04:04:52 INFO : sub dir/hello world: Copied (new) 2025/02/09 04:04:52 DEBUG : Waiting for deletions to finish 2025/02/09 04:04:52 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:04:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (6.05s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:04:55 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/02/09 04:04:55 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/09 04:04:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:04:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:04:57 DEBUG : hello world2: md5 = 79a7ae8050d1b1ae53930fada5947d67 OK 2025/02/09 04:04:57 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.36s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:04:59 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/09 04:04:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:04:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:05:00 DEBUG : potato2: md5 = 09a58f8c17ffe7dc12bb3a28a634c29c OK 2025/02/09 04:05:00 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.59s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:05:02 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/09 04:05:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:05:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:05:04 DEBUG : potato2: md5 = 6faeb3def65357e5b0ad3197bdd96169 OK 2025/02/09 04:05:04 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.39s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:05:06 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/02/09 04:05:06 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/09 04:05:06 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/02/09 04:05:06 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/09 04:05:06 DEBUG : sub dir: Making directory with metadata 2025/02/09 04:05:07 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/02/09 04:05:07 DEBUG : sub dir2: Making directory with metadata 2025/02/09 04:05:07 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/09 04:05:07 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/02/09 04:05:07 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/09 04:05:08 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/09 04:05:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:05:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:05:09 DEBUG : sub dir/hello world: md5 = eb00aa84e5c4fedc7bef315d7305eca8 OK 2025/02/09 04:05:09 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:05:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/02/09 04:05:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (8.73s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:05:14 INFO : sub dir2: Making directory 2025/02/09 04:05:14 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/02/09 04:05:14 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/09 04:05:15 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/09 04:05:15 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/02/09 04:05:15 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/02/09 04:05:15 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/09 04:05:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:05:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:05:17 DEBUG : sub dir/hello world: md5 = 55c14f6fcbf80a83abda1ebe642fda73 OK 2025/02/09 04:05:17 INFO : sub dir/hello world: Copied (new) 2025/02/09 04:05:18 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/09 04:05:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (5.79s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:05:20 DEBUG : sub dir2: Making directory with metadata 2025/02/09 04:05:20 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/09 04:05:20 DEBUG : sub dir: Making directory with metadata 2025/02/09 04:05:21 INFO : sub dir: Made directory with metadata (mtime=2025-02-09T04:05:20.567405588Z) 2025/02/09 04:05:21 DEBUG : sub dir2: Making directory with metadata 2025/02/09 04:05:22 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/09 04:05:22 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/09 04:05:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:05:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:05:23 DEBUG : sub dir/hello world: md5 = b53ae4d2bb848f8e3589458cab70a604 OK 2025/02/09 04:05:23 INFO : sub dir/hello world: Copied (new) 2025/02/09 04:05:23 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:05:26 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (7.10s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:05:27 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/02/09 04:05:27 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/02/09 04:05:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:05:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:05:29 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (4.08s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:05:31 INFO : sub dir2: Making directory 2025/02/09 04:05:31 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/09 04:05:31 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/02/09 04:05:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/09 04:05:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:05:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:05:34 DEBUG : sub dir/hello world: md5 = e85e76d98a67477feb0753ed61398d3d OK 2025/02/09 04:05:34 INFO : sub dir/hello world: Copied (new) 2025/02/09 04:05:34 INFO : sub dir/hello world: Deleted 2025/02/09 04:05:34 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/09 04:05:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (5.29s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:05:37 DEBUG : sub dir2: Making directory with metadata 2025/02/09 04:05:37 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/09 04:05:37 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/09 04:05:37 DEBUG : sub dir: Making directory with metadata 2025/02/09 04:05:37 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/02/09 04:05:37 DEBUG : sub dir2: Making directory with metadata 2025/02/09 04:05:38 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/09 04:05:38 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/09 04:05:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:05:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:05:40 DEBUG : sub dir/hello world: md5 = 1c7a22d18fceee995531538ab57399cc OK 2025/02/09 04:05:40 INFO : sub dir/hello world: Copied (new) 2025/02/09 04:05:40 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:05:43 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (7.21s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.45s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:05:44 INFO : sub dir2: Making directory 2025/02/09 04:05:44 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/09 04:05:44 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/02/09 04:05:44 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/09 04:05:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:05:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:05:46 DEBUG : sub dir/hello world: md5 = 6c41a590fb3561f3c0417417f845ab0d OK 2025/02/09 04:05:46 INFO : sub dir/hello world: Copied (new) 2025/02/09 04:05:46 DEBUG : Waiting for deletions to finish 2025/02/09 04:05:47 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/09 04:05:49 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.17s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:05:52 DEBUG : sub dir/hello world: md5 = f1406aff2ded1394c1a5d671137e57d0 OK 2025/02/09 04:05:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yecafew5heru" 2025/02/09 04:05:52 DEBUG : Creating backend with remote "TestDrive:crypt/vb3hbb9e836avqa1098a34hn7djjlc0d6gee4o3c7lidlbc7sb0g" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca' -> Encrypted drive 'TestCryptDrive:rclone-test-yecafew5heru' 2025/02/09 04:05:53 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/09 04:05:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/09 04:05:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yecafew5heru': Waiting for checks to finish 2025/02/09 04:05:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yecafew5heru': Waiting for transfers to finish 2025/02/09 04:05:56 INFO : sub dir/hello world: Copied (server-side copy) 2025/02/09 04:05:56 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:05:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yecafew5heru': Purge remote 2025/02/09 04:05:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (10.27s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:06:02 DEBUG : sub dir/hello world: md5 = d0cfe83e30db721ea14ad7016c52ba02 OK 2025/02/09 04:06:03 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/02/09 04:06:03 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/02/09 04:06:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:06:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:06:04 DEBUG : sub dir/hello world: md5 = 9e87b82d43135f900bece8bd94feebe5 OK 2025/02/09 04:06:04 INFO : sub dir/hello world: Copied (replaced existing) 2025/02/09 04:06:04 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:06:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (7.43s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:06:09 DEBUG : sub dir/hello world: md5 = ce49422066186f6a9685497c76cc62aa OK 2025/02/09 04:06:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tilobub1yixe" 2025/02/09 04:06:10 DEBUG : Creating backend with remote "TestDrive:crypt/g6lm1gg4o1n7omo79u76h8iq6svv3puiehm5g4ukshuc389upvf0" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca' -> Encrypted drive 'TestCryptDrive:rclone-test-tilobub1yixe' 2025/02/09 04:06:11 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/09 04:06:11 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/09 04:06:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tilobub1yixe': Waiting for checks to finish 2025/02/09 04:06:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tilobub1yixe': Waiting for transfers to finish 2025/02/09 04:06:14 INFO : sub dir/hello world: Copied (server-side copy) 2025/02/09 04:06:14 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:06:16 DEBUG : sub dir/hello world: md5 = 877181e14014b294bb5d7de6edb404c3 OK 2025/02/09 04:06:17 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/02/09 04:06:17 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/02/09 04:06:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tilobub1yixe': Waiting for checks to finish 2025/02/09 04:06:17 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/02/09 04:06:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tilobub1yixe': Waiting for transfers to finish 2025/02/09 04:06:18 INFO : sub dir/hello world: Copied (server-side copy) 2025/02/09 04:06:19 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:06:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tilobub1yixe': Purge remote 2025/02/09 04:06:21 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (15.49s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:06:25 DEBUG : sub dir/hello world: md5 = ca848bc89a3481b9b2ea64a977e90acc OK 2025/02/09 04:06:25 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/02/09 04:06:25 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/02/09 04:06:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:06:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:06:27 DEBUG : sub dir/hello world: md5 = 7eea9055b59a36826d5b4d57c75c72f0 OK 2025/02/09 04:06:27 INFO : sub dir/hello world: Copied (replaced existing) 2025/02/09 04:06:27 INFO : sub dir/hello world: Deleted 2025/02/09 04:06:27 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:06:29 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (7.43s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:06:32 DEBUG : sub dir/hello world: md5 = 010f404f4f2b534f2c5e7509fce18c58 OK 2025/02/09 04:06:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jesetuk2qoxi" 2025/02/09 04:06:33 DEBUG : Creating backend with remote "TestDrive:crypt/76olrg00pr7hhp6fp34kkva026n0pl31mjt4knoakkqgfnj7re0g" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca' -> Encrypted drive 'TestCryptDrive:rclone-test-jesetuk2qoxi' 2025/02/09 04:06:34 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/09 04:06:34 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/09 04:06:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jesetuk2qoxi': Waiting for checks to finish 2025/02/09 04:06:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jesetuk2qoxi': Waiting for transfers to finish 2025/02/09 04:06:36 INFO : sub dir/hello world: Copied (server-side copy) 2025/02/09 04:06:37 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:06:39 DEBUG : sub dir/hello world: md5 = ac8475604ab6161d6c1ee8623c032058 OK 2025/02/09 04:06:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jesetuk2qoxi': Using server-side directory move 2025/02/09 04:06:39 INFO : Encrypted drive 'TestCryptDrive:rclone-test-jesetuk2qoxi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/02/09 04:06:40 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/02/09 04:06:40 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/02/09 04:06:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jesetuk2qoxi': Waiting for checks to finish 2025/02/09 04:06:40 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/02/09 04:06:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jesetuk2qoxi': Waiting for transfers to finish 2025/02/09 04:06:40 INFO : sub dir/hello world: Deleted 2025/02/09 04:06:41 INFO : sub dir/hello world: Moved (server-side) 2025/02/09 04:06:41 INFO : sub dir: Set directory modification time (using SetModTime) 2025/02/09 04:06:44 DEBUG : sub dir/hello world: md5 = 36532e726ff64897f1720e16a1f1476e OK 2025/02/09 04:06:44 DEBUG : testing file moves 2025/02/09 04:06:44 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/02/09 04:06:44 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/02/09 04:06:44 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/02/09 04:06:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jesetuk2qoxi': Waiting for checks to finish 2025/02/09 04:06:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jesetuk2qoxi': Waiting for transfers to finish 2025/02/09 04:06:45 INFO : sub dir/hello world: Deleted 2025/02/09 04:06:45 INFO : sub dir/hello world: Moved (server-side) 2025/02/09 04:06:46 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:06:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jesetuk2qoxi': Purge remote --- PASS: TestServerSideMoveOverSelf (19.45s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:06:52 DEBUG : sub dir/hello world: md5 = 2300de75e3578a7c740265861ecb3cfb OK 2025/02/09 04:06:52 ERROR : : error listing: directory not found 2025/02/09 04:06:52 INFO : Local file system at /tmp/rclone2478755479: Making directory 2025/02/09 04:06:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:06:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:06:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (6.04s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:06:58 DEBUG : sub dir/hello world: md5 = 402648b8b140048226a33ccd5ea5d1bd OK 2025/02/09 04:06:59 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/09 04:06:59 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/09 04:06:59 DEBUG : Local file system at /tmp/rclone2478755479: Waiting for checks to finish 2025/02/09 04:06:59 DEBUG : Local file system at /tmp/rclone2478755479: Waiting for transfers to finish 2025/02/09 04:07:00 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/02/09 04:07:00 INFO : sub dir/hello world: Copied (new) 2025/02/09 04:07:00 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:07:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (6.35s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:07:02 DEBUG : check sum: Need to transfer - File not found at Destination 2025/02/09 04:07:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:07:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:07:03 DEBUG : check sum: md5 = 531d7c34112e537e2fb1ef2096abb574 OK 2025/02/09 04:07:03 INFO : check sum: Copied (new) 2025/02/09 04:07:03 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:07:04 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/02/09 04:07:04 DEBUG : check sum: Size of src and dst objects identical 2025/02/09 04:07:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:07:04 DEBUG : check sum: Unchanged skipping 2025/02/09 04:07:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:07:04 DEBUG : Waiting for deletions to finish 2025/02/09 04:07:04 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.31s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:07:06 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/02/09 04:07:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:07:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:07:08 DEBUG : sizeonly: md5 = 2d1ae9e9ee874efb858f1cb661dc62b5 OK 2025/02/09 04:07:08 INFO : sizeonly: Copied (new) 2025/02/09 04:07:08 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:07:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:07:08 DEBUG : sizeonly: Sizes identical 2025/02/09 04:07:08 DEBUG : sizeonly: Unchanged skipping 2025/02/09 04:07:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:07:08 DEBUG : Waiting for deletions to finish 2025/02/09 04:07:08 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.36s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:07:11 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/02/09 04:07:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:07:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:07:12 DEBUG : ignore-size: md5 = b1a54d135edcbe6f18c7b64f79a9ab3d OK 2025/02/09 04:07:12 INFO : ignore-size: Copied (new) 2025/02/09 04:07:12 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:07:13 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:07:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:07:13 DEBUG : ignore-size: Unchanged skipping 2025/02/09 04:07:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:07:13 DEBUG : Waiting for deletions to finish 2025/02/09 04:07:13 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.17s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:07:16 DEBUG : existing: md5 = e5273b5b79880f2da6291b5fea38d7f9 OK 2025/02/09 04:07:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:07:16 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:07:16 DEBUG : existing: Unchanged skipping 2025/02/09 04:07:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:07:16 DEBUG : Waiting for deletions to finish 2025/02/09 04:07:16 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:07:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:07:17 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/02/09 04:07:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:07:18 DEBUG : existing: md5 = 14700881864d37e15add0b5d8f915756 OK 2025/02/09 04:07:18 INFO : existing: Copied (replaced existing) 2025/02/09 04:07:18 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.28s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:07:20 DEBUG : existing: Need to transfer - File not found at Destination 2025/02/09 04:07:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:07:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:07:22 DEBUG : existing: md5 = 1b3aa890df9cd46f980ce8e4d1f765bc OK 2025/02/09 04:07:22 INFO : existing: Copied (new) 2025/02/09 04:07:22 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:07:22 DEBUG : existing: Destination exists, skipping 2025/02/09 04:07:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:07:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:07:22 DEBUG : Waiting for deletions to finish 2025/02/09 04:07:22 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.25s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:07:26 DEBUG : b/potato: md5 = ae2d2e45c1518433243654c41b42cdfc OK 2025/02/09 04:07:28 DEBUG : c/non empty space: md5 = 2ce612a0c9d97c1e583d870e45751007 OK 2025/02/09 04:07:28 INFO : d: Making directory 2025/02/09 04:07:30 DEBUG : Added delayed dir = "a", newDst= 2025/02/09 04:07:30 DEBUG : Added delayed dir = "c", newDst=c 2025/02/09 04:07:30 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:07:30 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/02/09 04:07:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:07:30 DEBUG : c/non empty space: Unchanged skipping 2025/02/09 04:07:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:07:33 DEBUG : a/potato2: md5 = 7d8aafa2d98cb8c566cb67f623a856e9 OK 2025/02/09 04:07:33 INFO : a/potato2: Copied (new) 2025/02/09 04:07:33 DEBUG : Waiting for deletions to finish 2025/02/09 04:07:33 INFO : b/potato: Deleted 2025/02/09 04:07:34 INFO : a: Set directory modification time (using DirSetModTime) 2025/02/09 04:07:34 INFO : d: Removing directory 2025/02/09 04:07:34 INFO : b: Removing directory 2025/02/09 04:07:34 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/02/09 04:07:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:07:37 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/02/09 04:07:38 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (14.61s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:07:40 DEBUG : empty space: md5 = f867a95f568eb90e534afdb0045521f7 OK 2025/02/09 04:07:41 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 2025/02/09 04:07:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:07:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:07:41 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/02/09 04:07:41 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:07:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:07:41 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 2025/02/09 04:07:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:07:42 DEBUG : empty space: md5 = 7c398b97ec58646f5d3dc2489884fcbe OK 2025/02/09 04:07:42 INFO : empty space: Copied (replaced existing) 2025/02/09 04:07:42 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (5.68s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.46s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:07:46 DEBUG : foo: md5 = 0493fcd0926667d5bab1b5cbdc33048d OK 2025/02/09 04:07:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:07:47 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 2025/02/09 04:07:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:07:48 DEBUG : foo: md5 = 2b86de5132e3d982db676603fbf119b4 OK 2025/02/09 04:07:48 INFO : foo: Copied (replaced existing) 2025/02/09 04:07:48 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.75s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:07:51 DEBUG : empty space: md5 = 9e24b42f535506921ea0e418c8b39065 OK 2025/02/09 04:07:52 DEBUG : potato: Need to transfer - File not found at Destination 2025/02/09 04:07:52 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:07:52 DEBUG : empty space: Unchanged skipping 2025/02/09 04:07:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:07:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:07:53 DEBUG : potato: md5 = d24bc4c33a1ca75b690623f83ae7acc3 OK 2025/02/09 04:07:53 INFO : potato: Copied (new) 2025/02/09 04:07:53 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.28s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:07:56 DEBUG : potato: md5 = bfd528631ad36b2ee42352f2548b12ab OK 2025/02/09 04:07:57 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/02/09 04:07:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:07:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:07:58 DEBUG : potato: md5 = e6f605340576604d4088d05462648730 OK 2025/02/09 04:07:58 INFO : potato: Copied (replaced existing) 2025/02/09 04:07:58 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.60s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:08:01 DEBUG : potato: md5 = cb5ef31d950d62d51c29f6c60af27f5c OK 2025/02/09 04:08:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:08:01 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 2025/02/09 04:08:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:08:03 DEBUG : potato: md5 = ff87a757459e571fb2dac9d8279a50c1 OK 2025/02/09 04:08:03 INFO : potato: Copied (replaced existing) 2025/02/09 04:08:03 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.65s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:08:06 DEBUG : potato: md5 = 8705cd53d48ec3e3f20b98e1793a4f21 OK 2025/02/09 04:08:07 DEBUG : empty space: md5 = ec7f94cdc24a969960767e9ff7a79386 OK 2025/02/09 04:08:07 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/09 04:08:07 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:08:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:08:07 DEBUG : empty space: Unchanged skipping 2025/02/09 04:08:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:08:07 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/02/09 04:08:07 DEBUG : Waiting for deletions to finish 2025/02/09 04:08:07 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.08s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:08:11 DEBUG : potato: md5 = d6ddb340f1a4d55c52933c95eb1ac133 OK 2025/02/09 04:08:12 DEBUG : empty space: md5 = 9341988c76c2cf768c8b2bd12fd9fc05 OK 2025/02/09 04:08:13 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/09 04:08:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:08:13 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:08:13 DEBUG : empty space: Unchanged skipping 2025/02/09 04:08:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:08:14 DEBUG : potato2: md5 = 76841b4da9ce1a502ffa2728f947fc93 OK 2025/02/09 04:08:14 INFO : potato2: Copied (new) 2025/02/09 04:08:14 DEBUG : Waiting for deletions to finish 2025/02/09 04:08:15 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.26s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:08:19 DEBUG : b/potato: md5 = 7e0a0ab1197821f3e0d653045259d74e OK 2025/02/09 04:08:21 DEBUG : c/non empty space: md5 = ff56cd468e1255ff169188827ed8942e OK 2025/02/09 04:08:21 INFO : d: Making directory 2025/02/09 04:08:22 INFO : d/e: Making directory 2025/02/09 04:08:24 DEBUG : Added delayed dir = "a", newDst= 2025/02/09 04:08:24 DEBUG : Added delayed dir = "c", newDst=c 2025/02/09 04:08:24 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:08:24 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/02/09 04:08:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:08:24 DEBUG : c/non empty space: Unchanged skipping 2025/02/09 04:08:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:08:26 DEBUG : a/potato2: md5 = 14b983cbe66dc1b22a66df98077bb54d OK 2025/02/09 04:08:26 INFO : a/potato2: Copied (new) 2025/02/09 04:08:26 DEBUG : Waiting for deletions to finish 2025/02/09 04:08:26 INFO : b/potato: Deleted 2025/02/09 04:08:27 INFO : a: Set directory modification time (using DirSetModTime) 2025/02/09 04:08:27 INFO : d/e: Removing directory 2025/02/09 04:08:27 INFO : d: Removing directory 2025/02/09 04:08:28 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/02/09 04:08:28 INFO : b: Removing directory 2025/02/09 04:08:28 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/02/09 04:08:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:08:31 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/02/09 04:08:32 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (16.18s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:08:35 DEBUG : b/potato: md5 = 9917b26bdfb92ee5696ebe68bee36970 OK 2025/02/09 04:08:37 DEBUG : c/non empty space: md5 = 16b30d0d9b78b89b817931c1b08f8aa7 OK 2025/02/09 04:08:37 INFO : d: Making directory 2025/02/09 04:08:38 DEBUG : Added delayed dir = "a", newDst= 2025/02/09 04:08:38 DEBUG : Added delayed dir = "c", newDst=c 2025/02/09 04:08:38 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:08:38 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/02/09 04:08:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:08:38 DEBUG : c/non empty space: Unchanged skipping 2025/02/09 04:08:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:08:40 DEBUG : a/potato2: md5 = f83c891c4a0ab87bbca95d89298a814f OK 2025/02/09 04:08:40 INFO : a/potato2: Copied (new) 2025/02/09 04:08:40 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': not deleting files as there were IO errors 2025/02/09 04:08:41 INFO : a: Set directory modification time (using DirSetModTime) 2025/02/09 04:08:41 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:08:44 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/02/09 04:08:45 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/02/09 04:08:46 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (14.06s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:08:48 DEBUG : potato: md5 = c6fa6b39ce664888f4bef6b74db131c4 OK 2025/02/09 04:08:49 DEBUG : empty space: md5 = 2c2ecb5449c7dbba12eee3e4789233c8 OK 2025/02/09 04:08:50 DEBUG : Waiting for deletions to finish 2025/02/09 04:08:50 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/09 04:08:50 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:08:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:08:50 DEBUG : empty space: Unchanged skipping 2025/02/09 04:08:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:08:50 INFO : potato: Deleted 2025/02/09 04:08:51 DEBUG : potato2: md5 = 33b46fa1c2f51775635fb3b1083ed275 OK 2025/02/09 04:08:51 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (6.42s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:08:55 DEBUG : potato: md5 = 0c3bb7f1891e5bd9c6474453eff36322 OK 2025/02/09 04:08:56 DEBUG : empty space: md5 = dedb93a0cf883b1dd03131a8c048643e OK 2025/02/09 04:08:56 DEBUG : Waiting for deletions to finish 2025/02/09 04:08:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:08:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:08:57 INFO : potato: Deleted 2025/02/09 04:08:57 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/09 04:08:57 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:08:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:08:57 DEBUG : empty space: Unchanged skipping 2025/02/09 04:08:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:08:58 DEBUG : potato2: md5 = 077c3236f10ce93a33edf227d2a08161 OK 2025/02/09 04:08:58 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.41s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:09:02 DEBUG : potato: md5 = b952382874787306af56ae2ab96652cf OK 2025/02/09 04:09:03 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/09 04:09:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:09:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:09:04 DEBUG : potato2: md5 = 1af5e9cb22a7851bf819866b634a9c62 OK 2025/02/09 04:09:04 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.42s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:09:07 DEBUG : potato2: md5 = 9b147d3432bb4dc12fd004afab2749fb OK 2025/02/09 04:09:09 DEBUG : empty space: md5 = 6e36a535a5ee7e9c16b6f16cca62a824 OK 2025/02/09 04:09:09 DEBUG : enormous: Excluded (Size Filter) 2025/02/09 04:09:09 DEBUG : enormous: Excluded 2025/02/09 04:09:09 DEBUG : potato2: Excluded (Size Filter) 2025/02/09 04:09:09 DEBUG : potato2: Excluded 2025/02/09 04:09:09 DEBUG : potato2: Excluded (Size Filter) 2025/02/09 04:09:09 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:09:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:09:09 DEBUG : empty space: Unchanged skipping 2025/02/09 04:09:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:09:09 DEBUG : Waiting for deletions to finish 2025/02/09 04:09:09 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:09:09 DEBUG : enormous: Excluded (Size Filter) 2025/02/09 04:09:09 DEBUG : enormous: Excluded 2025/02/09 04:09:09 DEBUG : potato2: Excluded (Size Filter) 2025/02/09 04:09:09 DEBUG : potato2: Excluded 2025/02/09 04:09:10 DEBUG : potato2: Excluded (Size Filter) 2025/02/09 04:09:10 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/02/09 04:09:10 DEBUG : empty space: Unchanged skipping 2025/02/09 04:09:10 DEBUG : Local file system at /tmp/rclone2478755479: Waiting for checks to finish 2025/02/09 04:09:10 DEBUG : Local file system at /tmp/rclone2478755479: Waiting for transfers to finish 2025/02/09 04:09:10 DEBUG : Waiting for deletions to finish 2025/02/09 04:09:10 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncWithExclude (5.85s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:09:13 DEBUG : potato2: md5 = 54e739c0a041f457211bed96771c96a0 OK 2025/02/09 04:09:15 DEBUG : empty space: md5 = a9e82e8c55a5bd292cb8ff7564529557 OK 2025/02/09 04:09:16 DEBUG : enormous: md5 = ce2e106c223a917256806228df252e2d OK 2025/02/09 04:09:16 DEBUG : enormous: Excluded (Size Filter) 2025/02/09 04:09:16 DEBUG : enormous: Excluded 2025/02/09 04:09:16 DEBUG : potato2: Excluded (Size Filter) 2025/02/09 04:09:16 DEBUG : potato2: Excluded 2025/02/09 04:09:17 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:09:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:09:17 DEBUG : empty space: Unchanged skipping 2025/02/09 04:09:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:09:17 DEBUG : Waiting for deletions to finish 2025/02/09 04:09:17 INFO : enormous: Deleted 2025/02/09 04:09:17 INFO : potato2: Deleted 2025/02/09 04:09:17 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:09:18 DEBUG : Local file system at /tmp/rclone2478755479: Waiting for checks to finish 2025/02/09 04:09:18 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/02/09 04:09:18 DEBUG : empty space: Unchanged skipping 2025/02/09 04:09:18 DEBUG : Local file system at /tmp/rclone2478755479: Waiting for transfers to finish 2025/02/09 04:09:18 DEBUG : Waiting for deletions to finish 2025/02/09 04:09:18 INFO : enormous: Deleted 2025/02/09 04:09:18 INFO : potato2: Deleted 2025/02/09 04:09:18 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.48s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:09:21 DEBUG : one: md5 = 2d5873c591c6f882b5f4e784f1dd657e OK 2025/02/09 04:09:22 DEBUG : two: md5 = 2cd633ee3e872bf11d32ab6f1b03d62e OK 2025/02/09 04:09:24 DEBUG : three: md5 = 47cd1059c62109cde5bbc53ba24bcb12 OK 2025/02/09 04:09:25 DEBUG : four: md5 = 1c47005010b3c02991791589b31b77f3 OK 2025/02/09 04:09:25 DEBUG : five: Need to transfer - File not found at Destination 2025/02/09 04:09:25 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/02/09 04:09:25 DEBUG : one: Destination is newer than source, skipping 2025/02/09 04:09:25 DEBUG : three: Sizes identical 2025/02/09 04:09:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:09:25 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/02/09 04:09:25 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/02/09 04:09:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:09:27 DEBUG : two: md5 = 7386390789f3a694d48a73900d2ac864 OK 2025/02/09 04:09:27 INFO : two: Copied (replaced existing) 2025/02/09 04:09:27 DEBUG : four: md5 = be8e7e0e0eaec0b77b42f1ba8541444c OK 2025/02/09 04:09:27 INFO : four: Copied (replaced existing) 2025/02/09 04:09:27 DEBUG : five: md5 = b5d110ceb85b641fc03765a24a1afe90 OK 2025/02/09 04:09:27 INFO : five: Copied (new) 2025/02/09 04:09:27 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (10.67s) === 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-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/02/09 04:09:30 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Ignoring --track-renames as the source and destination do not have a common hash 2025/02/09 04:09:30 DEBUG : potato: Need to transfer - File not found at Destination 2025/02/09 04:09:30 DEBUG : yam: Need to transfer - File not found at Destination 2025/02/09 04:09:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:09:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:09:32 DEBUG : yam: md5 = 3a1ee2e1433921d2a274d4daa00504dd OK 2025/02/09 04:09:32 INFO : yam: Copied (new) 2025/02/09 04:09:32 DEBUG : potato: md5 = 7d11b963213acfc8390f1e49bde2f954 OK 2025/02/09 04:09:32 INFO : potato: Copied (new) 2025/02/09 04:09:32 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:09:32 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Ignoring --track-renames as the source and destination do not have a common hash 2025/02/09 04:09:32 DEBUG : yaml: Need to transfer - File not found at Destination 2025/02/09 04:09:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:09:32 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:09:32 DEBUG : potato: Unchanged skipping 2025/02/09 04:09:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:09:34 DEBUG : yaml: md5 = d8b1037b9a9de4d434f4f36f7db92c08 OK 2025/02/09 04:09:34 INFO : yaml: Copied (new) 2025/02/09 04:09:34 DEBUG : Waiting for deletions to finish 2025/02/09 04:09:34 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (6.35s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/02/09 04:09:37 INFO : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Making map for --track-renames 2025/02/09 04:09:37 INFO : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Finished making map for --track-renames 2025/02/09 04:09:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:09:37 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/02/09 04:09:37 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/02/09 04:09:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for renames to finish 2025/02/09 04:09:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:09:38 DEBUG : yam: md5 = 5cae3ce1be1df4422bc36c4562d083c9 OK 2025/02/09 04:09:38 INFO : yam: Copied (new) 2025/02/09 04:09:38 DEBUG : potato: md5 = e249c59a16971efd89d197ccc74128af OK 2025/02/09 04:09:38 INFO : potato: Copied (new) 2025/02/09 04:09:38 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:09:39 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:09:39 INFO : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Making map for --track-renames 2025/02/09 04:09:39 INFO : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Finished making map for --track-renames 2025/02/09 04:09:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:09:39 DEBUG : potato: Unchanged skipping 2025/02/09 04:09:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for renames to finish 2025/02/09 04:09:39 INFO : yam: Moved (server-side) to: yaml 2025/02/09 04:09:39 INFO : yaml: Renamed from "yam" 2025/02/09 04:09:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:09:39 DEBUG : Waiting for deletions to finish 2025/02/09 04:09:39 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.51s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/02/09 04:09:42 DEBUG : Added delayed dir = "sub", newDst= 2025/02/09 04:09:42 INFO : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Making map for --track-renames 2025/02/09 04:09:42 INFO : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Finished making map for --track-renames 2025/02/09 04:09:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:09:42 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/02/09 04:09:42 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/02/09 04:09:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for renames to finish 2025/02/09 04:09:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:09:44 DEBUG : potato: md5 = 609b802d0c398560c49d4e1a828e5bbe OK 2025/02/09 04:09:44 INFO : potato: Copied (new) 2025/02/09 04:09:44 DEBUG : sub/yam: md5 = 225ac9a1392feb65912d095bf13a0b48 OK 2025/02/09 04:09:44 INFO : sub/yam: Copied (new) 2025/02/09 04:09:44 DEBUG : Waiting for deletions to finish 2025/02/09 04:09:45 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:09:46 DEBUG : Added delayed dir = "sub", newDst=sub 2025/02/09 04:09:46 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:09:46 DEBUG : potato: Unchanged skipping 2025/02/09 04:09:46 INFO : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Making map for --track-renames 2025/02/09 04:09:46 INFO : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Finished making map for --track-renames 2025/02/09 04:09:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:09:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for renames to finish 2025/02/09 04:09:47 INFO : sub/yam: Moved (server-side) to: yam 2025/02/09 04:09:47 INFO : yam: Renamed from "sub/yam" 2025/02/09 04:09:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:09:47 DEBUG : Waiting for deletions to finish 2025/02/09 04:09:47 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (8.36s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:09:50 DEBUG : Creating backend with remote "/tmp/rclone2478755479/dir1" 2025/02/09 04:09:50 DEBUG : Config file has changed externally - reloading 2025/02/09 04:09:50 DEBUG : Creating backend with remote "/tmp/rclone2478755479/dir2" 2025/02/09 04:09:50 DEBUG : Local file system at /tmp/rclone2478755479/dir2: Using server-side directory move 2025/02/09 04:09:50 INFO : Local file system at /tmp/rclone2478755479/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/02/09 04:09:50 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/02/09 04:09:50 INFO : file1.txt: Moved (server-side) 2025/02/09 04:09:50 DEBUG : Local file system at /tmp/rclone2478755479/dir2: Waiting for checks to finish 2025/02/09 04:09:50 DEBUG : Local file system at /tmp/rclone2478755479/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.42s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:09:51 DEBUG : Added delayed dir = "nested", newDst= 2025/02/09 04:09:51 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/09 04:09:51 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/09 04:09:51 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/02/09 04:09:51 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/02/09 04:09:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:09:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:09:53 DEBUG : sub dir/hello world: md5 = 1d2747964511e702caa1061e91e6dfbe OK 2025/02/09 04:09:53 INFO : sub dir/hello world: Copied (new) 2025/02/09 04:09:53 INFO : sub dir/hello world: Deleted 2025/02/09 04:09:55 DEBUG : nested/sub dir/file: md5 = 012e8bef3c0c11a17054851d25fa0495 OK 2025/02/09 04:09:55 INFO : nested/sub dir/file: Copied (new) 2025/02/09 04:09:55 INFO : nested/sub dir/file: Deleted 2025/02/09 04:09:55 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/02/09 04:09:56 INFO : nested: Set directory modification time (using DirSetModTime) 2025/02/09 04:09:56 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/09 04:09:56 INFO : sub dir: Removing directory 2025/02/09 04:09:56 INFO : nested/sub dir: Removing directory 2025/02/09 04:09:56 INFO : nested: Removing directory 2025/02/09 04:09:56 DEBUG : Local file system at /tmp/rclone2478755479: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:09:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/02/09 04:09:59 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/02/09 04:10:00 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (10.18s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:10:01 DEBUG : Added delayed dir = "nested", newDst= 2025/02/09 04:10:01 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/09 04:10:01 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/09 04:10:01 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/02/09 04:10:01 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/02/09 04:10:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:10:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:10:03 DEBUG : sub dir/hello world: md5 = 79c3c7ccd224dacabc001745bc8f4b5d OK 2025/02/09 04:10:03 INFO : sub dir/hello world: Copied (new) 2025/02/09 04:10:03 INFO : sub dir/hello world: Deleted 2025/02/09 04:10:05 DEBUG : nested/sub dir/file: md5 = ec9c5d2f517d8c40424c1d7c2103fea8 OK 2025/02/09 04:10:05 INFO : nested/sub dir/file: Copied (new) 2025/02/09 04:10:05 INFO : nested/sub dir/file: Deleted 2025/02/09 04:10:06 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/02/09 04:10:06 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/09 04:10:06 INFO : nested: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:10:09 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/02/09 04:10:09 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/02/09 04:10:10 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.26s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:10:11 DEBUG : existing: Need to transfer - File not found at Destination 2025/02/09 04:10:11 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/02/09 04:10:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:10:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:10:13 DEBUG : existing: md5 = c267c43500267c7c1fb8de430ce4eff0 OK 2025/02/09 04:10:13 INFO : existing: Copied (new) 2025/02/09 04:10:13 INFO : existing: Deleted 2025/02/09 04:10:13 DEBUG : existing-b: md5 = 02f9ca4a955155054294418488672a38 OK 2025/02/09 04:10:13 INFO : existing-b: Copied (new) 2025/02/09 04:10:13 INFO : existing-b: Deleted 2025/02/09 04:10:13 DEBUG : existing: Destination exists, skipping 2025/02/09 04:10:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:10:13 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/02/09 04:10:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:10:13 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.21s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:10:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hesituc7cobu" 2025/02/09 04:10:15 DEBUG : Creating backend with remote "TestDrive:crypt/c7m9rr0c0o4mr1qqe2oc1s76mi3f350fsi3l4qr9f40faqogska0" 2025/02/09 04:10:18 DEBUG : potato2: md5 = 056b66bb8618a56c7cb24fe088346a45 OK 2025/02/09 04:10:19 DEBUG : empty space: md5 = 2d1ce6f28993be1d2fa9dc096f3ea680 OK 2025/02/09 04:10:21 DEBUG : potato3: md5 = a0ef337e142d6e3adccd42cee58ad29a OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca' -> Encrypted drive 'TestCryptDrive:rclone-test-hesituc7cobu' 2025/02/09 04:10:23 DEBUG : empty space: md5 = 59be03d68e7bd8ae9db329e24e95f10f OK 2025/02/09 04:10:24 DEBUG : potato3: md5 = 430a04e2eddc9fd228032a949d7defe9 OK 2025/02/09 04:10:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hesituc7cobu': Using server-side directory move 2025/02/09 04:10:24 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hesituc7cobu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/02/09 04:10:25 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/09 04:10:25 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/02/09 04:10:25 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/02/09 04:10:25 DEBUG : empty space: Unchanged skipping 2025/02/09 04:10:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hesituc7cobu': Waiting for checks to finish 2025/02/09 04:10:25 INFO : potato3: Deleted 2025/02/09 04:10:25 INFO : empty space: Deleted 2025/02/09 04:10:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hesituc7cobu': Waiting for transfers to finish 2025/02/09 04:10:25 INFO : potato2: Moved (server-side) 2025/02/09 04:10:26 INFO : potato3: Moved (server-side) 2025/02/09 04:10:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zubafeh1cuyo" 2025/02/09 04:10:26 DEBUG : Creating backend with remote "TestDrive:crypt/qnk00c2g667t75rlrau59gteufprdeaopo8esk131t9o2kse888g" 2025/02/09 04:10:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zubafeh1cuyo': Using server-side directory move 2025/02/09 04:10:28 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zubafeh1cuyo': Server side directory move succeeded 2025/02/09 04:10:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zubafeh1cuyo': Purge remote 2025/02/09 04:10:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hesituc7cobu': Purge remote 2025/02/09 04:10:29 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (14.53s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:10:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dajuked9hama" 2025/02/09 04:10:30 DEBUG : Creating backend with remote "TestDrive:crypt/tlh4d9a261i2gt09i08runtdf48d7v43qhdpfa3nnod6a88qtae0" 2025/02/09 04:10:32 DEBUG : potato2: md5 = 5f65ae1c3e627ce5cc8c868fcd2ce8d2 OK 2025/02/09 04:10:34 DEBUG : empty space: md5 = d72991e65b1aa1673cba5ecb80473634 OK 2025/02/09 04:10:35 DEBUG : potato3: md5 = a55c4e7e4a48a36460aeff941a9bd7d6 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca' -> Encrypted drive 'TestCryptDrive:rclone-test-dajuked9hama' 2025/02/09 04:10:37 DEBUG : empty space: md5 = 3326435f4f73b8822f1069d12f8a3303 OK 2025/02/09 04:10:39 DEBUG : potato3: md5 = 9d5a05bacab6169db06fdfbfe112abb7 OK 2025/02/09 04:10:39 DEBUG : empty space: Excluded (Size Filter) 2025/02/09 04:10:39 DEBUG : empty space: Excluded (Size Filter) 2025/02/09 04:10:39 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/09 04:10:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dajuked9hama': Waiting for checks to finish 2025/02/09 04:10:39 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/02/09 04:10:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dajuked9hama': Waiting for transfers to finish 2025/02/09 04:10:40 INFO : potato3: Deleted 2025/02/09 04:10:40 INFO : potato2: Moved (server-side) 2025/02/09 04:10:40 INFO : potato3: Moved (server-side) 2025/02/09 04:10:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kiradod8zici" 2025/02/09 04:10:41 DEBUG : Creating backend with remote "TestDrive:crypt/lgs82lsnru2t7c1mftesb3sqo8nmdq8ebvaj0rtp52kfp7shequg" 2025/02/09 04:10:42 DEBUG : empty space: Excluded (Size Filter) 2025/02/09 04:10:42 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/09 04:10:42 DEBUG : potato3: Need to transfer - File not found at Destination 2025/02/09 04:10:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kiradod8zici': Waiting for checks to finish 2025/02/09 04:10:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kiradod8zici': Waiting for transfers to finish 2025/02/09 04:10:43 INFO : potato2: Moved (server-side) 2025/02/09 04:10:44 INFO : potato3: Moved (server-side) 2025/02/09 04:10:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kiradod8zici': Purge remote 2025/02/09 04:10:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dajuked9hama': Purge remote --- PASS: TestServerSideMoveWithFilter (15.88s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:10:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-josihil3woqu" 2025/02/09 04:10:46 DEBUG : Creating backend with remote "TestDrive:crypt/d7jqeeler43usbepikipca2er5b9cn5dkdkc4fjkp6o0qt3ib8sg" 2025/02/09 04:10:48 DEBUG : potato2: md5 = 19222440ec30c367e0042ee1a6bdd36d OK 2025/02/09 04:10:49 DEBUG : empty space: md5 = 31e6a80ae3d4b86858b8d8480b1f74bc OK 2025/02/09 04:10:51 DEBUG : potato3: md5 = 060330b2829fc8e1386e96da425c0328 OK 2025/02/09 04:10:51 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca' -> Encrypted drive 'TestCryptDrive:rclone-test-josihil3woqu' 2025/02/09 04:10:54 DEBUG : empty space: md5 = 0f04ee3ca0b489ca521cb340a77dbd2e OK 2025/02/09 04:10:56 DEBUG : potato3: md5 = 5fa927c5fd677fc0ebb2cc9baccfd064 OK 2025/02/09 04:10:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-josihil3woqu': Using server-side directory move 2025/02/09 04:10:56 INFO : Encrypted drive 'TestCryptDrive:rclone-test-josihil3woqu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/02/09 04:10:56 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/09 04:10:56 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/02/09 04:10:56 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/02/09 04:10:56 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/02/09 04:10:56 DEBUG : empty space: Unchanged skipping 2025/02/09 04:10:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-josihil3woqu': Waiting for checks to finish 2025/02/09 04:10:57 INFO : potato3: Deleted 2025/02/09 04:10:57 INFO : empty space: Deleted 2025/02/09 04:10:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-josihil3woqu': Waiting for transfers to finish 2025/02/09 04:10:57 INFO : potato2: Moved (server-side) 2025/02/09 04:10:57 INFO : potato3: Moved (server-side) 2025/02/09 04:10:57 INFO : tomatoDir: Removing directory 2025/02/09 04:10:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': deleted 1 directories 2025/02/09 04:10:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vuxupug4zoja" 2025/02/09 04:10:59 DEBUG : Creating backend with remote "TestDrive:crypt/5k0hd17hbobo797p6vf7j8u92tv2uki0977isu775fm5um0r3200" 2025/02/09 04:11:00 INFO : tomatoDir: Making directory 2025/02/09 04:11:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vuxupug4zoja': Using server-side directory move 2025/02/09 04:11:01 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vuxupug4zoja': Server side directory move succeeded 2025/02/09 04:11:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vuxupug4zoja': Purge remote 2025/02/09 04:11:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-josihil3woqu': Purge remote 2025/02/09 04:11:03 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (17.79s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.45s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:11:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/rclone-sync-test" 2025/02/09 04:11:04 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncOverlap (3.75s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:11:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/rclone-sync-test" 2025/02/09 04:11:08 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/02/09 04:11:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/rclone-sync-test-include/layer2" 2025/02/09 04:11:10 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/02/09 04:11:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/rclone-sync-test-ignore-file" 2025/02/09 04:11:13 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/02/09 04:11:17 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = c7a11be717b75a9f1522bb49f1ce1968 OK 2025/02/09 04:11:19 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/02/09 04:11:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/rclone-sync-test': Waiting for checks to finish 2025/02/09 04:11:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/rclone-sync-test': Waiting for transfers to finish 2025/02/09 04:11:19 DEBUG : Waiting for deletions to finish 2025/02/09 04:11:19 INFO : There was nothing to transfer 2025/02/09 04:11:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:11:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:11:20 DEBUG : Waiting for deletions to finish 2025/02/09 04:11:20 INFO : rclone-sync-test-include: Removing directory 2025/02/09 04:11:21 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/02/09 04:11:21 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/02/09 04:11:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': failed to delete 1 directories 2025/02/09 04:11:21 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:11:22 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/02/09 04:11:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/02/09 04:11:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/02/09 04:11:22 DEBUG : Waiting for deletions to finish 2025/02/09 04:11:22 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:11:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:11:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:11:24 DEBUG : Waiting for deletions to finish 2025/02/09 04:11:24 INFO : rclone-sync-test-include: Removing directory 2025/02/09 04:11:25 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/02/09 04:11:25 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/02/09 04:11:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': failed to delete 1 directories 2025/02/09 04:11:25 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:11:26 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/02/09 04:11:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/02/09 04:11:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/02/09 04:11:26 DEBUG : Waiting for deletions to finish 2025/02/09 04:11:26 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:11:28 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/02/09 04:11:29 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (30.44s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:11:38 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/dst" 2025/02/09 04:11:38 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/09 04:11:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/CompareDest" 2025/02/09 04:11:40 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/gveqi14airsml4bgu7krj116o8" 2025/02/09 04:11:42 DEBUG : one: Need to transfer - File not found at Destination 2025/02/09 04:11:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:11:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:11:44 DEBUG : one: md5 = 9274f4148e07b227028f74b2853f1922 OK 2025/02/09 04:11:44 INFO : one: Copied (new) 2025/02/09 04:11:44 DEBUG : Waiting for deletions to finish 2025/02/09 04:11:45 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/09 04:11:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:11:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:11:46 DEBUG : one: md5 = 43cf1e9fd2cc54d6ae10bdd4f0e1c70d OK 2025/02/09 04:11:46 INFO : one: Copied (replaced existing) 2025/02/09 04:11:46 DEBUG : Waiting for deletions to finish 2025/02/09 04:11:48 DEBUG : dst/one: md5 = 9ba89dc306a1bee2df961d2fe480b459 OK 2025/02/09 04:11:50 DEBUG : CompareDest/one: md5 = 6bfc5b8eee905dfb13a0d0c92fa20f82 OK 2025/02/09 04:11:51 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/09 04:11:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:11:51 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:11:51 DEBUG : one: Destination found in --compare-dest, skipping 2025/02/09 04:11:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:11:51 DEBUG : Waiting for deletions to finish 2025/02/09 04:11:51 INFO : There was nothing to transfer 2025/02/09 04:11:53 DEBUG : CompareDest/two: md5 = cf2c4b52d12b8497a96474312acfddee OK 2025/02/09 04:11:54 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:11:54 DEBUG : two: Destination found in --compare-dest, skipping 2025/02/09 04:11:54 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/09 04:11:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:11:54 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:11:54 DEBUG : one: Destination found in --compare-dest, skipping 2025/02/09 04:11:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:11:54 DEBUG : Waiting for deletions to finish 2025/02/09 04:11:54 INFO : There was nothing to transfer 2025/02/09 04:11:55 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:11:55 DEBUG : two: Destination found in --compare-dest, skipping 2025/02/09 04:11:55 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/09 04:11:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:11:56 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:11:56 DEBUG : one: Destination found in --compare-dest, skipping 2025/02/09 04:11:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:11:56 DEBUG : Waiting for deletions to finish 2025/02/09 04:11:56 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/02/09 04:11:57 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/02/09 04:11:57 DEBUG : two: Need to transfer - File not found at Destination 2025/02/09 04:11:57 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/09 04:11:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:11:57 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:11:57 DEBUG : one: Destination found in --compare-dest, skipping 2025/02/09 04:11:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:11:58 DEBUG : two: md5 = 60e8b817e813d33668b3958b37cf4577 OK 2025/02/09 04:11:58 INFO : two: Copied (new) 2025/02/09 04:11:58 DEBUG : Waiting for deletions to finish 2025/02/09 04:12:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/09 04:12:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/09 04:12:02 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/09 04:12:02 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncCompareDest (24.96s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:12:05 DEBUG : pre-dest1/1: md5 = 1efaf524c8e2b2d3a006cf4f6a3ec3eb OK 2025/02/09 04:12:07 DEBUG : pre-dest2/2: md5 = d16c503ce079e39636bc0adccc5a2200 OK 2025/02/09 04:12:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/dest" 2025/02/09 04:12:08 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/rg03c1jvnehrrc617i0lnqjddc" 2025/02/09 04:12:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/pre-dest1" 2025/02/09 04:12:09 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/bbnblvh6k061ssopqrp18kd7gc" 2025/02/09 04:12:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/pre-dest2" 2025/02/09 04:12:10 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/dgicm1h6b5ejvlltm8eeif0bnk" 2025/02/09 04:12:11 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:12:11 DEBUG : 1: Destination found in --compare-dest, skipping 2025/02/09 04:12:12 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:12:12 DEBUG : 2: Destination found in --compare-dest, skipping 2025/02/09 04:12:12 DEBUG : 3: Need to transfer - File not found at Destination 2025/02/09 04:12:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dest': Waiting for checks to finish 2025/02/09 04:12:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dest': Waiting for transfers to finish 2025/02/09 04:12:14 DEBUG : 3: md5 = eca4e36809aca55185af78713fb88a4c OK 2025/02/09 04:12:14 INFO : 3: Copied (new) 2025/02/09 04:12:14 DEBUG : Waiting for deletions to finish 2025/02/09 04:12:17 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/02/09 04:12:18 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/02/09 04:12:18 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (15.84s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:12:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/dst" 2025/02/09 04:12:19 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/09 04:12:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/CopyDest" 2025/02/09 04:12:20 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/d09o6po3f7bm6ce32vdgs8h9ls" 2025/02/09 04:12:22 DEBUG : one: Need to transfer - File not found at Destination 2025/02/09 04:12:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:12:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:12:24 DEBUG : one: md5 = 46ca3a85fd9580c19a2b7024db334d39 OK 2025/02/09 04:12:24 INFO : one: Copied (new) 2025/02/09 04:12:24 DEBUG : Waiting for deletions to finish 2025/02/09 04:12:26 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/09 04:12:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:12:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:12:27 DEBUG : one: md5 = b9a08acc354b416f16f853f5dc456870 OK 2025/02/09 04:12:27 INFO : one: Copied (replaced existing) 2025/02/09 04:12:27 DEBUG : Waiting for deletions to finish 2025/02/09 04:12:29 DEBUG : dst/one: md5 = 8f4a60ac35901b668eecfe2c1f3dd26a OK 2025/02/09 04:12:31 DEBUG : CopyDest/one: md5 = 5140a48ad2bc240e4642bcf47ac36f22 OK 2025/02/09 04:12:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/BackupDir" 2025/02/09 04:12:31 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/02/09 04:12:33 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/09 04:12:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:12:33 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:12:33 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/09 04:12:35 INFO : one: Moved (server-side) 2025/02/09 04:12:36 INFO : one: Copied (server-side copy) 2025/02/09 04:12:36 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/02/09 04:12:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:12:36 DEBUG : Waiting for deletions to finish 2025/02/09 04:12:38 DEBUG : CopyDest/two: md5 = 401ca2133b8d7f2b4cd049b8ee675952 OK 2025/02/09 04:12:39 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:12:40 INFO : two: Copied (server-side copy) 2025/02/09 04:12:40 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/02/09 04:12:40 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:12:40 DEBUG : one: Unchanged skipping 2025/02/09 04:12:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:12:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:12:40 DEBUG : Waiting for deletions to finish 2025/02/09 04:12:41 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:12:41 DEBUG : one: Unchanged skipping 2025/02/09 04:12:41 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:12:41 DEBUG : two: Unchanged skipping 2025/02/09 04:12:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:12:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:12:41 DEBUG : Waiting for deletions to finish 2025/02/09 04:12:41 INFO : There was nothing to transfer 2025/02/09 04:12:43 DEBUG : CopyDest/three: md5 = 4e010f1736564e9d0e233778062379c6 OK 2025/02/09 04:12:44 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/02/09 04:12:44 DEBUG : three: Destination not found in --copy-dest 2025/02/09 04:12:44 DEBUG : three: Need to transfer - File not found at Destination 2025/02/09 04:12:44 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:12:44 DEBUG : one: Unchanged skipping 2025/02/09 04:12:44 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/09 04:12:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:12:44 DEBUG : two: Unchanged skipping 2025/02/09 04:12:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:12:45 DEBUG : three: md5 = c04cbeb8267ee117d5c1c9b5aad24180 OK 2025/02/09 04:12:45 INFO : three: Copied (new) 2025/02/09 04:12:45 DEBUG : Waiting for deletions to finish 2025/02/09 04:12:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/02/09 04:12:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/09 04:12:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/09 04:12:50 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/02/09 04:12:50 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/09 04:12:50 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/09 04:12:51 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (32.56s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:12:53 DEBUG : dst/one: md5 = 34b9eac4f63ef6272d01b4a091d2d0fe OK 2025/02/09 04:12:55 DEBUG : dst/two: md5 = 3bf76374badfb515395f145b3cdcfd99 OK 2025/02/09 04:12:56 DEBUG : dst/three.txt: md5 = dacd0e074f10ef78ff8a6214f300ff38 OK 2025/02/09 04:12:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/dst" 2025/02/09 04:12:57 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/09 04:12:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/backup" 2025/02/09 04:12:58 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/1nrff024r7pq65ecp72fc28jb0" 2025/02/09 04:12:59 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/09 04:12:59 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:12:59 DEBUG : two: Unchanged skipping 2025/02/09 04:12:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:13:01 INFO : one: Moved (server-side) 2025/02/09 04:13:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:13:02 DEBUG : one: md5 = 39b9b22c9657c06bc386f3d021153dac OK 2025/02/09 04:13:02 INFO : one: Copied (new) 2025/02/09 04:13:02 DEBUG : Waiting for deletions to finish 2025/02/09 04:13:03 INFO : three.txt: Moved (server-side) 2025/02/09 04:13:03 INFO : three.txt: Moved into backup dir 2025/02/09 04:13:05 DEBUG : dst/three.txt: md5 = 927d80f84f0d16d5c327c711536abe3e OK 2025/02/09 04:13:06 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/09 04:13:06 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:13:06 DEBUG : two: Unchanged skipping 2025/02/09 04:13:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:13:06 INFO : one: Deleted 2025/02/09 04:13:07 INFO : one: Moved (server-side) 2025/02/09 04:13:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:13:08 DEBUG : one: md5 = 8394d51569494131e9549355b8d8bdd6 OK 2025/02/09 04:13:08 INFO : one: Copied (new) 2025/02/09 04:13:08 DEBUG : Waiting for deletions to finish 2025/02/09 04:13:09 INFO : three.txt: Deleted 2025/02/09 04:13:09 INFO : three.txt: Moved (server-side) 2025/02/09 04:13:09 INFO : three.txt: Moved into backup dir 2025/02/09 04:13:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/09 04:13:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/09 04:13:13 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/09 04:13:13 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/02/09 04:13:13 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/09 04:13:13 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" --- PASS: TestSyncBackupDir (22.25s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:13:16 DEBUG : dst/one: md5 = cfbc368a52615fb0f818b92f03173648 OK 2025/02/09 04:13:17 DEBUG : dst/two: md5 = 6faae88c0092cf9e9aa6d7bd643fa053 OK 2025/02/09 04:13:18 DEBUG : dst/three.txt: md5 = 5f0a1ef95e8d6349231e52279d94abea OK 2025/02/09 04:13:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/dst" 2025/02/09 04:13:19 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/09 04:13:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/backup" 2025/02/09 04:13:20 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/1nrff024r7pq65ecp72fc28jb0" 2025/02/09 04:13:21 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/09 04:13:21 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:13:21 DEBUG : two: Unchanged skipping 2025/02/09 04:13:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:13:23 INFO : one: Moved (server-side) to: one.bak 2025/02/09 04:13:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:13:24 DEBUG : one: md5 = 8cee812eab7ac57bc105517277b81420 OK 2025/02/09 04:13:24 INFO : one: Copied (new) 2025/02/09 04:13:24 DEBUG : Waiting for deletions to finish 2025/02/09 04:13:25 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/02/09 04:13:25 INFO : three.txt: Moved into backup dir 2025/02/09 04:13:27 DEBUG : dst/three.txt: md5 = ed1070696ac8de96d46aec8ec34b7de1 OK 2025/02/09 04:13:28 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/09 04:13:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:13:28 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:13:28 DEBUG : two: Unchanged skipping 2025/02/09 04:13:28 INFO : one.bak: Deleted 2025/02/09 04:13:29 INFO : one: Moved (server-side) to: one.bak 2025/02/09 04:13:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:13:30 DEBUG : one: md5 = 42588a6abf1529164db78f7589d1844d OK 2025/02/09 04:13:30 INFO : one: Copied (new) 2025/02/09 04:13:30 DEBUG : Waiting for deletions to finish 2025/02/09 04:13:31 INFO : three.txt.bak: Deleted 2025/02/09 04:13:32 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/02/09 04:13:32 INFO : three.txt: Moved into backup dir 2025/02/09 04:13:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/09 04:13:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/09 04:13:36 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/02/09 04:13:36 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/02/09 04:13:36 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/02/09 04:13:36 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirWithSuffix (22.44s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:13:38 DEBUG : dst/one: md5 = 5e7827c19558ba502067d573ff7ff9ce OK 2025/02/09 04:13:40 DEBUG : dst/two: md5 = 855bfaa8f35eb4262d46b91b3abba1a3 OK 2025/02/09 04:13:41 DEBUG : dst/three.txt: md5 = 41e29244794679b0d0bc96a431aed2c3 OK 2025/02/09 04:13:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/dst" 2025/02/09 04:13:42 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/09 04:13:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/backup" 2025/02/09 04:13:42 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/1nrff024r7pq65ecp72fc28jb0" 2025/02/09 04:13:44 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/09 04:13:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:13:44 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:13:44 DEBUG : two: Unchanged skipping 2025/02/09 04:13:46 INFO : one: Moved (server-side) to: one-2019-01-01 2025/02/09 04:13:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:13:47 DEBUG : one: md5 = 12bd97ff67427d61b94647f802e6a667 OK 2025/02/09 04:13:47 INFO : one: Copied (new) 2025/02/09 04:13:47 DEBUG : Waiting for deletions to finish 2025/02/09 04:13:48 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/02/09 04:13:48 INFO : three.txt: Moved into backup dir 2025/02/09 04:13:50 DEBUG : dst/three.txt: md5 = 4f23ebb817dd41f50d7f08ffdb5bce45 OK 2025/02/09 04:13:50 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/09 04:13:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:13:50 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:13:50 DEBUG : two: Unchanged skipping 2025/02/09 04:13:51 INFO : one-2019-01-01: Deleted 2025/02/09 04:13:51 INFO : one: Moved (server-side) to: one-2019-01-01 2025/02/09 04:13:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:13:53 DEBUG : one: md5 = ef0e74722eeec61087521ac77bd81384 OK 2025/02/09 04:13:53 INFO : one: Copied (new) 2025/02/09 04:13:53 DEBUG : Waiting for deletions to finish 2025/02/09 04:13:54 INFO : three-2019-01-01.txt: Deleted 2025/02/09 04:13:54 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/02/09 04:13:54 INFO : three.txt: Moved into backup dir 2025/02/09 04:13:57 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/09 04:13:57 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/09 04:13:58 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/02/09 04:13:58 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/02/09 04:13:58 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/02/09 04:13:58 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (22.16s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:14:00 DEBUG : dst/one: md5 = b5b3026a82a3da4f36403e67f49e4b28 OK 2025/02/09 04:14:02 DEBUG : dst/two: md5 = e451a03d8afaa65de139e19069b088c8 OK 2025/02/09 04:14:03 DEBUG : dst/three.txt: md5 = 3a66be4d1c1d5a965b0a675eb56b446e OK 2025/02/09 04:14:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/dst" 2025/02/09 04:14:04 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/09 04:14:05 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/09 04:14:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:14:05 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:14:05 DEBUG : two: Unchanged skipping 2025/02/09 04:14:05 INFO : one: Moved (server-side) to: one.bak 2025/02/09 04:14:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:14:07 DEBUG : one: md5 = ba75f0f4246c56f3ddc769892c8addb9 OK 2025/02/09 04:14:07 INFO : one: Copied (new) 2025/02/09 04:14:07 DEBUG : Waiting for deletions to finish 2025/02/09 04:14:07 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/02/09 04:14:07 INFO : three.txt: Moved into backup dir 2025/02/09 04:14:09 DEBUG : dst/three.txt: md5 = 9e2a7c402615987886565c3a95ce9805 OK 2025/02/09 04:14:10 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/02/09 04:14:10 DEBUG : one.bak: Excluded (Path Filter) 2025/02/09 04:14:10 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/09 04:14:10 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:14:10 DEBUG : two: Unchanged skipping 2025/02/09 04:14:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for checks to finish 2025/02/09 04:14:11 INFO : one.bak: Deleted 2025/02/09 04:14:11 INFO : one: Moved (server-side) to: one.bak 2025/02/09 04:14:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca/dst': Waiting for transfers to finish 2025/02/09 04:14:13 DEBUG : one: md5 = 0ab068448f39e5331b0201bdbd71e4c6 OK 2025/02/09 04:14:13 INFO : one: Copied (new) 2025/02/09 04:14:13 DEBUG : Waiting for deletions to finish 2025/02/09 04:14:13 INFO : three.txt.bak: Deleted 2025/02/09 04:14:14 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/02/09 04:14:14 INFO : three.txt: Moved into backup dir 2025/02/09 04:14:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/09 04:14:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/02/09 04:14:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/02/09 04:14:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/09 04:14:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/02/09 04:14:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirSuffixOnly (19.19s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:14:20 DEBUG : dst/one: md5 = 91137d8437af1a4a4712f1de00e61b5e OK 2025/02/09 04:14:21 DEBUG : dst/two: md5 = cee48932b35c19d57574e4c378c9ff4a OK 2025/02/09 04:14:22 DEBUG : dst/three.txt: md5 = f8c9e6c71d975880d85e571e6850566c OK 2025/02/09 04:14:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/dst" 2025/02/09 04:14:23 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/09 04:14:24 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/09 04:14:25 INFO : one: Moved (server-side) to: one.bak 2025/02/09 04:14:26 DEBUG : one: md5 = b80ad5bdad86bfe01e99e2f3e8b6d08b OK 2025/02/09 04:14:26 INFO : one: Copied (new) 2025/02/09 04:14:27 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:14:27 DEBUG : two: Unchanged skipping 2025/02/09 04:14:27 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/02/09 04:14:27 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/02/09 04:14:29 DEBUG : three.txt: md5 = 39265ab709dbae0caffebaa1c5a922eb OK 2025/02/09 04:14:29 INFO : three.txt: Copied (new) 2025/02/09 04:14:30 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/09 04:14:31 INFO : one.bak: Deleted 2025/02/09 04:14:31 INFO : one: Moved (server-side) to: one.bak 2025/02/09 04:14:32 DEBUG : one: md5 = 595d5d729caa5b443117bcd192766c16 OK 2025/02/09 04:14:32 INFO : one: Copied (new) 2025/02/09 04:14:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:14:33 DEBUG : two: Unchanged skipping 2025/02/09 04:14:33 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/02/09 04:14:34 INFO : three.txt.bak: Deleted 2025/02/09 04:14:34 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/02/09 04:14:35 DEBUG : three.txt: md5 = d2f36e7d402729af213305ebe590d695 OK 2025/02/09 04:14:35 INFO : three.txt: Copied (new) 2025/02/09 04:14:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/09 04:14:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/02/09 04:14:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/02/09 04:14:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/02/09 04:14:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/02/09 04:14:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/02/09 04:14:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncSuffix (21.64s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:14:41 DEBUG : dst/one: md5 = db4c95c82e0e7a2a5fa98ce180227367 OK 2025/02/09 04:14:43 DEBUG : dst/two: md5 = bfb66b28c8989c1589cd401bd2f37a6b OK 2025/02/09 04:14:44 DEBUG : dst/three.txt: md5 = e7f454bce14e7064acba8647b741440e OK 2025/02/09 04:14:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gumibab5roca/dst" 2025/02/09 04:14:45 DEBUG : Creating backend with remote "TestDrive:crypt/kjklmqkqnlbq73dn02t04m04e9ii10cp2lvii0lan2q5s1g3es80/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/09 04:14:46 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/09 04:14:46 INFO : one: Moved (server-side) to: one-2019-01-01 2025/02/09 04:14:48 DEBUG : one: md5 = 19164f132dc0280a1b5ee30ff07fd368 OK 2025/02/09 04:14:48 INFO : one: Copied (new) 2025/02/09 04:14:48 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:14:48 DEBUG : two: Unchanged skipping 2025/02/09 04:14:48 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/02/09 04:14:49 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/02/09 04:14:50 DEBUG : three.txt: md5 = a7514d1eaa70036f91725b40cec22409 OK 2025/02/09 04:14:50 INFO : three.txt: Copied (new) 2025/02/09 04:14:51 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/09 04:14:52 INFO : one-2019-01-01: Deleted 2025/02/09 04:14:53 INFO : one: Moved (server-side) to: one-2019-01-01 2025/02/09 04:14:54 DEBUG : one: md5 = e87139e658ce72dc8dee0d20873b9429 OK 2025/02/09 04:14:54 INFO : one: Copied (new) 2025/02/09 04:14:54 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:14:54 DEBUG : two: Unchanged skipping 2025/02/09 04:14:54 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/02/09 04:14:55 INFO : three-2019-01-01.txt: Deleted 2025/02/09 04:14:55 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/02/09 04:14:57 DEBUG : three.txt: md5 = 26ea2f7940e39e26681a5a3f4cfe6031 OK 2025/02/09 04:14:57 INFO : three.txt: Copied (new) 2025/02/09 04:15:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/09 04:15:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/02/09 04:15:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/02/09 04:15:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/02/09 04:15:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/09 04:15:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/02/09 04:15:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (21.59s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:15:02 DEBUG : Testêé: md5 = c45a74869f01fd33f6bfe3a8baf67c92 OK 2025/02/09 04:15:03 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/02/09 04:15:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:15:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:15:04 DEBUG : Testêé: md5 = a0d9fd567c216c8e223b76ae39f60e96 OK 2025/02/09 04:15:04 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/02/09 04:15:04 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.23s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:15:05 DEBUG : existing: Need to transfer - File not found at Destination 2025/02/09 04:15:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:15:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:15:07 DEBUG : existing: md5 = eaee86bcbd25e77952e3991513c5ae6a OK 2025/02/09 04:15:07 INFO : existing: Copied (new) 2025/02/09 04:15:07 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:15:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:15:08 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/02/09 04:15:08 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/02/09 04:15:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:15:08 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': not deleting files as there were IO errors 2025/02/09 04:15:08 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncImmutable (4.80s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:15:11 DEBUG : EXISTING: md5 = 9e30dd5cb8ffb882cc9f2a0b32242afd OK 2025/02/09 04:15:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:15:12 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:15:12 DEBUG : existing: Unchanged skipping 2025/02/09 04:15:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:15:12 DEBUG : Waiting for deletions to finish 2025/02/09 04:15:12 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (2.90s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.44s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", 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-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", 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-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.31s) --- SKIP: TestMaxTransfer/Hard (0.43s) --- SKIP: TestMaxTransfer/Soft (0.46s) --- SKIP: TestMaxTransfer/Cautious (0.41s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:15:16 DEBUG : both0: md5 = 5b2abc3b5d41924f41fc961c0a5d139b OK 2025/02/09 04:15:17 DEBUG : only0: md5 = 5463b37207f64ba9a6cef3f66dda45c8 OK 2025/02/09 04:15:19 DEBUG : both1: md5 = c4d8f8c3e5f7bab84b977b653ac78677 OK 2025/02/09 04:15:20 DEBUG : only1: md5 = b7df6caff17e8d86e72852de6e8c2b9a OK 2025/02/09 04:15:22 DEBUG : both2: md5 = 3346a313787ae1d14621ee7b3cd68d23 OK 2025/02/09 04:15:23 DEBUG : only2: md5 = d04e5255ad0d071e5d3c7b40d14f73ad OK 2025/02/09 04:15:24 DEBUG : both3: md5 = 0c2fbc1c434f859409d0a10382ab1ee5 OK 2025/02/09 04:15:26 DEBUG : only3: md5 = 8cc4a22c83e68570b14bc1e0157605f8 OK 2025/02/09 04:15:27 DEBUG : both4: md5 = e960f62e98411a0e59bb546b62b0b17a OK 2025/02/09 04:15:29 DEBUG : only4: md5 = 64f494358253ca181bbb68d2c25d4b31 OK 2025/02/09 04:15:30 DEBUG : both5: md5 = 8c8b97a88182780b63d684851e452d45 OK 2025/02/09 04:15:32 DEBUG : only5: md5 = c616b841e973887fd854b4e3827a8be8 OK 2025/02/09 04:15:33 DEBUG : both6: md5 = 1ae47a3a35c2697f1a9bcf9ec5b309eb OK 2025/02/09 04:15:34 DEBUG : only6: md5 = 57c969dbcb92d5413d3af2c066f0f551 OK 2025/02/09 04:15:36 DEBUG : both7: md5 = 404e2fcdf6db51d7ccb77911f69b0442 OK 2025/02/09 04:15:37 DEBUG : only7: md5 = 3f2cd5ff6f42af2eb2ed3ac1adb93142 OK 2025/02/09 04:15:39 DEBUG : both8: md5 = 91e9ff7640f5efe63e0c139608215a6c OK 2025/02/09 04:15:40 DEBUG : only8: md5 = fd5117b893a5b048574a1b1b177c6aad OK 2025/02/09 04:15:41 DEBUG : both9: md5 = b02f32622632c5e187b71755e24bb1c4 OK 2025/02/09 04:15:43 DEBUG : only9: md5 = 40688217db591098af1ca53d4f9a02b4 OK 2025/02/09 04:15:44 DEBUG : both10: md5 = 236e98254a7c098949eb92fa1fe5b029 OK 2025/02/09 04:15:45 DEBUG : only10: md5 = 7d7d3b9c6af10bdd71487a689fa69c03 OK 2025/02/09 04:15:47 DEBUG : both11: md5 = d0ed609b99ab46b1a3867c5017078b34 OK 2025/02/09 04:15:48 DEBUG : only11: md5 = 7ba0bfe22e794e18eadb27e47d1c41bb OK 2025/02/09 04:15:49 DEBUG : both12: md5 = 957ac191f347628f5a8e1d114e9c532a OK 2025/02/09 04:15:51 DEBUG : only12: md5 = 46093f53e554e085fc83184bb6a9f5eb OK 2025/02/09 04:15:52 DEBUG : both13: md5 = dbf365e874e16d57c80ffbd9f7f4584f OK 2025/02/09 04:15:54 DEBUG : only13: md5 = b0bb9996f3eef7445c7154b950ef1e60 OK 2025/02/09 04:15:55 DEBUG : both14: md5 = 0883b0af89e1ae7b89d1d2a9a2088992 OK 2025/02/09 04:15:56 DEBUG : only14: md5 = 33ce7d9d5d262a91a5d99f15af22455f OK 2025/02/09 04:15:58 DEBUG : both15: md5 = c8644a949c2fb1a11ef8f667954ae0c3 OK 2025/02/09 04:15:59 DEBUG : only15: md5 = d0a3699f8a7ac203ab93f5ce07119971 OK 2025/02/09 04:16:00 DEBUG : both16: md5 = 4e1a48031e43a796b5045ea2721364e4 OK 2025/02/09 04:16:02 DEBUG : only16: md5 = 25ea6f820a9f8d9f532194e45d2b74a7 OK 2025/02/09 04:16:03 DEBUG : both17: md5 = 2872a92b5ea27fed5dced272739e2650 OK 2025/02/09 04:16:04 DEBUG : only17: md5 = d40930c1d2834b1b331b20f0c4bd6c0a OK 2025/02/09 04:16:06 DEBUG : both18: md5 = c664302b3e5d2dffe79afad4f1ec650a OK 2025/02/09 04:16:07 DEBUG : only18: md5 = 217430bf7c4f40c76d9e1a8957d4aaa0 OK 2025/02/09 04:16:09 DEBUG : both19: md5 = 4844290b15d6ecf815608abdc01b2888 OK 2025/02/09 04:16:10 DEBUG : only19: md5 = ef29cd088949c0276a0bc0ef5f058d41 OK 2025/02/09 04:16:10 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:16:10 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both0: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both12: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both13: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both1: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both15: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both16: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both17: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both18: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both19: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both2: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both3: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both10: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both5: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both11: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both7: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both14: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:16:10 DEBUG : both4: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both9: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both6: Unchanged skipping 2025/02/09 04:16:10 DEBUG : both8: Unchanged skipping 2025/02/09 04:16:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:16:10 DEBUG : Waiting for deletions to finish 2025/02/09 04:16:11 INFO : only9: Deleted 2025/02/09 04:16:11 INFO : only4: Deleted 2025/02/09 04:16:11 INFO : only2: Deleted 2025/02/09 04:16:11 INFO : only18: Deleted 2025/02/09 04:16:11 INFO : only19: Deleted 2025/02/09 04:16:11 INFO : only3: Deleted 2025/02/09 04:16:11 INFO : only0: Deleted 2025/02/09 04:16:11 INFO : only6: Deleted 2025/02/09 04:16:12 INFO : only14: Deleted 2025/02/09 04:16:12 INFO : only12: Deleted 2025/02/09 04:16:12 INFO : only16: Deleted 2025/02/09 04:16:12 INFO : only10: Deleted 2025/02/09 04:16:12 INFO : only11: Deleted 2025/02/09 04:16:12 INFO : only13: Deleted 2025/02/09 04:16:12 INFO : only15: Deleted 2025/02/09 04:16:12 INFO : only17: Deleted 2025/02/09 04:16:13 INFO : only5: Deleted 2025/02/09 04:16:13 INFO : only7: Deleted 2025/02/09 04:16:13 INFO : only8: Deleted 2025/02/09 04:16:13 INFO : only1: Deleted 2025/02/09 04:16:13 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (67.75s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:16:24 DEBUG : both0: md5 = 446e8b0182d5120fdbc78aa1b3fa125d OK 2025/02/09 04:16:25 DEBUG : only0: md5 = 6e92a1d1adf7358117b723bfbe121ca0 OK 2025/02/09 04:16:26 DEBUG : both1: md5 = 1fa983a571ad051f5512e30f1a794d1b OK 2025/02/09 04:16:28 DEBUG : only1: md5 = 0181ba9ea1d0c3f73c910118b3f697d1 OK 2025/02/09 04:16:29 DEBUG : both2: md5 = 8d3a2ee6707c6ba78fc4edfb5f9d21c5 OK 2025/02/09 04:16:30 DEBUG : only2: md5 = 093c8134e852a08517eb9fcac0a006e2 OK 2025/02/09 04:16:32 DEBUG : both3: md5 = 23f5828d0d84dff1b821833567b80ab5 OK 2025/02/09 04:16:33 DEBUG : only3: md5 = 3f145f22db9891610ea856f4f234a63d OK 2025/02/09 04:16:34 DEBUG : both4: md5 = c5b1ddcef95476c630dd3d400bc42108 OK 2025/02/09 04:16:36 DEBUG : only4: md5 = 956d9e11ce34b606f18982438b4ed9cb OK 2025/02/09 04:16:37 DEBUG : both5: md5 = d90d20927b7e80864abcdf1935d20c51 OK 2025/02/09 04:16:39 DEBUG : only5: md5 = 5200fb2cecce6d12fdb2b49bad50a221 OK 2025/02/09 04:16:40 DEBUG : both6: md5 = 42c20b3c7a37e4aae22a538c4fe22582 OK 2025/02/09 04:16:41 DEBUG : only6: md5 = 95fd04ca77b9e0ef54cce10785646af1 OK 2025/02/09 04:16:43 DEBUG : both7: md5 = acdd92c6973605fee25e88ad1e012e4d OK 2025/02/09 04:16:44 DEBUG : only7: md5 = 8ae1223fadd6613e927e413821605574 OK 2025/02/09 04:16:45 DEBUG : both8: md5 = 25916046eaa89b61dccb48c8bd9163fa OK 2025/02/09 04:16:47 DEBUG : only8: md5 = 1e432846792c588b5960c3868795e0c0 OK 2025/02/09 04:16:48 DEBUG : both9: md5 = 86fa58fb1833d83ac89ff62b727d70b5 OK 2025/02/09 04:16:49 DEBUG : only9: md5 = 2f586dae750f200af1e04db9fe7866ca OK 2025/02/09 04:16:51 DEBUG : both10: md5 = 854e8414caafee8684aa7c7f6ff562e2 OK 2025/02/09 04:16:52 DEBUG : only10: md5 = 7475b0613bae7569d87dcd93d191f001 OK 2025/02/09 04:16:53 DEBUG : both11: md5 = b9d94b8f967372c3e38b2f94052d4c5d OK 2025/02/09 04:16:55 DEBUG : only11: md5 = 89768fe41c79836363460d8f3a014d39 OK 2025/02/09 04:16:56 DEBUG : both12: md5 = c0fbb3a9d905ebc85315ee71a5566cee OK 2025/02/09 04:16:57 DEBUG : only12: md5 = b3a7aabeb7ab55b18e2b10262d98e8ad OK 2025/02/09 04:16:59 DEBUG : both13: md5 = adf832ab767483b0ed59bda499407f68 OK 2025/02/09 04:17:00 DEBUG : only13: md5 = 6a796b66deeeb25f3a1c936c9113e4c4 OK 2025/02/09 04:17:02 DEBUG : both14: md5 = 2f2b60954f3f21ec4ba971d4deb75384 OK 2025/02/09 04:17:03 DEBUG : only14: md5 = d314b34fcf5f2e7f408d38ab03320ae5 OK 2025/02/09 04:17:04 DEBUG : both15: md5 = 76e04f11db5bfb7fb2d16046744bdf7c OK 2025/02/09 04:17:06 DEBUG : only15: md5 = 283cc572c870c4b1a1e1c3c4de165f2a OK 2025/02/09 04:17:07 DEBUG : both16: md5 = 86f7a0f8684e5ba5d9bd3cfcd57c9d6a OK 2025/02/09 04:17:08 DEBUG : only16: md5 = 955f167c5376c96eaa51f648e3175f17 OK 2025/02/09 04:17:10 DEBUG : both17: md5 = c7495cf4e139497ea5157a4cffafb65c OK 2025/02/09 04:17:11 DEBUG : only17: md5 = 72f4da61b2a16185619a93cb6c144441 OK 2025/02/09 04:17:12 DEBUG : both18: md5 = 76749773e952975284e489432263c1c2 OK 2025/02/09 04:17:14 DEBUG : only18: md5 = f6b0223296d24b1f8c31416522c59e8f OK 2025/02/09 04:17:15 DEBUG : both19: md5 = d026b67a7789455e765df8765227b07b OK 2025/02/09 04:17:17 DEBUG : only19: md5 = a5f57954ce520f89b37cf4252df96cb0 OK 2025/02/09 04:17:17 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for checks to finish 2025/02/09 04:17:17 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both0: Unchanged skipping 2025/02/09 04:17:17 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both12: Unchanged skipping 2025/02/09 04:17:17 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both13: Unchanged skipping 2025/02/09 04:17:17 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both1: Unchanged skipping 2025/02/09 04:17:17 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both15: Unchanged skipping 2025/02/09 04:17:17 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both16: Unchanged skipping 2025/02/09 04:17:17 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both17: Unchanged skipping 2025/02/09 04:17:17 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both18: Unchanged skipping 2025/02/09 04:17:17 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both11: Unchanged skipping 2025/02/09 04:17:17 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both10: Unchanged skipping 2025/02/09 04:17:17 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both3: Unchanged skipping 2025/02/09 04:17:17 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both14: Unchanged skipping 2025/02/09 04:17:17 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both5: Unchanged skipping 2025/02/09 04:17:17 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both6: Unchanged skipping 2025/02/09 04:17:17 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both7: Unchanged skipping 2025/02/09 04:17:17 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both8: Unchanged skipping 2025/02/09 04:17:17 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/09 04:17:17 DEBUG : both9: Unchanged skipping 2025/02/09 04:17:17 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : both4: Unchanged skipping 2025/02/09 04:17:17 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/02/09 04:17:17 DEBUG : both19: Unchanged skipping 2025/02/09 04:17:17 DEBUG : both2: Unchanged skipping 2025/02/09 04:17:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Waiting for transfers to finish 2025/02/09 04:17:18 DEBUG : only10: md5 = f765623fc349472541332e00323d4152 OK 2025/02/09 04:17:18 INFO : only10: Copied (replaced existing) 2025/02/09 04:17:18 DEBUG : only1: md5 = b1fae7fcd7e6ad5fdd52e7f8060c39bd OK 2025/02/09 04:17:18 INFO : only1: Copied (replaced existing) 2025/02/09 04:17:18 DEBUG : only0: md5 = ffb5133522391d8b884f2b2503a55ab6 OK 2025/02/09 04:17:18 INFO : only0: Copied (replaced existing) 2025/02/09 04:17:18 DEBUG : only11: md5 = b8bd5726230f031a71b6513f6876c8b8 OK 2025/02/09 04:17:18 INFO : only11: Copied (replaced existing) 2025/02/09 04:17:19 DEBUG : only12: md5 = dcce9829ff1fbfe39f7993128a351231 OK 2025/02/09 04:17:19 INFO : only12: Copied (replaced existing) 2025/02/09 04:17:19 DEBUG : only13: md5 = 299fe1afea6a1f7eaa4d4a910ab7d313 OK 2025/02/09 04:17:19 INFO : only13: Copied (replaced existing) 2025/02/09 04:17:20 DEBUG : only14: md5 = c01f80c5160d421e90173b36900a7a73 OK 2025/02/09 04:17:20 INFO : only14: Copied (replaced existing) 2025/02/09 04:17:20 DEBUG : only15: md5 = 7838d8be95ac1a5316bc0c326fd53097 OK 2025/02/09 04:17:20 INFO : only15: Copied (replaced existing) 2025/02/09 04:17:20 DEBUG : only16: md5 = 0621490f0f49a8ea7d46ea5f29d62003 OK 2025/02/09 04:17:20 INFO : only16: Copied (replaced existing) 2025/02/09 04:17:21 DEBUG : only17: md5 = e649ef9c10e4877a6a34649e9535ea55 OK 2025/02/09 04:17:21 INFO : only17: Copied (replaced existing) 2025/02/09 04:17:21 DEBUG : only18: md5 = b845025bd1da973e9518816c37ab48d7 OK 2025/02/09 04:17:21 INFO : only18: Copied (replaced existing) 2025/02/09 04:17:21 DEBUG : only2: md5 = 947436e5b6874e53de5647d11835d5eb OK 2025/02/09 04:17:21 INFO : only2: Copied (replaced existing) 2025/02/09 04:17:22 DEBUG : only3: md5 = bcf4548df34c0848fd56b15714980fb4 OK 2025/02/09 04:17:22 INFO : only3: Copied (replaced existing) 2025/02/09 04:17:22 DEBUG : only4: md5 = 9c80538fb9ac5b5260520b713d7e563a OK 2025/02/09 04:17:22 INFO : only4: Copied (replaced existing) 2025/02/09 04:17:22 DEBUG : only5: md5 = 285aadbde7cb07c0bcd4a5dea920c077 OK 2025/02/09 04:17:22 INFO : only5: Copied (replaced existing) 2025/02/09 04:17:22 DEBUG : only6: md5 = 696c9099c37f681f05f7642f892cfe2d OK 2025/02/09 04:17:22 INFO : only6: Copied (replaced existing) 2025/02/09 04:17:23 DEBUG : only7: md5 = 2c76ab737a489593700fffd980b6033b OK 2025/02/09 04:17:23 INFO : only7: Copied (replaced existing) 2025/02/09 04:17:23 DEBUG : only19: md5 = 971a9de16c6b0bce276c8d2ebba18b03 OK 2025/02/09 04:17:23 INFO : only19: Copied (replaced existing) 2025/02/09 04:17:23 DEBUG : only8: md5 = 1e7e1318f04dba8e48342cda0ad97c41 OK 2025/02/09 04:17:23 INFO : only8: Copied (replaced existing) 2025/02/09 04:17:23 DEBUG : only9: md5 = 5536ab262afef4a8c8ad4598d7c4168f OK 2025/02/09 04:17:23 INFO : only9: Copied (replaced existing) 2025/02/09 04:17:23 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (79.20s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:17:41 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/09 04:17:41 DEBUG : sub dir: Making directory with metadata 2025/02/09 04:17:42 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:17:59 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/02/09 04:17:59 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/02/09 04:17:59 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/09 04:17:59 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:18:13 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/02/09 04:18:13 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/02/09 04:18:14 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/02/09 04:18:15 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/02/09 04:18:15 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/09 04:18:16 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/09 04:18:17 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/09 04:18:17 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/09 04:18:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/02/09 04:18:19 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/02/09 04:18:19 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/09 04:18:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (40.22s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:18:22 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/09 04:18:22 DEBUG : sub dir: Making directory with metadata 2025/02/09 04:18:22 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:18:42 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/02/09 04:18:43 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/02/09 04:18:43 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/09 04:18:43 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca'", Local "Local file system at /tmp/rclone2478755479", Modify Window "1ms" 2025/02/09 04:18:55 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/02/09 04:18:56 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/02/09 04:18:56 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/02/09 04:18:57 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/09 04:18:57 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/09 04:18:58 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/09 04:18:59 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/09 04:18:59 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/02/09 04:19:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/02/09 04:19:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/09 04:19:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (41.08s) PASS 2025/02/09 04:19:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gumibab5roca': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 14m52.034871133s (try 1/5)