"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5) 2024/04/13 03:41:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8" 2024/04/13 03:41:00 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2024/04/13 03:41:00 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im" 2024/04/13 03:41:02 DEBUG : Creating backend with remote "/tmp/rclone2952895842" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.03s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:41:03 NOTICE: sub dir: Skipped make directory as --dry-run is set 2024/04/13 03:41:03 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:41:03 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2024/04/13 03:41:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:41:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.98s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:41:05 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/04/13 03:41:05 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:41:06 INFO : sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/04/13 03:41:06 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:41:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:41:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:41:08 DEBUG : sub dir/hello world: md5 = 3369d4abd8d7404e5ce9096bb2ac6dbe OK 2024/04/13 03:41:08 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:41:10 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (7.64s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:41:12 DEBUG : metadata sub dir: Making directory with metadata 2024/04/13 03:41:12 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/04/13 03:41:12 DEBUG : Local file system at /tmp/rclone2952895842: File to upload is small (21 bytes), uploading instead of streaming 2024/04/13 03:41:12 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2024/04/13 03:41:12 DEBUG : metadata sub dir/hello metadata world.jejofok5.partial: renamed to: metadata sub dir/hello metadata world 2024/04/13 03:41:12 INFO : metadata sub dir/hello metadata world: Copied (new) 2024/04/13 03:41:12 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2024/04/13 03:41:13 DEBUG : Google drive root 'crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im': Skipping btime metadata as can't update it on an existing file: 2024-04-13T03:41:12.755252098Z 2024/04/13 03:41:14 INFO : metadata sub dir: Updated directory metadata 2024/04/13 03:41:14 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2024/04/13 03:41:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:41:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:41:16 DEBUG : metadata sub dir/hello metadata world: md5 = 791ffb55c6e3cdf4d50a242894e80748 OK 2024/04/13 03:41:16 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:41:19 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (8.34s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:41:21 DEBUG : Creating backend with remote "/non-existing" 2024/04/13 03:41:21 DEBUG : Config file has changed externally - reloading 2024/04/13 03:41:21 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2024/04/13 03:41:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:41:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.32s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:41:22 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:41:23 INFO : sub dir: Made directory with metadata (mtime=2024-04-13T03:41:22.419254181Z) 2024/04/13 03:41:23 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:41:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:41:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:41:25 DEBUG : sub dir/hello world: md5 = ad2080cf132ac752dfdd66f8785bdd76 OK 2024/04/13 03:41:25 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:41:27 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (7.11s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:41:29 INFO : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Running all checks before starting transfers 2024/04/13 03:41:29 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:41:31 INFO : sub dir: Made directory with metadata (mtime=2024-04-13T03:41:29.535255708Z) 2024/04/13 03:41:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:41:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:41:31 INFO : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Checks finished, now starting transfers 2024/04/13 03:41:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:41:33 DEBUG : sub dir/hello world: md5 = 24386dd843316ddb043f35a3203a2253 OK 2024/04/13 03:41:33 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:41:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (7.78s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:41:37 ERROR : Ignoring --no-traverse with sync 2024/04/13 03:41:37 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:41:38 INFO : sub dir: Made directory with metadata (mtime=2024-04-13T03:41:37.311257376Z) 2024/04/13 03:41:38 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:41:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:41:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:41:40 DEBUG : sub dir/hello world: md5 = 5f6956236a40d010e896a11f3b7bc3c8 OK 2024/04/13 03:41:40 INFO : sub dir/hello world: Copied (new) 2024/04/13 03:41:40 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:41:42 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (7.09s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:41:44 DEBUG : hello world2: Need to transfer - File not found at Destination 2024/04/13 03:41:44 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:41:45 INFO : sub dir: Made directory with metadata (mtime=2024-04-13T03:41:44.399258891Z) 2024/04/13 03:41:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:41:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:41:46 DEBUG : hello world2: md5 = 616ccdf34fcc28981ff75a26e7a99dbd OK 2024/04/13 03:41:46 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestCopyWithDepth (6.11s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:41:50 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:41:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:41:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:41:52 DEBUG : potato2: md5 = 292a0225ab6ce134ad1a53dda4fb487f OK 2024/04/13 03:41:52 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (4.33s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:41:55 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:41:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:41:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:41:56 DEBUG : potato2: md5 = 04481de6538dfa843a0bd7d69e069176 OK 2024/04/13 03:41:56 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (4.40s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:41:59 DEBUG : sub dir2: Making directory with metadata 2024/04/13 03:41:59 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/04/13 03:41:59 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/04/13 03:41:59 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:42:00 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2024/04/13 03:42:00 DEBUG : sub dir2: Making directory with metadata 2024/04/13 03:42:02 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/04/13 03:42:02 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:42:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:42:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:42:04 DEBUG : sub dir/hello world: md5 = 4847fcfce8cc47ed598b5568fc85045e OK 2024/04/13 03:42:04 INFO : sub dir/hello world: Copied (new) 2024/04/13 03:42:04 DEBUG : sub dir2: Making directory 2024/04/13 03:42:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': copied 1 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:42:08 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (11.04s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:42:10 DEBUG : sub dir2: Making directory with metadata 2024/04/13 03:42:10 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/04/13 03:42:10 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:42:12 INFO : sub dir: Made directory with metadata (mtime=2024-04-13T03:42:10.279264402Z) 2024/04/13 03:42:12 DEBUG : sub dir2: Making directory with metadata 2024/04/13 03:42:13 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/04/13 03:42:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:42:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:42:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:42:15 DEBUG : sub dir/hello world: md5 = 4ece856154728080684f70bcadfe9a32 OK 2024/04/13 03:42:15 INFO : sub dir/hello world: Copied (new) 2024/04/13 03:42:15 INFO : sub dir/hello world: Deleted 2024/04/13 03:42:15 DEBUG : sub dir2: Making directory 2024/04/13 03:42:15 DEBUG : sub dir: Making directory 2024/04/13 03:42:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': copied 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:42:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (10.87s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:42:21 DEBUG : sub dir no update dir modtime: Making directory with metadata 2024/04/13 03:42:21 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2024/04/13 03:42:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:42:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:42:23 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (5.57s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:42:26 DEBUG : sub dir2: Making directory with metadata 2024/04/13 03:42:26 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/04/13 03:42:26 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/04/13 03:42:27 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:42:28 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2024/04/13 03:42:28 DEBUG : sub dir2: Making directory with metadata 2024/04/13 03:42:29 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/04/13 03:42:29 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:42:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:42:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:42:31 DEBUG : sub dir/hello world: md5 = e04b8f09b5d7c12b569261b2b070d98d OK 2024/04/13 03:42:31 INFO : sub dir/hello world: Copied (new) 2024/04/13 03:42:31 DEBUG : sub dir2: Making directory 2024/04/13 03:42:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': copied 1 directories 2024/04/13 03:42:31 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:42:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (10.26s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" sync_test.go:427: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.52s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:42:40 DEBUG : sub dir/hello world: md5 = 2b695327409bb008e5b165af92680a17 OK 2024/04/13 03:42:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-guvixej1pofuhed7zofujip0" 2024/04/13 03:42:41 DEBUG : Creating backend with remote "TestDrive:crypt/q3auulhdlela06seh91enoasumck5saf256v40da701cgdraidea92raa2sb355hk1lvr4dfbd2ke" sync_test.go:487: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8' -> Encrypted drive 'TestCryptDrive:rclone-test-guvixej1pofuhed7zofujip0' 2024/04/13 03:42:42 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:42:45 INFO : sub dir: Made directory with metadata (mtime=2024-04-13T03:42:38.112Z) 2024/04/13 03:42:45 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:42:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-guvixej1pofuhed7zofujip0': Waiting for checks to finish 2024/04/13 03:42:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-guvixej1pofuhed7zofujip0': Waiting for transfers to finish 2024/04/13 03:42:47 INFO : sub dir/hello world: Copied (server-side copy) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:42:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-guvixej1pofuhed7zofujip0': Purge remote 2024/04/13 03:42:50 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (14.41s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:42:54 DEBUG : sub dir/hello world: md5 = 3d6c5e2c260231425a58588d0806d291 OK 2024/04/13 03:42:54 ERROR : : error listing: directory not found 2024/04/13 03:42:55 DEBUG : Local file system at /tmp/rclone2952895842: Making directory 2024/04/13 03:42:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:42:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:42:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (7.93s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:43:03 DEBUG : sub dir/hello world: md5 = 313c330428a734a29883156da9b5652b OK 2024/04/13 03:43:04 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:43:04 INFO : sub dir: Made directory with metadata (mtime=2024-04-13T03:43:00.554Z) 2024/04/13 03:43:04 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2024/04/13 03:43:04 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:43:04 DEBUG : Local file system at /tmp/rclone2952895842: Waiting for checks to finish 2024/04/13 03:43:04 DEBUG : Local file system at /tmp/rclone2952895842: Waiting for transfers to finish 2024/04/13 03:43:05 DEBUG : sub dir/hello world.gekemet3.partial: renamed to: sub dir/hello world 2024/04/13 03:43:05 INFO : sub dir/hello world: Copied (new) 2024/04/13 03:43:05 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:43:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (8.56s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:43:08 DEBUG : check sum: Need to transfer - File not found at Destination 2024/04/13 03:43:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:43:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:43:10 DEBUG : check sum: md5 = 9db6be8ea72fa30bc2783855efb08472 OK 2024/04/13 03:43:10 INFO : check sum: Copied (new) 2024/04/13 03:43:10 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:43:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:43:11 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2024/04/13 03:43:11 DEBUG : check sum: Size of src and dst objects identical 2024/04/13 03:43:11 DEBUG : check sum: Unchanged skipping 2024/04/13 03:43:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:43:11 DEBUG : Waiting for deletions to finish 2024/04/13 03:43:11 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (5.47s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:43:14 DEBUG : sizeonly: Need to transfer - File not found at Destination 2024/04/13 03:43:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:43:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:43:15 DEBUG : sizeonly: md5 = 08f1078a5b57f6b145f8b74639f99a1d OK 2024/04/13 03:43:15 INFO : sizeonly: Copied (new) 2024/04/13 03:43:15 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:43:16 DEBUG : sizeonly: Sizes identical 2024/04/13 03:43:16 DEBUG : sizeonly: Unchanged skipping 2024/04/13 03:43:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:43:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:43:16 DEBUG : Waiting for deletions to finish 2024/04/13 03:43:16 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncSizeOnly (5.31s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:43:19 DEBUG : ignore-size: Need to transfer - File not found at Destination 2024/04/13 03:43:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:43:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:43:21 DEBUG : ignore-size: md5 = 94b1d7383b038660fe04e60e42f21cf7 OK 2024/04/13 03:43:21 INFO : ignore-size: Copied (new) 2024/04/13 03:43:21 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:43:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:43:21 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:43:21 DEBUG : ignore-size: Unchanged skipping 2024/04/13 03:43:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:43:21 DEBUG : Waiting for deletions to finish 2024/04/13 03:43:21 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (5.59s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:43:26 DEBUG : existing: md5 = f205a0dec47eb82fa84d4ebe434f23cf OK 2024/04/13 03:43:27 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:43:27 DEBUG : existing: Unchanged skipping 2024/04/13 03:43:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:43:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:43:27 DEBUG : Waiting for deletions to finish 2024/04/13 03:43:27 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:43:27 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2024/04/13 03:43:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:43:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:43:29 DEBUG : existing: md5 = 9da5e611452bfc101bd13357ecca2936 OK 2024/04/13 03:43:29 INFO : existing: Copied (replaced existing) 2024/04/13 03:43:29 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (7.52s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:43:32 DEBUG : existing: Need to transfer - File not found at Destination 2024/04/13 03:43:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:43:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:43:34 DEBUG : existing: md5 = cc7c0768fcf7c3ee813575d5e4ca1801 OK 2024/04/13 03:43:34 INFO : existing: Copied (new) 2024/04/13 03:43:34 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:43:35 DEBUG : existing: Destination exists, skipping 2024/04/13 03:43:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:43:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:43:35 DEBUG : Waiting for deletions to finish 2024/04/13 03:43:35 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (5.83s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:43:41 DEBUG : b/potato: md5 = cc49ddebc2dab51f657afba151fc32a7 OK 2024/04/13 03:43:44 DEBUG : c/non empty space: md5 = 25df65d12d19181f9eae21f39107d88a OK 2024/04/13 03:43:44 DEBUG : d: Making directory 2024/04/13 03:43:46 DEBUG : a: Making directory with metadata 2024/04/13 03:43:48 INFO : a: Made directory with metadata (mtime=2024-04-13T03:43:38.135261071Z) 2024/04/13 03:43:48 INFO : c: Set directory modification time (using SetModTime) 2024/04/13 03:43:48 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:43:48 DEBUG : a/potato2: Need to transfer - File not found at Destination 2024/04/13 03:43:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:43:48 DEBUG : c/non empty space: Unchanged skipping 2024/04/13 03:43:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:43:50 DEBUG : a/potato2: md5 = 5121f6bef4b46712a11c205fc332a974 OK 2024/04/13 03:43:50 INFO : a/potato2: Copied (new) 2024/04/13 03:43:50 DEBUG : Waiting for deletions to finish 2024/04/13 03:43:51 INFO : b/potato: Deleted 2024/04/13 03:43:51 INFO : d: Removing directory 2024/04/13 03:43:52 INFO : b: Removing directory 2024/04/13 03:43:52 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2024/04/13 03:43:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:43:56 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2024/04/13 03:43:58 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (21.48s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:44:01 DEBUG : empty space: md5 = eeea144ebb8430c430b9f14339dd839f OK 2024/04/13 03:44:02 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2024/04/13 03:44:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:44:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:44:02 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2024/04/13 03:44:02 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:44:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:44:02 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2024/04/13 03:44:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:44:04 DEBUG : empty space: md5 = ab265c1e5fbf2b22afe471993f955118 OK 2024/04/13 03:44:04 INFO : empty space: Copied (replaced existing) 2024/04/13 03:44:04 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (7.45s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" sync_test.go:811: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.53s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:44:09 DEBUG : foo: md5 = 83bff01146b651fbdc01fe6821818067 OK 2024/04/13 03:44:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:44:10 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2024/04/13 03:44:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:44:11 DEBUG : foo: md5 = 9159889dff9e87423fe6c2dc63b29d05 OK 2024/04/13 03:44:11 INFO : foo: Copied (replaced existing) 2024/04/13 03:44:11 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (6.34s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:44:15 DEBUG : empty space: md5 = 3b5f1bb57c39fc224afc8a27dd729cc7 OK 2024/04/13 03:44:16 DEBUG : potato: Need to transfer - File not found at Destination 2024/04/13 03:44:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:44:16 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:44:16 DEBUG : empty space: Unchanged skipping 2024/04/13 03:44:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:44:18 DEBUG : potato: md5 = a0ef96af10b02e9a78d66bdae83254d1 OK 2024/04/13 03:44:18 INFO : potato: Copied (new) 2024/04/13 03:44:18 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (7.37s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:44:23 DEBUG : potato: md5 = ecc4b9b3489d91d511e1d4680f1cd719 OK 2024/04/13 03:44:23 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2024/04/13 03:44:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:44:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:44:25 DEBUG : potato: md5 = d08a40f656f0e5167035c2d84e643d51 OK 2024/04/13 03:44:25 INFO : potato: Copied (replaced existing) 2024/04/13 03:44:25 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (6.27s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:44:29 DEBUG : potato: md5 = 1eaccdfb25f01c163c5f9070f23ed343 OK 2024/04/13 03:44:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:44:30 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC 2024/04/13 03:44:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:44:31 DEBUG : potato: md5 = b0a1ed17918a2b1f6fb78abffbbe0643 OK 2024/04/13 03:44:31 INFO : potato: Copied (replaced existing) 2024/04/13 03:44:31 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (6.39s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:44:35 DEBUG : potato: md5 = d44ab4964e5a6055b2c0da8b58f7211d OK 2024/04/13 03:44:37 DEBUG : empty space: md5 = 748529a0cb95db1f1ed2cfab75b9492a OK 2024/04/13 03:44:38 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:44:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:44:38 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:44:38 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2024/04/13 03:44:38 DEBUG : empty space: Unchanged skipping 2024/04/13 03:44:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:44:38 DEBUG : Waiting for deletions to finish 2024/04/13 03:44:38 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (7.20s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:44:42 DEBUG : potato: md5 = e876e628d25cf24489eb65fbaf6c6a7b OK 2024/04/13 03:44:44 DEBUG : empty space: md5 = 94c4af265eb945bef4f163081e3034a8 OK 2024/04/13 03:44:45 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:44:45 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:44:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:44:45 DEBUG : empty space: Unchanged skipping 2024/04/13 03:44:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:44:47 DEBUG : potato2: md5 = 1b4e074fa98867e0a1415ba613bbb56c OK 2024/04/13 03:44:47 INFO : potato2: Copied (new) 2024/04/13 03:44:47 DEBUG : Waiting for deletions to finish 2024/04/13 03:44:48 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (10.03s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:44:54 DEBUG : b/potato: md5 = 0efca6aed038aa56912121c0e953f8ed OK 2024/04/13 03:44:57 DEBUG : c/non empty space: md5 = b5f106bbeaded12a5b5868de3c34bd0b OK 2024/04/13 03:44:57 DEBUG : d: Making directory 2024/04/13 03:44:58 DEBUG : d/e: Making directory 2024/04/13 03:45:01 DEBUG : a: Making directory with metadata 2024/04/13 03:45:03 INFO : a: Made directory with metadata (mtime=2024-04-13T03:44:51.191179111Z) 2024/04/13 03:45:04 INFO : c: Set directory modification time (using SetModTime) 2024/04/13 03:45:04 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:45:04 DEBUG : a/potato2: Need to transfer - File not found at Destination 2024/04/13 03:45:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:45:04 DEBUG : c/non empty space: Unchanged skipping 2024/04/13 03:45:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:45:06 DEBUG : a/potato2: md5 = 15b5742108404b3298b57ce536112b5f OK 2024/04/13 03:45:06 INFO : a/potato2: Copied (new) 2024/04/13 03:45:06 DEBUG : Waiting for deletions to finish 2024/04/13 03:45:06 INFO : b/potato: Deleted 2024/04/13 03:45:06 INFO : d/e: Removing directory 2024/04/13 03:45:08 INFO : d: Removing directory 2024/04/13 03:45:08 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2024/04/13 03:45:09 INFO : b: Removing directory 2024/04/13 03:45:09 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2024/04/13 03:45:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:45:13 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2024/04/13 03:45:14 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (25.28s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:45:19 DEBUG : b/potato: md5 = 85398b612e22a86a6e881114a9921e70 OK 2024/04/13 03:45:22 DEBUG : c/non empty space: md5 = 1bd1e30bcfb9f4afaa342f1e1faeca35 OK 2024/04/13 03:45:22 DEBUG : d: Making directory 2024/04/13 03:45:25 DEBUG : a: Making directory with metadata 2024/04/13 03:45:26 INFO : a: Made directory with metadata (mtime=2024-04-13T03:45:16.471153278Z) 2024/04/13 03:45:27 INFO : c: Set directory modification time (using SetModTime) 2024/04/13 03:45:27 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:45:27 DEBUG : a/potato2: Need to transfer - File not found at Destination 2024/04/13 03:45:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:45:27 DEBUG : c/non empty space: Unchanged skipping 2024/04/13 03:45:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:45:29 DEBUG : a/potato2: md5 = 58d5ff472716f10ac379d08dfcee7206 OK 2024/04/13 03:45:29 INFO : a/potato2: Copied (new) 2024/04/13 03:45:29 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': not deleting files as there were IO errors 2024/04/13 03:45:29 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:45:34 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2024/04/13 03:45:35 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2024/04/13 03:45:36 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (21.78s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:45:40 DEBUG : potato: md5 = 44742313c923e07582640e88858a67cc OK 2024/04/13 03:45:42 DEBUG : empty space: md5 = 56dbe6e652bdd66277fdf139f16b1d29 OK 2024/04/13 03:45:42 DEBUG : Waiting for deletions to finish 2024/04/13 03:45:42 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:45:42 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:45:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:45:42 DEBUG : empty space: Unchanged skipping 2024/04/13 03:45:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:45:43 INFO : potato: Deleted 2024/04/13 03:45:44 DEBUG : potato2: md5 = cc2af2588ef13e2d24bf8c690b6930f0 OK 2024/04/13 03:45:44 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (9.67s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:45:49 DEBUG : potato: md5 = 1667647b9a9e63cdb66e43f036859055 OK 2024/04/13 03:45:51 DEBUG : empty space: md5 = 00d46de9d05dba3cce8489433d93214e OK 2024/04/13 03:45:52 DEBUG : Waiting for deletions to finish 2024/04/13 03:45:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:45:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:45:53 INFO : potato: Deleted 2024/04/13 03:45:53 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:45:53 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:45:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:45:53 DEBUG : empty space: Unchanged skipping 2024/04/13 03:45:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:45:55 DEBUG : potato2: md5 = 1696c2e8a5aa1c335eed0b6a0c880d52 OK 2024/04/13 03:45:55 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (10.47s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:46:00 DEBUG : potato: md5 = 547c0481e1781ac40369de0e49626b57 OK 2024/04/13 03:46:00 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:46:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:46:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:46:02 DEBUG : potato2: md5 = 01ba886099e9116fb8b59b0462f769f5 OK 2024/04/13 03:46:02 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (6.98s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:46:07 DEBUG : potato2: md5 = becd0862a3e3face513ee94aa88bb411 OK 2024/04/13 03:46:09 DEBUG : empty space: md5 = 8cbfcec069e3c383981ee208470c8856 OK 2024/04/13 03:46:09 DEBUG : enormous: Excluded (Size Filter) 2024/04/13 03:46:09 DEBUG : enormous: Excluded 2024/04/13 03:46:09 DEBUG : potato2: Excluded (Size Filter) 2024/04/13 03:46:09 DEBUG : potato2: Excluded 2024/04/13 03:46:10 DEBUG : potato2: Excluded (Size Filter) 2024/04/13 03:46:10 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:46:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:46:10 DEBUG : empty space: Unchanged skipping 2024/04/13 03:46:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:46:10 DEBUG : Waiting for deletions to finish 2024/04/13 03:46:10 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:46:10 DEBUG : enormous: Excluded (Size Filter) 2024/04/13 03:46:10 DEBUG : enormous: Excluded 2024/04/13 03:46:10 DEBUG : potato2: Excluded (Size Filter) 2024/04/13 03:46:10 DEBUG : potato2: Excluded 2024/04/13 03:46:10 DEBUG : potato2: Excluded (Size Filter) 2024/04/13 03:46:10 DEBUG : Local file system at /tmp/rclone2952895842: Waiting for checks to finish 2024/04/13 03:46:10 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2024/04/13 03:46:10 DEBUG : empty space: Unchanged skipping 2024/04/13 03:46:10 DEBUG : Local file system at /tmp/rclone2952895842: Waiting for transfers to finish 2024/04/13 03:46:10 DEBUG : Waiting for deletions to finish 2024/04/13 03:46:10 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncWithExclude (8.38s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:46:16 DEBUG : potato2: md5 = a0ea913f93d65a496cd761f4f1583f6d OK 2024/04/13 03:46:17 DEBUG : empty space: md5 = 4217b0d3734f2677bf11d82a2197a07e OK 2024/04/13 03:46:19 DEBUG : enormous: md5 = 398c98d294b085b4f6c07ce2b150792c OK 2024/04/13 03:46:19 DEBUG : enormous: Excluded (Size Filter) 2024/04/13 03:46:19 DEBUG : enormous: Excluded 2024/04/13 03:46:19 DEBUG : potato2: Excluded (Size Filter) 2024/04/13 03:46:19 DEBUG : potato2: Excluded 2024/04/13 03:46:20 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:46:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:46:20 DEBUG : empty space: Unchanged skipping 2024/04/13 03:46:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:46:20 DEBUG : Waiting for deletions to finish 2024/04/13 03:46:21 INFO : enormous: Deleted 2024/04/13 03:46:21 INFO : potato2: Deleted 2024/04/13 03:46:21 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:46:21 DEBUG : Local file system at /tmp/rclone2952895842: Waiting for checks to finish 2024/04/13 03:46:21 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2024/04/13 03:46:21 DEBUG : empty space: Unchanged skipping 2024/04/13 03:46:21 DEBUG : Local file system at /tmp/rclone2952895842: Waiting for transfers to finish 2024/04/13 03:46:21 DEBUG : Waiting for deletions to finish 2024/04/13 03:46:21 INFO : enormous: Deleted 2024/04/13 03:46:21 INFO : potato2: Deleted 2024/04/13 03:46:21 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (10.55s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:46:26 DEBUG : one: md5 = bd5b81524becd56bb12e86af54d3d15d OK 2024/04/13 03:46:28 DEBUG : two: md5 = 3c278ca312e131cacb60d3e4bc0bf221 OK 2024/04/13 03:46:29 DEBUG : three: md5 = 97c7fd01e40c3735c288330552679a4e OK 2024/04/13 03:46:31 DEBUG : four: md5 = 084bfd88a0fcd389ba325860383c078e OK 2024/04/13 03:46:32 DEBUG : five: Need to transfer - File not found at Destination 2024/04/13 03:46:32 DEBUG : four: Sizes differ (src 4 vs dst 8) 2024/04/13 03:46:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:46:32 DEBUG : one: Destination is newer than source, skipping 2024/04/13 03:46:32 DEBUG : three: Sizes identical 2024/04/13 03:46:32 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2024/04/13 03:46:32 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2024/04/13 03:46:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:46:34 DEBUG : two: md5 = 7e8092571dcde9e580071d0bc0f27e28 OK 2024/04/13 03:46:34 INFO : two: Copied (replaced existing) 2024/04/13 03:46:34 DEBUG : five: md5 = 8cb0b10001b99479ce7d16a254f187af OK 2024/04/13 03:46:34 INFO : five: Copied (new) 2024/04/13 03:46:34 DEBUG : four: md5 = f5c82242db4cd9e5809af36fe1bdb2fe OK 2024/04/13 03:46:34 INFO : four: Copied (replaced existing) 2024/04/13 03:46:34 DEBUG : Waiting for deletions to finish sync_test.go:1244: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (15.08s) === RUN TestSyncWithMaxDuration === RUN TestSyncWithMaxDuration/Hard sync_test.go:1261: Skipping test on non local remote === RUN TestSyncWithMaxDuration/Soft sync_test.go:1261: 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-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" sync_test.go:1327: Can track renames: false 2024/04/13 03:46:39 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Ignoring --track-renames as the source and destination do not have a common hash 2024/04/13 03:46:39 DEBUG : potato: Need to transfer - File not found at Destination 2024/04/13 03:46:39 DEBUG : yam: Need to transfer - File not found at Destination 2024/04/13 03:46:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:46:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:46:41 DEBUG : potato: md5 = 123ae1980d9ef783473297f376a51f3b OK 2024/04/13 03:46:41 INFO : potato: Copied (new) 2024/04/13 03:46:42 DEBUG : yam: md5 = 5324579681f1b89a1f56c92401d72ca3 OK 2024/04/13 03:46:42 INFO : yam: Copied (new) 2024/04/13 03:46:42 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:46:42 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Ignoring --track-renames as the source and destination do not have a common hash 2024/04/13 03:46:42 DEBUG : yaml: Need to transfer - File not found at Destination 2024/04/13 03:46:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:46:42 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:46:42 DEBUG : potato: Unchanged skipping 2024/04/13 03:46:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:46:44 DEBUG : yaml: md5 = eccf29fa5ea4bf0bf9f79a885c6d4410 OK 2024/04/13 03:46:44 INFO : yaml: Copied (new) 2024/04/13 03:46:44 DEBUG : Waiting for deletions to finish 2024/04/13 03:46:45 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (10.75s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" sync_test.go:1399: Can track renames: true 2024/04/13 03:46:50 INFO : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Making map for --track-renames 2024/04/13 03:46:50 INFO : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Finished making map for --track-renames 2024/04/13 03:46:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:46:50 DEBUG : potato: Need to transfer - No matching file found at Destination 2024/04/13 03:46:50 DEBUG : yam: Need to transfer - No matching file found at Destination 2024/04/13 03:46:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for renames to finish 2024/04/13 03:46:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:46:52 DEBUG : potato: md5 = feb40951717da51e3f6353d1002b79c8 OK 2024/04/13 03:46:52 INFO : potato: Copied (new) 2024/04/13 03:46:52 DEBUG : yam: md5 = 6c94ddbae13bcbbff702db069560ce01 OK 2024/04/13 03:46:52 INFO : yam: Copied (new) 2024/04/13 03:46:52 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:46:53 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:46:53 INFO : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Making map for --track-renames 2024/04/13 03:46:53 INFO : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Finished making map for --track-renames 2024/04/13 03:46:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:46:53 DEBUG : potato: Unchanged skipping 2024/04/13 03:46:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for renames to finish 2024/04/13 03:46:54 INFO : yam: Moved (server-side) to: yaml 2024/04/13 03:46:54 INFO : yaml: Renamed from "yam" 2024/04/13 03:46:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:46:54 DEBUG : Waiting for deletions to finish 2024/04/13 03:46:54 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (8.11s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" sync_test.go:1438: Can track renames: true 2024/04/13 03:46:58 DEBUG : sub: Making directory with metadata 2024/04/13 03:46:59 INFO : sub: Made directory with metadata (mtime=2024-04-13T03:46:58.23906083Z) 2024/04/13 03:46:59 INFO : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Making map for --track-renames 2024/04/13 03:46:59 INFO : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Finished making map for --track-renames 2024/04/13 03:46:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:46:59 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2024/04/13 03:46:59 DEBUG : potato: Need to transfer - No matching file found at Destination 2024/04/13 03:46:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for renames to finish 2024/04/13 03:46:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:47:01 DEBUG : potato: md5 = c1f6ab30124d23b45ffa2b4241183448 OK 2024/04/13 03:47:01 INFO : potato: Copied (new) 2024/04/13 03:47:01 DEBUG : sub/yam: md5 = cc6a5fbc65fb93de044f08581c96e23d OK 2024/04/13 03:47:01 INFO : sub/yam: Copied (new) 2024/04/13 03:47:01 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:47:02 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:47:02 DEBUG : potato: Unchanged skipping 2024/04/13 03:47:03 INFO : sub: Set directory modification time (using SetModTime) 2024/04/13 03:47:03 INFO : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Making map for --track-renames 2024/04/13 03:47:03 INFO : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Finished making map for --track-renames 2024/04/13 03:47:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:47:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for renames to finish 2024/04/13 03:47:05 INFO : sub/yam: Moved (server-side) to: yam 2024/04/13 03:47:05 INFO : yam: Renamed from "sub/yam" 2024/04/13 03:47:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:47:05 DEBUG : Waiting for deletions to finish 2024/04/13 03:47:05 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (12.40s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:47:10 DEBUG : Creating backend with remote "/tmp/rclone2952895842/dir1" 2024/04/13 03:47:10 DEBUG : Config file has changed externally - reloading 2024/04/13 03:47:10 DEBUG : Creating backend with remote "/tmp/rclone2952895842/dir2" 2024/04/13 03:47:10 DEBUG : Local file system at /tmp/rclone2952895842/dir2: Using server-side directory move 2024/04/13 03:47:10 INFO : Local file system at /tmp/rclone2952895842/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2024/04/13 03:47:10 DEBUG : file1.txt: Need to transfer - File not found at Destination 2024/04/13 03:47:10 DEBUG : Local file system at /tmp/rclone2952895842/dir2: Waiting for checks to finish 2024/04/13 03:47:10 DEBUG : Local file system at /tmp/rclone2952895842/dir2: Waiting for transfers to finish 2024/04/13 03:47:10 INFO : file1.txt: Moved (server-side) --- PASS: TestServerSideMoveLocal (0.59s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:47:11 DEBUG : nested: Making directory with metadata 2024/04/13 03:47:12 INFO : nested: Made directory with metadata (mtime=2024-04-13T03:47:11.227050249Z) 2024/04/13 03:47:12 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:47:14 INFO : sub dir: Made directory with metadata (mtime=2024-04-13T03:47:11.227050249Z) 2024/04/13 03:47:14 DEBUG : nested/sub dir: Making directory with metadata 2024/04/13 03:47:14 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:47:15 INFO : nested/sub dir: Made directory with metadata (mtime=2024-04-13T03:47:11.227050249Z) 2024/04/13 03:47:15 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2024/04/13 03:47:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:47:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:47:16 DEBUG : sub dir/hello world: md5 = df6494cd02ca67a06b7605e67e796a34 OK 2024/04/13 03:47:16 INFO : sub dir/hello world: Copied (new) 2024/04/13 03:47:16 INFO : sub dir/hello world: Deleted 2024/04/13 03:47:17 DEBUG : nested/sub dir/file: md5 = c4c9f1a4d0208eb62a5237c0cb872596 OK 2024/04/13 03:47:17 INFO : nested/sub dir/file: Copied (new) 2024/04/13 03:47:17 INFO : nested/sub dir/file: Deleted 2024/04/13 03:47:17 INFO : sub dir: Removing directory 2024/04/13 03:47:17 INFO : nested/sub dir: Removing directory 2024/04/13 03:47:17 INFO : nested: Removing directory 2024/04/13 03:47:17 DEBUG : Local file system at /tmp/rclone2952895842: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:47:21 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/04/13 03:47:22 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2024/04/13 03:47:23 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (14.12s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:47:25 DEBUG : nested: Making directory with metadata 2024/04/13 03:47:26 INFO : nested: Made directory with metadata (mtime=2024-04-13T03:47:25.347039029Z) 2024/04/13 03:47:26 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:47:27 INFO : sub dir: Made directory with metadata (mtime=2024-04-13T03:47:25.347039029Z) 2024/04/13 03:47:27 DEBUG : nested/sub dir: Making directory with metadata 2024/04/13 03:47:27 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:47:29 INFO : nested/sub dir: Made directory with metadata (mtime=2024-04-13T03:47:25.347039029Z) 2024/04/13 03:47:29 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2024/04/13 03:47:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:47:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:47:30 DEBUG : sub dir/hello world: md5 = f3b95d3af1abab1b17ab53e665d1b065 OK 2024/04/13 03:47:30 INFO : sub dir/hello world: Copied (new) 2024/04/13 03:47:30 INFO : sub dir/hello world: Deleted 2024/04/13 03:47:30 DEBUG : nested/sub dir/file: md5 = 68966c2c4deb42c081cd3db1c96ef698 OK 2024/04/13 03:47:30 INFO : nested/sub dir/file: Copied (new) 2024/04/13 03:47:30 INFO : nested/sub dir/file: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:47:34 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/04/13 03:47:35 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2024/04/13 03:47:36 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (13.26s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:47:38 DEBUG : existing: Need to transfer - File not found at Destination 2024/04/13 03:47:38 DEBUG : existing-b: Need to transfer - File not found at Destination 2024/04/13 03:47:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:47:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:47:40 DEBUG : existing-b: md5 = d5f6c83ecc89cdd46f916c6d9b9ce748 OK 2024/04/13 03:47:40 INFO : existing-b: Copied (new) 2024/04/13 03:47:40 INFO : existing-b: Deleted 2024/04/13 03:47:41 DEBUG : existing: md5 = 0d7698434191dce1e38b0a56250e72ed OK 2024/04/13 03:47:41 INFO : existing: Copied (new) 2024/04/13 03:47:41 INFO : existing: Deleted 2024/04/13 03:47:41 DEBUG : existing: Destination exists, skipping 2024/04/13 03:47:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:47:41 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2024/04/13 03:47:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:47:41 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (6.21s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:47:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jeyafor5kafotet7ciwucib5" 2024/04/13 03:47:44 DEBUG : Creating backend with remote "TestDrive:crypt/pdbuvs31gcumrhnbdlcdlbvf5qcfhvs1mb6dqu3objqcs1ciflts1tch5j7tdakd5oas6qpeohirk" 2024/04/13 03:47:47 DEBUG : potato2: md5 = 26f4a10dabd8178865467a93cf25bd15 OK 2024/04/13 03:47:49 DEBUG : empty space: md5 = dcc3c1ef63f672a1f9e731ec0557d8c5 OK 2024/04/13 03:47:51 DEBUG : potato3: md5 = aaf80c6273f3981d2cd80cf95cec6713 OK sync_test.go:1494: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8' -> Encrypted drive 'TestCryptDrive:rclone-test-jeyafor5kafotet7ciwucib5' 2024/04/13 03:47:55 DEBUG : empty space: md5 = 676ab30161cf32b3267df01f2b1fe2e8 OK 2024/04/13 03:47:57 DEBUG : potato3: md5 = 184cb777f659448dd96bcf6a2bc2543c OK 2024/04/13 03:47:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jeyafor5kafotet7ciwucib5': Using server-side directory move 2024/04/13 03:47:57 INFO : Encrypted drive 'TestCryptDrive:rclone-test-jeyafor5kafotet7ciwucib5': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2024/04/13 03:47:57 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:47:57 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2024/04/13 03:47:57 DEBUG : empty space: Unchanged skipping 2024/04/13 03:47:57 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2024/04/13 03:47:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jeyafor5kafotet7ciwucib5': Waiting for checks to finish 2024/04/13 03:47:58 INFO : empty space: Deleted 2024/04/13 03:47:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jeyafor5kafotet7ciwucib5': Waiting for transfers to finish 2024/04/13 03:47:58 INFO : potato3: Deleted 2024/04/13 03:47:59 INFO : potato2: Moved (server-side) 2024/04/13 03:47:59 INFO : potato3: Moved (server-side) 2024/04/13 03:48:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pocasiy0gezuwet3funubun5" 2024/04/13 03:48:00 DEBUG : Creating backend with remote "TestDrive:crypt/ker59deqekdgjdsq4h327ltlg355cp8b6jjceusbcskk1opvkm68ns3de7kjm15pmtr02hkoiq80e" 2024/04/13 03:48:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pocasiy0gezuwet3funubun5': Using server-side directory move 2024/04/13 03:48:02 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pocasiy0gezuwet3funubun5': Server side directory move succeeded 2024/04/13 03:48:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pocasiy0gezuwet3funubun5': Purge remote 2024/04/13 03:48:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jeyafor5kafotet7ciwucib5': Purge remote 2024/04/13 03:48:05 purge failed: directory not found --- PASS: TestServerSideMove (20.86s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:48:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-riwacan4taxahuy6nohocat4" 2024/04/13 03:48:05 DEBUG : Creating backend with remote "TestDrive:crypt/e8tkou8upo2uqkj8be6ftsu3ntkdo10v1dtlgnk4r4lpgfp9pv519i1lmtrkt5i5ufciejrsd3pc8" 2024/04/13 03:48:08 DEBUG : potato2: md5 = 0f6eb7d5972f2f30ca8879e93eac1de4 OK 2024/04/13 03:48:10 DEBUG : empty space: md5 = 4819cc358cee34dce8af6ea97b16370b OK 2024/04/13 03:48:12 DEBUG : potato3: md5 = a426155979cd148bfc0d27ee42d74cf5 OK sync_test.go:1494: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8' -> Encrypted drive 'TestCryptDrive:rclone-test-riwacan4taxahuy6nohocat4' 2024/04/13 03:48:16 DEBUG : empty space: md5 = efcd0f93fd7c59aa69ceb0a9c01db3fb OK 2024/04/13 03:48:18 DEBUG : potato3: md5 = ae79da10ee94d994ea769fd7f8c07104 OK 2024/04/13 03:48:18 DEBUG : empty space: Excluded (Size Filter) 2024/04/13 03:48:18 DEBUG : empty space: Excluded (Size Filter) 2024/04/13 03:48:18 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:48:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-riwacan4taxahuy6nohocat4': Waiting for checks to finish 2024/04/13 03:48:18 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2024/04/13 03:48:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-riwacan4taxahuy6nohocat4': Waiting for transfers to finish 2024/04/13 03:48:19 INFO : potato3: Deleted 2024/04/13 03:48:19 INFO : potato2: Moved (server-side) 2024/04/13 03:48:20 INFO : potato3: Moved (server-side) 2024/04/13 03:48:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hapayiz0tahasih5mewaxix9" 2024/04/13 03:48:21 DEBUG : Creating backend with remote "TestDrive:crypt/1203ju8hd0b7ok6b4hnrro0m5j1l79op8dvj9pjegms6dvos878doj7ipt05vtahcla4surgd2ah2" 2024/04/13 03:48:23 DEBUG : empty space: Excluded (Size Filter) 2024/04/13 03:48:23 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:48:23 DEBUG : potato3: Need to transfer - File not found at Destination 2024/04/13 03:48:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hapayiz0tahasih5mewaxix9': Waiting for checks to finish 2024/04/13 03:48:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hapayiz0tahasih5mewaxix9': Waiting for transfers to finish 2024/04/13 03:48:25 INFO : potato2: Moved (server-side) 2024/04/13 03:48:25 INFO : potato3: Moved (server-side) 2024/04/13 03:48:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hapayiz0tahasih5mewaxix9': Purge remote 2024/04/13 03:48:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-riwacan4taxahuy6nohocat4': Purge remote --- PASS: TestServerSideMoveWithFilter (24.06s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:48:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tilexoc7wirajag2febehef0" 2024/04/13 03:48:29 DEBUG : Creating backend with remote "TestDrive:crypt/k744n1ab2srbg4bq3pd6cjddef5ser1snvlscgl0arb68kjov1rocvsi8fm257088gh1sf9q5tq9c" 2024/04/13 03:48:32 DEBUG : potato2: md5 = 1abbe93e9037b1a79e07a758266ef277 OK 2024/04/13 03:48:34 DEBUG : empty space: md5 = da32cba26ec72e31a27fd967db7b38e6 OK 2024/04/13 03:48:36 DEBUG : potato3: md5 = 54400a50052797272c206f99a72e18d2 OK 2024/04/13 03:48:36 DEBUG : tomatoDir: Making directory sync_test.go:1494: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8' -> Encrypted drive 'TestCryptDrive:rclone-test-tilexoc7wirajag2febehef0' 2024/04/13 03:48:41 DEBUG : empty space: md5 = d4bb8960b884bca36612c06cca332d49 OK 2024/04/13 03:48:43 DEBUG : potato3: md5 = fdf80d97a4bcfed653c0f5f9d1817c36 OK 2024/04/13 03:48:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tilexoc7wirajag2febehef0': Using server-side directory move 2024/04/13 03:48:43 INFO : Encrypted drive 'TestCryptDrive:rclone-test-tilexoc7wirajag2febehef0': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2024/04/13 03:48:44 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:48:44 DEBUG : tomatoDir: Making directory with metadata 2024/04/13 03:48:45 INFO : tomatoDir: Made directory with metadata (mtime=2024-04-13T03:48:36.874Z) 2024/04/13 03:48:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tilexoc7wirajag2febehef0': Waiting for checks to finish 2024/04/13 03:48:45 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2024/04/13 03:48:45 DEBUG : empty space: Unchanged skipping 2024/04/13 03:48:45 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2024/04/13 03:48:46 INFO : potato2: Moved (server-side) 2024/04/13 03:48:46 INFO : empty space: Deleted 2024/04/13 03:48:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tilexoc7wirajag2febehef0': Waiting for transfers to finish 2024/04/13 03:48:46 INFO : potato3: Deleted 2024/04/13 03:48:47 INFO : potato3: Moved (server-side) 2024/04/13 03:48:47 INFO : tomatoDir: Removing directory 2024/04/13 03:48:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': deleted 1 directories 2024/04/13 03:48:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kuqejow1zuqohoc1betiwog6" 2024/04/13 03:48:49 DEBUG : Creating backend with remote "TestDrive:crypt/ogctbc4rc0sec06es51s9n6n4prflt6no4bnnf1md6od9va67b51bs9ld5ali6sut7u5uaben9b7c" 2024/04/13 03:48:50 DEBUG : tomatoDir: Making directory 2024/04/13 03:48:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kuqejow1zuqohoc1betiwog6': Using server-side directory move 2024/04/13 03:48:52 INFO : Encrypted drive 'TestCryptDrive:rclone-test-kuqejow1zuqohoc1betiwog6': Server side directory move succeeded 2024/04/13 03:48:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kuqejow1zuqohoc1betiwog6': Purge remote 2024/04/13 03:48:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tilexoc7wirajag2febehef0': Purge remote 2024/04/13 03:48:55 purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (25.84s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" sync_test.go:1699: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.51s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:48:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/rclone-sync-test" 2024/04/13 03:48:56 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncOverlap (4.47s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:49:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/rclone-sync-test" 2024/04/13 03:49:00 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2024/04/13 03:49:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/rclone-sync-test-include/layer2" 2024/04/13 03:49:03 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2024/04/13 03:49:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/rclone-sync-test-ignore-file" 2024/04/13 03:49:08 DEBUG : Config file has changed externally - reloading 2024/04/13 03:49:08 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2024/04/13 03:49:13 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = dd51061542d628cea73e12d6926ef348 OK 2024/04/13 03:49:16 DEBUG : rclone-sync-test-include: Making directory with metadata 2024/04/13 03:49:17 INFO : rclone-sync-test-include: Made directory with metadata (mtime=2024-04-13T03:49:06.12Z) 2024/04/13 03:49:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/rclone-sync-test': Waiting for checks to finish 2024/04/13 03:49:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/rclone-sync-test': Waiting for transfers to finish 2024/04/13 03:49:17 DEBUG : Waiting for deletions to finish 2024/04/13 03:49:17 INFO : There was nothing to transfer 2024/04/13 03:49:20 DEBUG : rclone-sync-test-include: Directory modification time the same (differ by 0s, within tolerance 1ms) 2024/04/13 03:49:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:49:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:49:20 DEBUG : Waiting for deletions to finish 2024/04/13 03:49:20 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:49:23 DEBUG : rclone-sync-test-include: Making directory with metadata 2024/04/13 03:49:24 INFO : rclone-sync-test-include: Made directory with metadata (mtime=2024-04-13T03:49:06.12Z) 2024/04/13 03:49:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/rclone-sync-test-include/layer2': Waiting for checks to finish 2024/04/13 03:49:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/rclone-sync-test-include/layer2': Waiting for transfers to finish 2024/04/13 03:49:24 DEBUG : Waiting for deletions to finish 2024/04/13 03:49:24 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:49:27 DEBUG : rclone-sync-test-include: Directory modification time the same (differ by 0s, within tolerance 1ms) 2024/04/13 03:49:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:49:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:49:27 DEBUG : Waiting for deletions to finish 2024/04/13 03:49:27 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:49:30 DEBUG : rclone-sync-test-include: Making directory with metadata 2024/04/13 03:49:31 INFO : rclone-sync-test-include: Made directory with metadata (mtime=2024-04-13T03:49:06.12Z) 2024/04/13 03:49:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/rclone-sync-test-ignore-file': Waiting for checks to finish 2024/04/13 03:49:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/rclone-sync-test-ignore-file': Waiting for transfers to finish 2024/04/13 03:49:31 DEBUG : Waiting for deletions to finish 2024/04/13 03:49:31 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:49:36 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4: Rmdir: contains trashed file: "khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0" 2024/04/13 03:49:37 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2024/04/13 03:49:39 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0" 2024/04/13 03:49:39 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" 2024/04/13 03:49:40 DEBUG : i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0: Rmdir: contains trashed file: "khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0" --- PASS: TestSyncOverlapWithFilter (51.04s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:49:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst" 2024/04/13 03:49:51 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/31u3jie661vd5p8j7rtc3hgbh0" 2024/04/13 03:49:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/CompareDest" 2024/04/13 03:49:53 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/gveqi14airsml4bgu7krj116o8" 2024/04/13 03:49:55 DEBUG : one: Need to transfer - File not found at Destination 2024/04/13 03:49:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:49:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:49:59 DEBUG : one: md5 = 864a85e352691e26218d8b61e4399d30 OK 2024/04/13 03:49:59 INFO : one: Copied (new) 2024/04/13 03:49:59 DEBUG : Waiting for deletions to finish 2024/04/13 03:50:00 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/04/13 03:50:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:50:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:50:02 DEBUG : one: md5 = 2cb152c7fd008de365e83c22b273b30b OK 2024/04/13 03:50:02 INFO : one: Copied (replaced existing) 2024/04/13 03:50:02 DEBUG : Waiting for deletions to finish 2024/04/13 03:50:05 DEBUG : dst/one: md5 = 07d0599fcae7b7d1ca1f86624a5f4b43 OK 2024/04/13 03:50:08 DEBUG : CompareDest/one: md5 = 994b78a466de7ccf3f7b9e1417874fe3 OK 2024/04/13 03:50:09 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/04/13 03:50:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:50:10 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:50:10 DEBUG : one: Destination found in --compare-dest, skipping 2024/04/13 03:50:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:50:10 DEBUG : Waiting for deletions to finish 2024/04/13 03:50:10 INFO : There was nothing to transfer 2024/04/13 03:50:12 DEBUG : CompareDest/two: md5 = fc1f3f205694d16fee8faa55a89e4831 OK 2024/04/13 03:50:14 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:50:14 DEBUG : two: Destination found in --compare-dest, skipping 2024/04/13 03:50:14 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/04/13 03:50:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:50:14 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:50:14 DEBUG : one: Destination found in --compare-dest, skipping 2024/04/13 03:50:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:50:14 DEBUG : Waiting for deletions to finish 2024/04/13 03:50:14 INFO : There was nothing to transfer 2024/04/13 03:50:15 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:50:15 DEBUG : two: Destination found in --compare-dest, skipping 2024/04/13 03:50:15 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/04/13 03:50:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:50:15 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:50:15 DEBUG : one: Destination found in --compare-dest, skipping 2024/04/13 03:50:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:50:15 DEBUG : Waiting for deletions to finish 2024/04/13 03:50:15 INFO : There was nothing to transfer sync_test.go:1964: No hash on uploaded file so skipping compare timestamp test 2024/04/13 03:50:17 DEBUG : two: Sizes differ (src 5 vs dst 3) 2024/04/13 03:50:17 DEBUG : two: Need to transfer - File not found at Destination 2024/04/13 03:50:17 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/04/13 03:50:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:50:18 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:50:18 DEBUG : one: Destination found in --compare-dest, skipping 2024/04/13 03:50:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:50:19 DEBUG : two: md5 = 047c99f78a0a432ca8904a9415503eb4 OK 2024/04/13 03:50:19 INFO : two: Copied (new) 2024/04/13 03:50:19 DEBUG : Waiting for deletions to finish 2024/04/13 03:50:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/04/13 03:50:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:50:25 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:50:25 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncCompareDest (35.21s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:50:29 DEBUG : pre-dest1/1: md5 = 29f87f748353b7f52996087c6cc7fa4f OK 2024/04/13 03:50:33 DEBUG : pre-dest2/2: md5 = 08e43bd72f0825526f4070dd032a6964 OK 2024/04/13 03:50:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dest" 2024/04/13 03:50:33 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/rg03c1jvnehrrc617i0lnqjddc" 2024/04/13 03:50:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/pre-dest1" 2024/04/13 03:50:35 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/bbnblvh6k061ssopqrp18kd7gc" 2024/04/13 03:50:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/pre-dest2" 2024/04/13 03:50:36 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/dgicm1h6b5ejvlltm8eeif0bnk" 2024/04/13 03:50:38 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:50:38 DEBUG : 1: Destination found in --compare-dest, skipping 2024/04/13 03:50:38 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:50:38 DEBUG : 2: Destination found in --compare-dest, skipping 2024/04/13 03:50:39 DEBUG : 3: Need to transfer - File not found at Destination 2024/04/13 03:50:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dest': Waiting for checks to finish 2024/04/13 03:50:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dest': Waiting for transfers to finish 2024/04/13 03:50:42 DEBUG : 3: md5 = 5f1e02a605e5da20ae452ef96fdae17a OK 2024/04/13 03:50:42 INFO : 3: Copied (new) 2024/04/13 03:50:42 DEBUG : Waiting for deletions to finish 2024/04/13 03:50:47 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2024/04/13 03:50:48 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2024/04/13 03:50:49 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (23.93s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:50:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst" 2024/04/13 03:50:50 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/31u3jie661vd5p8j7rtc3hgbh0" 2024/04/13 03:50:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/CopyDest" 2024/04/13 03:50:52 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/d09o6po3f7bm6ce32vdgs8h9ls" 2024/04/13 03:50:55 DEBUG : one: Need to transfer - File not found at Destination 2024/04/13 03:50:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:50:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:50:58 DEBUG : one: md5 = f6a7b8460b5144090e0e9a3ebea1805b OK 2024/04/13 03:50:58 INFO : one: Copied (new) 2024/04/13 03:50:58 DEBUG : Waiting for deletions to finish 2024/04/13 03:50:59 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/04/13 03:50:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:51:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:51:01 DEBUG : one: md5 = 906b45833862f324ba36b2310b2780de OK 2024/04/13 03:51:01 INFO : one: Copied (replaced existing) 2024/04/13 03:51:01 DEBUG : Waiting for deletions to finish 2024/04/13 03:51:04 DEBUG : dst/one: md5 = 10e63467c0f2fcc8b7ebd31d5b77f233 OK 2024/04/13 03:51:07 DEBUG : CopyDest/one: md5 = 26748422c85f866fa8b918956478c846 OK 2024/04/13 03:51:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/BackupDir" 2024/04/13 03:51:08 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/s6dbk3lfi7c9kfvo6j7bla9m0g" 2024/04/13 03:51:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:51:10 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/04/13 03:51:10 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:51:10 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/04/13 03:51:13 INFO : one: Moved (server-side) 2024/04/13 03:51:15 INFO : one: Copied (server-side copy) 2024/04/13 03:51:15 DEBUG : one: Destination found in --copy-dest, using server-side copy 2024/04/13 03:51:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:51:15 DEBUG : Waiting for deletions to finish 2024/04/13 03:51:18 DEBUG : CopyDest/two: md5 = 58f0594ac19a3496936f2508293e65fd OK 2024/04/13 03:51:19 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:51:21 INFO : two: Copied (server-side copy) 2024/04/13 03:51:21 DEBUG : two: Destination found in --copy-dest, using server-side copy 2024/04/13 03:51:21 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:51:21 DEBUG : one: Unchanged skipping 2024/04/13 03:51:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:51:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:51:21 DEBUG : Waiting for deletions to finish 2024/04/13 03:51:22 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:51:22 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:51:22 DEBUG : two: Unchanged skipping 2024/04/13 03:51:22 DEBUG : one: Unchanged skipping 2024/04/13 03:51:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:51:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:51:22 DEBUG : Waiting for deletions to finish 2024/04/13 03:51:22 INFO : There was nothing to transfer 2024/04/13 03:51:24 DEBUG : CopyDest/three: md5 = be018587b0399d404105c46ed5183430 OK 2024/04/13 03:51:26 DEBUG : three: Sizes differ (src 7 vs dst 5) 2024/04/13 03:51:26 DEBUG : three: Destination not found in --copy-dest 2024/04/13 03:51:26 DEBUG : three: Need to transfer - File not found at Destination 2024/04/13 03:51:26 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:51:26 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:51:26 DEBUG : one: Unchanged skipping 2024/04/13 03:51:26 DEBUG : two: Unchanged skipping 2024/04/13 03:51:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:51:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:51:28 DEBUG : three: md5 = 8a495ba4d3a49aa9cd1519c678df42c9 OK 2024/04/13 03:51:28 INFO : three: Copied (new) 2024/04/13 03:51:28 DEBUG : Waiting for deletions to finish 2024/04/13 03:51:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2024/04/13 03:51:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:51:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/04/13 03:51:37 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2024/04/13 03:51:37 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:51:37 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/04/13 03:51:38 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (49.31s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:51:43 DEBUG : dst/one: md5 = 9684dc38fccc02904d5bc6b84aa44a41 OK 2024/04/13 03:51:45 DEBUG : dst/two: md5 = 9a5838771c2c8219559e2e6dfc84c14f OK 2024/04/13 03:51:46 DEBUG : dst/three.txt: md5 = 16afeceb7bf355244099e810a11b259f OK 2024/04/13 03:51:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst" 2024/04/13 03:51:47 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/31u3jie661vd5p8j7rtc3hgbh0" 2024/04/13 03:51:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/backup" 2024/04/13 03:51:48 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/1nrff024r7pq65ecp72fc28jb0" 2024/04/13 03:51:50 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/04/13 03:51:50 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:51:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:51:50 DEBUG : two: Unchanged skipping 2024/04/13 03:51:53 INFO : one: Moved (server-side) 2024/04/13 03:51:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:51:55 DEBUG : one: md5 = 28962be7b40941291a1b880cd1a63cf6 OK 2024/04/13 03:51:55 INFO : one: Copied (new) 2024/04/13 03:51:55 DEBUG : Waiting for deletions to finish 2024/04/13 03:51:56 INFO : three.txt: Moved (server-side) 2024/04/13 03:51:56 INFO : three.txt: Moved into backup dir 2024/04/13 03:51:59 DEBUG : dst/three.txt: md5 = 526463d8bd3f0ee673f163968942dd20 OK 2024/04/13 03:52:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:52:00 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/04/13 03:52:00 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:52:00 DEBUG : two: Unchanged skipping 2024/04/13 03:52:01 INFO : one: Deleted 2024/04/13 03:52:02 INFO : one: Moved (server-side) 2024/04/13 03:52:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:52:04 DEBUG : one: md5 = 5f6e3f109febc7a6710e754daefce4ea OK 2024/04/13 03:52:04 INFO : one: Copied (new) 2024/04/13 03:52:04 DEBUG : Waiting for deletions to finish 2024/04/13 03:52:05 INFO : three.txt: Deleted 2024/04/13 03:52:06 INFO : three.txt: Moved (server-side) 2024/04/13 03:52:06 INFO : three.txt: Moved into backup dir 2024/04/13 03:52:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:52:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/04/13 03:52:12 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:52:12 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2024/04/13 03:52:12 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2024/04/13 03:52:12 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncBackupDir (33.75s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:52:16 DEBUG : dst/one: md5 = b431e62e6ddd0428bf99b24ce14dae46 OK 2024/04/13 03:52:18 DEBUG : dst/two: md5 = 8ffcc81f2f8355c54a45a8f62603ac10 OK 2024/04/13 03:52:20 DEBUG : dst/three.txt: md5 = 1c7c57127155e24373dc517419cf13f9 OK 2024/04/13 03:52:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst" 2024/04/13 03:52:21 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/31u3jie661vd5p8j7rtc3hgbh0" 2024/04/13 03:52:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/backup" 2024/04/13 03:52:22 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/1nrff024r7pq65ecp72fc28jb0" 2024/04/13 03:52:24 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/04/13 03:52:24 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:52:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:52:24 DEBUG : two: Unchanged skipping 2024/04/13 03:52:27 INFO : one: Moved (server-side) to: one.bak 2024/04/13 03:52:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:52:29 DEBUG : one: md5 = 2b1668544c174383db977d80a6fc1525 OK 2024/04/13 03:52:29 INFO : one: Copied (new) 2024/04/13 03:52:29 DEBUG : Waiting for deletions to finish 2024/04/13 03:52:30 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/04/13 03:52:30 INFO : three.txt: Moved into backup dir 2024/04/13 03:52:32 DEBUG : dst/three.txt: md5 = 769f520fe494ede9c02fcb60b4e885c3 OK 2024/04/13 03:52:33 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/04/13 03:52:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:52:33 DEBUG : two: Unchanged skipping 2024/04/13 03:52:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:52:35 INFO : one.bak: Deleted 2024/04/13 03:52:36 INFO : one: Moved (server-side) to: one.bak 2024/04/13 03:52:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:52:38 DEBUG : one: md5 = b609020099effdc02c480bd8f7661eaf OK 2024/04/13 03:52:38 INFO : one: Copied (new) 2024/04/13 03:52:38 DEBUG : Waiting for deletions to finish 2024/04/13 03:52:39 INFO : three.txt.bak: Deleted 2024/04/13 03:52:40 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/04/13 03:52:40 INFO : three.txt: Moved into backup dir 2024/04/13 03:52:45 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:52:45 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/04/13 03:52:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/04/13 03:52:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2024/04/13 03:52:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/04/13 03:52:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirWithSuffix (33.62s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:52:50 DEBUG : dst/one: md5 = 93998e972568aa9d4ce54b449b1bf1ed OK 2024/04/13 03:52:52 DEBUG : dst/two: md5 = beeab629b44774cf8005498621d673da OK 2024/04/13 03:52:54 DEBUG : dst/three.txt: md5 = 2389805a398c1ff73df389053779196d OK 2024/04/13 03:52:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst" 2024/04/13 03:52:55 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/31u3jie661vd5p8j7rtc3hgbh0" 2024/04/13 03:52:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/backup" 2024/04/13 03:52:56 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/1nrff024r7pq65ecp72fc28jb0" 2024/04/13 03:52:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:52:58 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/04/13 03:52:58 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:52:58 DEBUG : two: Unchanged skipping 2024/04/13 03:53:00 INFO : one: Moved (server-side) to: one-2019-01-01 2024/04/13 03:53:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:53:02 DEBUG : one: md5 = 7570a8d571e551173a8ae690fe99a1b6 OK 2024/04/13 03:53:02 INFO : one: Copied (new) 2024/04/13 03:53:02 DEBUG : Waiting for deletions to finish 2024/04/13 03:53:04 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2024/04/13 03:53:04 INFO : three.txt: Moved into backup dir 2024/04/13 03:53:06 DEBUG : dst/three.txt: md5 = d3178ebf5817c57094a2e30781238fe7 OK 2024/04/13 03:53:07 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/04/13 03:53:07 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:53:07 DEBUG : two: Unchanged skipping 2024/04/13 03:53:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:53:08 INFO : one-2019-01-01: Deleted 2024/04/13 03:53:09 INFO : one: Moved (server-side) to: one-2019-01-01 2024/04/13 03:53:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:53:11 DEBUG : one: md5 = 5402805260e08cc60f302d1d4aa0ccc4 OK 2024/04/13 03:53:11 INFO : one: Copied (new) 2024/04/13 03:53:11 DEBUG : Waiting for deletions to finish 2024/04/13 03:53:12 INFO : three-2019-01-01.txt: Deleted 2024/04/13 03:53:13 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2024/04/13 03:53:13 INFO : three.txt: Moved into backup dir 2024/04/13 03:53:18 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:53:18 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/04/13 03:53:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2024/04/13 03:53:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2024/04/13 03:53:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2024/04/13 03:53:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (33.35s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:53:23 DEBUG : dst/one: md5 = a04a7b6695d404d9c855ebab120bdea2 OK 2024/04/13 03:53:25 DEBUG : dst/two: md5 = 05f3f3da61f281aec21c9b99b30cb40b OK 2024/04/13 03:53:28 DEBUG : dst/three.txt: md5 = 963a73bb205173356ed53da5cc973cea OK 2024/04/13 03:53:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst" 2024/04/13 03:53:28 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/31u3jie661vd5p8j7rtc3hgbh0" 2024/04/13 03:53:30 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/04/13 03:53:30 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:53:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:53:30 DEBUG : two: Unchanged skipping 2024/04/13 03:53:31 INFO : one: Moved (server-side) to: one.bak 2024/04/13 03:53:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:53:33 DEBUG : one: md5 = 3d1b53644c7a98636ebfe993aea4356a OK 2024/04/13 03:53:33 INFO : one: Copied (new) 2024/04/13 03:53:33 DEBUG : Waiting for deletions to finish 2024/04/13 03:53:34 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/04/13 03:53:34 INFO : three.txt: Moved into backup dir 2024/04/13 03:53:37 DEBUG : dst/three.txt: md5 = fe36f11de1cdb34d7cb45b67d5980ff5 OK 2024/04/13 03:53:38 DEBUG : one.bak: Excluded (Path Filter) 2024/04/13 03:53:38 DEBUG : three.txt.bak: Excluded (Path Filter) 2024/04/13 03:53:38 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/04/13 03:53:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for checks to finish 2024/04/13 03:53:38 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:53:38 DEBUG : two: Unchanged skipping 2024/04/13 03:53:39 INFO : one.bak: Deleted 2024/04/13 03:53:40 INFO : one: Moved (server-side) to: one.bak 2024/04/13 03:53:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst': Waiting for transfers to finish 2024/04/13 03:53:42 DEBUG : one: md5 = c0bbe6fa86eed32e1581936d05520364 OK 2024/04/13 03:53:42 INFO : one: Copied (new) 2024/04/13 03:53:42 DEBUG : Waiting for deletions to finish 2024/04/13 03:53:43 INFO : three.txt.bak: Deleted 2024/04/13 03:53:43 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/04/13 03:53:43 INFO : three.txt: Moved into backup dir 2024/04/13 03:53:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:53:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/04/13 03:53:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2024/04/13 03:53:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/04/13 03:53:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/04/13 03:53:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirSuffixOnly (29.61s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:53:53 DEBUG : dst/one: md5 = a82d99ef1b2d5f062c1be31510ec41f0 OK 2024/04/13 03:53:56 DEBUG : dst/two: md5 = 16c6adeebfb5f089b927b7d71632ec57 OK 2024/04/13 03:53:58 DEBUG : dst/three.txt: md5 = 39a2d9420fbadbb43e568aeaa35b95b8 OK 2024/04/13 03:53:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst" 2024/04/13 03:53:58 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/31u3jie661vd5p8j7rtc3hgbh0" 2024/04/13 03:53:59 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/04/13 03:54:01 INFO : one: Moved (server-side) to: one.bak 2024/04/13 03:54:03 DEBUG : one: md5 = e3449da6e30d2cdbea1f76c6a26c19ff OK 2024/04/13 03:54:03 INFO : one: Copied (new) 2024/04/13 03:54:03 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:54:03 DEBUG : two: Unchanged skipping 2024/04/13 03:54:03 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2024/04/13 03:54:05 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/04/13 03:54:06 DEBUG : three.txt: md5 = 0f4e53dabe8796bd7ce806f1ceef7343 OK 2024/04/13 03:54:06 INFO : three.txt: Copied (new) 2024/04/13 03:54:08 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/04/13 03:54:09 INFO : one.bak: Deleted 2024/04/13 03:54:10 INFO : one: Moved (server-side) to: one.bak 2024/04/13 03:54:12 DEBUG : one: md5 = 91a501a4075de3bada3517c4f5acd6b6 OK 2024/04/13 03:54:12 INFO : one: Copied (new) 2024/04/13 03:54:13 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:54:13 DEBUG : two: Unchanged skipping 2024/04/13 03:54:13 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2024/04/13 03:54:14 INFO : three.txt.bak: Deleted 2024/04/13 03:54:15 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/04/13 03:54:17 DEBUG : three.txt: md5 = 922af6ef48e0ac4ea76715a115392280 OK 2024/04/13 03:54:17 INFO : three.txt: Copied (new) 2024/04/13 03:54:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2024/04/13 03:54:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:54:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/04/13 03:54:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2024/04/13 03:54:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/04/13 03:54:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/04/13 03:54:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncSuffix (33.74s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:54:27 DEBUG : dst/one: md5 = a6a7f14d8c18fbe339d5952e676fea3c OK 2024/04/13 03:54:29 DEBUG : dst/two: md5 = 877019824fac4e94606058730dd10731 OK 2024/04/13 03:54:31 DEBUG : dst/three.txt: md5 = 1f20da89ccfe2babdbea74dd30c82ddf OK 2024/04/13 03:54:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voveyox2kadojul2belowik8/dst" 2024/04/13 03:54:31 DEBUG : Creating backend with remote "TestDrive:crypt/do87dunaaqdjded1bjpik3attfbvjn49q2o35rc0miq0cdef7cfuj3ojtplksiunti9ad9tean3im/31u3jie661vd5p8j7rtc3hgbh0" 2024/04/13 03:54:32 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/04/13 03:54:34 INFO : one: Moved (server-side) to: one-2019-01-01 2024/04/13 03:54:36 DEBUG : one: md5 = 6b6d05210e02a124a2ec8ac91264730d OK 2024/04/13 03:54:36 INFO : one: Copied (new) 2024/04/13 03:54:36 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:54:36 DEBUG : two: Unchanged skipping 2024/04/13 03:54:36 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2024/04/13 03:54:37 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2024/04/13 03:54:39 DEBUG : three.txt: md5 = 451c24651e9eabba5cf2c15bcd52ba88 OK 2024/04/13 03:54:39 INFO : three.txt: Copied (new) 2024/04/13 03:54:41 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/04/13 03:54:42 INFO : one-2019-01-01: Deleted 2024/04/13 03:54:43 INFO : one: Moved (server-side) to: one-2019-01-01 2024/04/13 03:54:45 DEBUG : one: md5 = 3721a41904c9c5fd74df291173bfdfbb OK 2024/04/13 03:54:45 INFO : one: Copied (new) 2024/04/13 03:54:45 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:54:45 DEBUG : two: Unchanged skipping 2024/04/13 03:54:45 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2024/04/13 03:54:47 INFO : three-2019-01-01.txt: Deleted 2024/04/13 03:54:48 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2024/04/13 03:54:49 DEBUG : three.txt: md5 = ec02eb7a671dab85515c705c225fe40b OK 2024/04/13 03:54:49 INFO : three.txt: Copied (new) 2024/04/13 03:54:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:54:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2024/04/13 03:54:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2024/04/13 03:54:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/04/13 03:54:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2024/04/13 03:54:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2024/04/13 03:54:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncSuffixKeepExtension (32.46s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:54:58 DEBUG : Testêé: md5 = c051f2d238c6145654f40168c0b1530a OK 2024/04/13 03:54:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:54:59 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2024/04/13 03:54:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:55:00 DEBUG : Testêé: md5 = dcb4d8f79a6102f253772d6cb3ed3f4a OK 2024/04/13 03:55:00 INFO : Testêé: Copied (replaced existing) to: Testêé 2024/04/13 03:55:00 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (6.04s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:55:03 DEBUG : existing: Need to transfer - File not found at Destination 2024/04/13 03:55:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:55:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:55:05 DEBUG : existing: md5 = 085e16d507b3db6004668baa82c420e3 OK 2024/04/13 03:55:05 INFO : existing: Copied (new) 2024/04/13 03:55:05 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:55:06 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2024/04/13 03:55:06 ERROR : existing: Source and destination exist but do not match: immutable file modified 2024/04/13 03:55:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:55:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:55:06 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': not deleting files as there were IO errors 2024/04/13 03:55:06 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncImmutable (6.64s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:55:11 DEBUG : EXISTING: md5 = a83552b76a03b5320e886e65a3c606c5 OK 2024/04/13 03:55:11 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:55:11 DEBUG : existing: Unchanged skipping 2024/04/13 03:55:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:55:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:55:11 DEBUG : Waiting for deletions to finish 2024/04/13 03:55:11 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (4.19s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" sync_test.go:2420: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.60s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" sync_test.go:2459: This test only runs on local === RUN TestMaxTransfer/Soft run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" sync_test.go:2459: This test only runs on local === RUN TestMaxTransfer/Cautious run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" sync_test.go:2459: This test only runs on local --- PASS: TestMaxTransfer (1.67s) --- SKIP: TestMaxTransfer/Hard (0.52s) --- SKIP: TestMaxTransfer/Soft (0.59s) --- SKIP: TestMaxTransfer/Cautious (0.56s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:55:17 DEBUG : both0: md5 = 311d4dbecf9eddd02f1ac2728580c3d3 OK 2024/04/13 03:55:19 DEBUG : only0: md5 = 2c5d776a3b923339b3980384bb4865bb OK 2024/04/13 03:55:21 DEBUG : both1: md5 = 3248602d3ba171fac5846d0c848ad413 OK 2024/04/13 03:55:23 DEBUG : only1: md5 = a9a858c49c3a41c221c1f79eb6bd8655 OK 2024/04/13 03:55:24 DEBUG : both2: md5 = a88a728932e519c6a62c1f3745a6409d OK 2024/04/13 03:55:26 DEBUG : only2: md5 = 5b68469655f514321f8c825ace7ea4cc OK 2024/04/13 03:55:28 DEBUG : both3: md5 = 38bb64bf9535633b9e947020fe06d5af OK 2024/04/13 03:55:30 DEBUG : only3: md5 = d35031de4f314a938753c9aa91d4fd64 OK 2024/04/13 03:55:32 DEBUG : both4: md5 = 675750341f6e98d3282b7ffd7b1b2487 OK 2024/04/13 03:55:34 DEBUG : only4: md5 = 6a55ea21c414217ae87724e737c21f6e OK 2024/04/13 03:55:36 DEBUG : both5: md5 = f9e3f9b84101ab2893fdd4a9e03010c4 OK 2024/04/13 03:55:38 DEBUG : only5: md5 = a60eda181ad1b395c47dd8dd4db36db1 OK 2024/04/13 03:55:40 DEBUG : both6: md5 = 820a38b306065bb4ce92423c69964480 OK 2024/04/13 03:55:41 DEBUG : only6: md5 = 17a34f81d085c7febfe11f169941fedc OK 2024/04/13 03:55:43 DEBUG : both7: md5 = 7b19a21a8a4116e4652be986baf27c86 OK 2024/04/13 03:55:45 DEBUG : only7: md5 = e6883c63004a159c4d6f8d41820f4dd6 OK 2024/04/13 03:55:47 DEBUG : both8: md5 = f9073d01b63a30268b636c0cd978618f OK 2024/04/13 03:55:49 DEBUG : only8: md5 = f9bf9d69d54acdd5a2fd1c2f04b9249e OK 2024/04/13 03:55:51 DEBUG : both9: md5 = 83f044654ecf0f5d319e9234c400128d OK 2024/04/13 03:55:53 DEBUG : only9: md5 = 5ce8e0951965e8e11565d7c442bdedb1 OK 2024/04/13 03:55:55 DEBUG : both10: md5 = 57d9bcb0c976902df4404d9f9da9be0f OK 2024/04/13 03:55:57 DEBUG : only10: md5 = e34baaeb65d2836f77e635b2b9e6fd10 OK 2024/04/13 03:55:58 DEBUG : both11: md5 = b4cb4dc544b69b910f5c656bf9f62a1c OK 2024/04/13 03:56:00 DEBUG : only11: md5 = 216493170ad5fe6a85312bf28b98129a OK 2024/04/13 03:56:02 DEBUG : both12: md5 = 7c376283e863b4749e9ae52408fb9578 OK 2024/04/13 03:56:04 DEBUG : only12: md5 = f543e214b6ed976812bddf5e0fd7c3ad OK 2024/04/13 03:56:06 DEBUG : both13: md5 = 0e40b8def254c037907249f952f0dc90 OK 2024/04/13 03:56:08 DEBUG : only13: md5 = 7837ec5dbed7f4a06505dff1ec1577fe OK 2024/04/13 03:56:10 DEBUG : both14: md5 = c5c240ff49cf96ec27d27018b5091574 OK 2024/04/13 03:56:12 DEBUG : only14: md5 = fabbe0843ad147e56e9517dd0a760d5b OK 2024/04/13 03:56:14 DEBUG : both15: md5 = f093785ad6038a5f093e7616d9c11e01 OK 2024/04/13 03:56:16 DEBUG : only15: md5 = e85567b3d1b9dfd10337b5fe930c80bc OK 2024/04/13 03:56:18 DEBUG : both16: md5 = e0f04686f296bf9c9b39a03379c1e7ac OK 2024/04/13 03:56:20 DEBUG : only16: md5 = de0e1361094c957922a68c22423a921c OK 2024/04/13 03:56:22 DEBUG : both17: md5 = 9a8c4e3d540b8fb01475764bc15a1872 OK 2024/04/13 03:56:23 DEBUG : only17: md5 = 569a6f323934f87746ad175d90ca7a9f OK 2024/04/13 03:56:25 DEBUG : both18: md5 = 23f2ccb03b419fb07197089f536de545 OK 2024/04/13 03:56:27 DEBUG : only18: md5 = 092aa206024e7d4487fcc2bd2856b60d OK 2024/04/13 03:56:29 DEBUG : both19: md5 = 827ff79367abe86455f1c7ae2a0652df OK 2024/04/13 03:56:31 DEBUG : only19: md5 = 1058afcd82b8d3d8eea905241236b164 OK 2024/04/13 03:56:32 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:56:32 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both0: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both12: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both13: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both1: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both15: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both16: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both17: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both18: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both19: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both2: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both10: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both11: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both14: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both5: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both7: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both8: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:56:32 DEBUG : both3: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both4: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both6: Unchanged skipping 2024/04/13 03:56:32 DEBUG : both9: Unchanged skipping 2024/04/13 03:56:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:56:32 DEBUG : Waiting for deletions to finish 2024/04/13 03:56:32 INFO : only11: Deleted 2024/04/13 03:56:32 INFO : only10: Deleted 2024/04/13 03:56:32 INFO : only19: Deleted 2024/04/13 03:56:32 INFO : only18: Deleted 2024/04/13 03:56:33 INFO : only17: Deleted 2024/04/13 03:56:33 INFO : only12: Deleted 2024/04/13 03:56:33 INFO : only15: Deleted 2024/04/13 03:56:33 INFO : only16: Deleted 2024/04/13 03:56:34 INFO : only0: Deleted 2024/04/13 03:56:34 INFO : only8: Deleted 2024/04/13 03:56:34 INFO : only3: Deleted 2024/04/13 03:56:34 INFO : only1: Deleted 2024/04/13 03:56:35 INFO : only13: Deleted 2024/04/13 03:56:35 INFO : only2: Deleted 2024/04/13 03:56:35 INFO : only7: Deleted 2024/04/13 03:56:35 INFO : only14: Deleted 2024/04/13 03:56:36 INFO : only4: Deleted 2024/04/13 03:56:36 INFO : only9: Deleted 2024/04/13 03:56:36 INFO : only6: Deleted 2024/04/13 03:56:36 INFO : only5: Deleted 2024/04/13 03:56:36 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (98.55s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:56:56 DEBUG : both0: md5 = ddf257c42df7a42b3dd7a2fd8efc2667 OK 2024/04/13 03:56:58 DEBUG : only0: md5 = 21c161ab93d79c51bfdad0c6d30c689d OK 2024/04/13 03:57:00 DEBUG : both1: md5 = abc0a355a1d64583d32669c4badd84b2 OK 2024/04/13 03:57:01 DEBUG : only1: md5 = 2c05cfb6c55636e0fa974edc417572ea OK 2024/04/13 03:57:03 DEBUG : both2: md5 = 572e95e889b9b7a1323cffcdd19e0aa2 OK 2024/04/13 03:57:05 DEBUG : only2: md5 = 1517777e1dd3cb46ccaa866704db51a7 OK 2024/04/13 03:57:07 DEBUG : both3: md5 = 8c77a0d76c85e349044d2edd911ceb01 OK 2024/04/13 03:57:09 DEBUG : only3: md5 = b316721a665ff6da8221aeb1cefb16c9 OK 2024/04/13 03:57:11 DEBUG : both4: md5 = 8709628c213ce9254eb5de15569a4679 OK 2024/04/13 03:57:13 DEBUG : only4: md5 = 0f18d8b104c4aca5ccdf0107448f2f95 OK 2024/04/13 03:57:14 DEBUG : both5: md5 = fed9b298a7eade7bd27ef37c4a50fcc3 OK 2024/04/13 03:57:18 DEBUG : only5: md5 = 5c0a50022f9e15911c05a03191a249fc OK 2024/04/13 03:57:19 DEBUG : both6: md5 = 21ef98cb9894944831a60f04449c5aee OK 2024/04/13 03:57:21 DEBUG : only6: md5 = 6392aa35d60ea1d06ae58ab0a994f9cc OK 2024/04/13 03:57:23 DEBUG : both7: md5 = abd8960c187d826225e099cdfe8b522b OK 2024/04/13 03:57:25 DEBUG : only7: md5 = e9db590715078fdca53ee7b972f7ecb3 OK 2024/04/13 03:57:27 DEBUG : both8: md5 = b69438cd245800cc3a0931ef7044f99b OK 2024/04/13 03:57:29 DEBUG : only8: md5 = f034d2beb49a9d923ab47201c70b61e9 OK 2024/04/13 03:57:31 DEBUG : both9: md5 = 3d000325f8ef7399a7f28a1603c94fbf OK 2024/04/13 03:57:33 DEBUG : only9: md5 = eee0195ce848b8ae355e2cbc1f6abfd6 OK 2024/04/13 03:57:35 DEBUG : both10: md5 = 6b36c13a5cd20c9613c6adc6bb00023d OK 2024/04/13 03:57:37 DEBUG : only10: md5 = 8f99a4757a9f6b6c3953248852a2a8f2 OK 2024/04/13 03:57:38 DEBUG : both11: md5 = 1ffa27402b0b2bdded98617b98181119 OK 2024/04/13 03:57:40 DEBUG : only11: md5 = 09eb5fb9d0893ad8b540930094e8fffb OK 2024/04/13 03:57:42 DEBUG : both12: md5 = b3e00492c7d0b01ecfee22e62e510548 OK 2024/04/13 03:57:44 DEBUG : only12: md5 = 9cdcc51f2204bda39e3d941f45dfd87a OK 2024/04/13 03:57:46 DEBUG : both13: md5 = dd07c9dc992795987f2bf610fb0b4b1a OK 2024/04/13 03:57:48 DEBUG : only13: md5 = 65a622f048eeed37516abdff553f5d40 OK 2024/04/13 03:57:50 DEBUG : both14: md5 = afe59c44c97b89d3db65f073336196fa OK 2024/04/13 03:57:52 DEBUG : only14: md5 = b8825c6adb7064c0638c2006e104bc9e OK 2024/04/13 03:57:54 DEBUG : both15: md5 = c813b0d7922e3d38cdd32f75b055ae2f OK 2024/04/13 03:57:55 DEBUG : only15: md5 = 390f0e3e490262185f1dc858ff6b8949 OK 2024/04/13 03:57:57 DEBUG : both16: md5 = 92d5fdbbd847f4ef2f4ac4ea713d95c8 OK 2024/04/13 03:57:59 DEBUG : only16: md5 = 148811759e3a31ceb97adb0edd8f48e0 OK 2024/04/13 03:58:01 DEBUG : both17: md5 = 7ddc04685cbf3d5a15b009497ce8e68a OK 2024/04/13 03:58:03 DEBUG : only17: md5 = 380a07ef8f48957af8dcd90c0a3efdaa OK 2024/04/13 03:58:05 DEBUG : both18: md5 = 12c6b6d86fa4cf5e5487f76a859c8817 OK 2024/04/13 03:58:07 DEBUG : only18: md5 = 4166fdf15fd79484226d48e9a9d7b215 OK 2024/04/13 03:58:08 DEBUG : both19: md5 = 1d54148732732edcff1d3d407888c6d4 OK 2024/04/13 03:58:10 DEBUG : only19: md5 = 35db9dd06c681550874eb00c5894e043 OK 2024/04/13 03:58:11 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for checks to finish 2024/04/13 03:58:11 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both1: Unchanged skipping 2024/04/13 03:58:11 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both11: Unchanged skipping 2024/04/13 03:58:11 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both13: Unchanged skipping 2024/04/13 03:58:11 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both12: Unchanged skipping 2024/04/13 03:58:11 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both15: Unchanged skipping 2024/04/13 03:58:11 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both16: Unchanged skipping 2024/04/13 03:58:11 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both10: Unchanged skipping 2024/04/13 03:58:11 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both0: Unchanged skipping 2024/04/13 03:58:11 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both19: Unchanged skipping 2024/04/13 03:58:11 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both14: Unchanged skipping 2024/04/13 03:58:11 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both17: Unchanged skipping 2024/04/13 03:58:11 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both4: Unchanged skipping 2024/04/13 03:58:11 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both5: Unchanged skipping 2024/04/13 03:58:11 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both6: Unchanged skipping 2024/04/13 03:58:11 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both18: Unchanged skipping 2024/04/13 03:58:11 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both8: Unchanged skipping 2024/04/13 03:58:11 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:11 DEBUG : both9: Unchanged skipping 2024/04/13 03:58:11 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : both2: Unchanged skipping 2024/04/13 03:58:11 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : both3: Unchanged skipping 2024/04/13 03:58:11 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : both7: Unchanged skipping 2024/04/13 03:58:11 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2024/04/13 03:58:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Waiting for transfers to finish 2024/04/13 03:58:13 DEBUG : only14: md5 = ef29816b4b5163b5e135aecac89e3a7b OK 2024/04/13 03:58:13 INFO : only14: Copied (replaced existing) 2024/04/13 03:58:13 DEBUG : only10: md5 = c13182959c88ea7059e5467b4180bfa1 OK 2024/04/13 03:58:13 INFO : only10: Copied (replaced existing) 2024/04/13 03:58:13 DEBUG : only1: md5 = 9ab5679a8bacad68bfedafc764d94ef8 OK 2024/04/13 03:58:13 INFO : only1: Copied (replaced existing) 2024/04/13 03:58:13 DEBUG : only0: md5 = fb5baa0fb3854c9e6b40acc1c94ae318 OK 2024/04/13 03:58:13 INFO : only0: Copied (replaced existing) 2024/04/13 03:58:15 DEBUG : only16: md5 = 7aab405a21692ec49114937d757f3528 OK 2024/04/13 03:58:15 INFO : only16: Copied (replaced existing) 2024/04/13 03:58:15 DEBUG : only15: md5 = badb6eca465a7cb7a4332405ea452e04 OK 2024/04/13 03:58:15 INFO : only15: Copied (replaced existing) 2024/04/13 03:58:15 DEBUG : only17: md5 = 1ea8b3e6b848610e5d4c90a1c259b38a OK 2024/04/13 03:58:15 INFO : only17: Copied (replaced existing) 2024/04/13 03:58:15 DEBUG : only18: md5 = 8f508ef51cb3a40f24d6d97712ea3a74 OK 2024/04/13 03:58:15 INFO : only18: Copied (replaced existing) 2024/04/13 03:58:16 DEBUG : only19: md5 = 641a9c8d78aa22b9a30be29ac6d4c75f OK 2024/04/13 03:58:16 INFO : only19: Copied (replaced existing) 2024/04/13 03:58:16 DEBUG : only2: md5 = 0f449f3f839bb5f6a40fece5c966ac71 OK 2024/04/13 03:58:16 INFO : only2: Copied (replaced existing) 2024/04/13 03:58:16 DEBUG : only4: md5 = 65b86bf9f97c62b639002cd3b57cbad8 OK 2024/04/13 03:58:16 DEBUG : only11: md5 = 6cb5331fbd8615ebff40b7f623951945 OK 2024/04/13 03:58:16 INFO : only4: Copied (replaced existing) 2024/04/13 03:58:16 INFO : only11: Copied (replaced existing) 2024/04/13 03:58:18 DEBUG : only5: md5 = ff980f31781ba0e234ab0ba8ebe65d13 OK 2024/04/13 03:58:18 INFO : only5: Copied (replaced existing) 2024/04/13 03:58:18 DEBUG : only8: md5 = 119256c41515d1b89e328ab3ff45a983 OK 2024/04/13 03:58:18 INFO : only8: Copied (replaced existing) 2024/04/13 03:58:18 DEBUG : only7: md5 = 4bb47653749e9032c6be08ca99a39c26 OK 2024/04/13 03:58:18 INFO : only7: Copied (replaced existing) 2024/04/13 03:58:18 DEBUG : only12: md5 = cb217025552179db101e153e43359b1f OK 2024/04/13 03:58:18 INFO : only12: Copied (replaced existing) 2024/04/13 03:58:20 DEBUG : only13: md5 = bbade83a85e4fdf48f43ff8803fca496 OK 2024/04/13 03:58:20 INFO : only13: Copied (replaced existing) 2024/04/13 03:58:20 DEBUG : only3: md5 = 0f05419b74d77f24703b9fffa8b06dcb OK 2024/04/13 03:58:20 INFO : only3: Copied (replaced existing) 2024/04/13 03:58:20 DEBUG : only6: md5 = 5d48b9846acd0d8c50d69d07acd02734 OK 2024/04/13 03:58:20 INFO : only6: Copied (replaced existing) 2024/04/13 03:58:20 DEBUG : only9: md5 = 1217e1846534b06b1f37cafa533cc859 OK 2024/04/13 03:58:20 INFO : only9: Copied (replaced existing) 2024/04/13 03:58:20 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (118.79s) === RUN TestNothingToTransfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:58:53 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/04/13 03:58:53 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:58:54 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8'", Local "Local file system at /tmp/rclone2952895842", Modify Window "1ms" 2024/04/13 03:59:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/04/13 03:59:21 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2024/04/13 03:59:22 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2024/04/13 03:59:23 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/04/13 03:59:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/04/13 03:59:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/04/13 03:59:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/04/13 03:59:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/04/13 03:59:29 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransfer (38.75s) PASS 2024/04/13 03:59:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voveyox2kadojul2belowik8': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 18m31.796916901s (try 1/5)