"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5) 2024/04/13 03:46:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8" 2024/04/13 03:46:24 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2024/04/13 03:46:24 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu" 2024/04/13 03:46:25 DEBUG : Creating backend with remote "/tmp/rclone2772693830" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.05s) === 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-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:46:27 NOTICE: sub dir: Skipped make directory as --dry-run is set 2024/04/13 03:46:27 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:46:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:46:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:46:27 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.97s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:46:28 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/04/13 03:46:28 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:46:30 INFO : sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/04/13 03:46:30 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:46:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:46:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:46:32 DEBUG : sub dir/hello world: md5 = 2d8dc8aca00bdcc51f18fcf10ad67968 OK 2024/04/13 03:46:32 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:46:34 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (7.97s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:46:36 DEBUG : metadata sub dir: Making directory with metadata 2024/04/13 03:46:36 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/04/13 03:46:36 DEBUG : Local file system at /tmp/rclone2772693830: File to upload is small (21 bytes), uploading instead of streaming 2024/04/13 03:46:36 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2024/04/13 03:46:36 DEBUG : metadata sub dir/hello metadata world.gihunej5.partial: renamed to: metadata sub dir/hello metadata world 2024/04/13 03:46:36 INFO : metadata sub dir/hello metadata world: Copied (new) 2024/04/13 03:46:36 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2024/04/13 03:46:37 DEBUG : Google drive root 'crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu': Skipping btime metadata as can't update it on an existing file: 2024-04-13T03:46:36.579079061Z 2024/04/13 03:46:38 INFO : metadata sub dir: Updated directory metadata 2024/04/13 03:46:38 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2024/04/13 03:46:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:46:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:46:39 DEBUG : metadata sub dir/hello metadata world: md5 = 378b01c4cae336b91f0c9b523c96d370 OK 2024/04/13 03:46:39 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:46:43 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (8.07s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:46:44 DEBUG : Creating backend with remote "/non-existing" 2024/04/13 03:46:44 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2024/04/13 03:46:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:46:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.34s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:46:45 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:46:47 INFO : sub dir: Made directory with metadata (mtime=2024-04-13T03:46:45.987071052Z) 2024/04/13 03:46:47 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:46:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:46:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:46:49 DEBUG : sub dir/hello world: md5 = edde893e3a43a344b9baef9cc4839d5e OK 2024/04/13 03:46:49 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:46:51 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (7.34s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:46:53 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Running all checks before starting transfers 2024/04/13 03:46:53 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:46:54 INFO : sub dir: Made directory with metadata (mtime=2024-04-13T03:46:53.3270649Z) 2024/04/13 03:46:54 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:46:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:46:54 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Checks finished, now starting transfers 2024/04/13 03:46:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:46:56 DEBUG : sub dir/hello world: md5 = 2c00bb046d2df706fb9a55b5c2c2ad0a OK 2024/04/13 03:46:56 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:46:59 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (7.41s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:47:00 ERROR : Ignoring --no-traverse with sync 2024/04/13 03:47:00 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:47:02 INFO : sub dir: Made directory with metadata (mtime=2024-04-13T03:47:00.735058777Z) 2024/04/13 03:47:02 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:47:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:47:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:47:04 DEBUG : sub dir/hello world: md5 = 408cf6a62da0987aa46140dce4e16aac OK 2024/04/13 03:47:04 INFO : sub dir/hello world: Copied (new) 2024/04/13 03:47:04 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:47:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (8.38s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:47:09 DEBUG : hello world2: Need to transfer - File not found at Destination 2024/04/13 03:47:09 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:47:10 INFO : sub dir: Made directory with metadata (mtime=2024-04-13T03:47:09.111051955Z) 2024/04/13 03:47:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:47:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:47:11 DEBUG : hello world2: md5 = 5ca05893be2fc88891d11e69e4fff48c OK 2024/04/13 03:47:11 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestCopyWithDepth (6.35s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:47:15 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:47:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:47:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:47:17 DEBUG : potato2: md5 = 13b2cfb499c74ff1e5af3bdbbf8e277f OK 2024/04/13 03:47:17 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (4.41s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:47:20 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:47:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:47:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:47:22 DEBUG : potato2: md5 = d6748b2b1ca38a108bd44528e60a3714 OK 2024/04/13 03:47:22 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (4.41s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:47:24 DEBUG : sub dir2: Making directory with metadata 2024/04/13 03:47:24 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/04/13 03:47:24 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/04/13 03:47:24 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:47:25 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2024/04/13 03:47:25 DEBUG : sub dir2: Making directory with metadata 2024/04/13 03:47:26 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/04/13 03:47:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:47:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:47:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:47:28 DEBUG : sub dir/hello world: md5 = 29c02b10c2784d7e8a3a7224f36682bb OK 2024/04/13 03:47:28 INFO : sub dir/hello world: Copied (new) 2024/04/13 03:47:28 DEBUG : sub dir2: Making directory 2024/04/13 03:47:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': copied 1 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:47:32 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (10.01s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:47:34 DEBUG : sub dir2: Making directory with metadata 2024/04/13 03:47:34 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/04/13 03:47:34 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:47:35 INFO : sub dir: Made directory with metadata (mtime=2024-04-13T03:47:34.287032073Z) 2024/04/13 03:47:35 DEBUG : sub dir2: Making directory with metadata 2024/04/13 03:47:37 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/04/13 03:47:37 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:47:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:47:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:47:38 DEBUG : sub dir/hello world: md5 = 4c75fa025dbc8826b59f66009d2b3e83 OK 2024/04/13 03:47:38 INFO : sub dir/hello world: Copied (new) 2024/04/13 03:47:38 INFO : sub dir/hello world: Deleted 2024/04/13 03:47:38 DEBUG : sub dir: Making directory 2024/04/13 03:47:38 DEBUG : sub dir2: Making directory 2024/04/13 03:47:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': copied 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:47:42 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (10.23s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:47:44 DEBUG : sub dir no update dir modtime: Making directory with metadata 2024/04/13 03:47:44 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2024/04/13 03:47:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:47:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:47:46 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (5.09s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:47:49 DEBUG : sub dir2: Making directory with metadata 2024/04/13 03:47:49 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/04/13 03:47:49 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/04/13 03:47:49 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:47:51 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2024/04/13 03:47:51 DEBUG : sub dir2: Making directory with metadata 2024/04/13 03:47:52 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/04/13 03:47:52 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:47:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:47:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:47:54 DEBUG : sub dir/hello world: md5 = dbdb1fac41d219148d0e8231deb143e2 OK 2024/04/13 03:47:54 INFO : sub dir/hello world: Copied (new) 2024/04/13 03:47:54 DEBUG : sub dir2: Making directory 2024/04/13 03:47:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': copied 1 directories 2024/04/13 03:47:54 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:47:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (10.47s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", 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-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:48:03 DEBUG : sub dir/hello world: md5 = 8fefc08bef0576c6d067f556c2b15082 OK 2024/04/13 03:48:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zasuval1lukozew7sazuhak7" 2024/04/13 03:48:04 DEBUG : Creating backend with remote "TestDrive:crypt/pv9l42sm3re9jl0bg5et3lrflvmmsoefdckgghmuo59u09vvona2otntihd5no6kaod7tn5p3uub6" sync_test.go:487: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8' -> Encrypted drive 'TestCryptDrive:rclone-test-zasuval1lukozew7sazuhak7' 2024/04/13 03:48:05 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:48:08 INFO : sub dir: Made directory with metadata (mtime=2024-04-13T03:48:01.203Z) 2024/04/13 03:48:08 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:48:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zasuval1lukozew7sazuhak7': Waiting for checks to finish 2024/04/13 03:48:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zasuval1lukozew7sazuhak7': Waiting for transfers to finish 2024/04/13 03:48:10 INFO : sub dir/hello world: Copied (server-side copy) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:48:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zasuval1lukozew7sazuhak7': Purge remote 2024/04/13 03:48:14 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (15.22s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:48:19 DEBUG : sub dir/hello world: md5 = 50b017c8083d6275173e107efb3e8b63 OK 2024/04/13 03:48:19 ERROR : : error listing: directory not found 2024/04/13 03:48:19 DEBUG : Local file system at /tmp/rclone2772693830: Making directory 2024/04/13 03:48:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:48:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:48:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (8.79s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:48:27 DEBUG : sub dir/hello world: md5 = 10a9c06cb5fc16b351d1f5bcd5be2f60 OK 2024/04/13 03:48:28 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:48:28 INFO : sub dir: Made directory with metadata (mtime=2024-04-13T03:48:25.245Z) 2024/04/13 03:48:28 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2024/04/13 03:48:28 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:48:28 DEBUG : Local file system at /tmp/rclone2772693830: Waiting for checks to finish 2024/04/13 03:48:28 DEBUG : Local file system at /tmp/rclone2772693830: Waiting for transfers to finish 2024/04/13 03:48:30 DEBUG : sub dir/hello world.jukimac7.partial: renamed to: sub dir/hello world 2024/04/13 03:48:30 INFO : sub dir/hello world: Copied (new) 2024/04/13 03:48:30 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:48:31 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (8.84s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:48:33 DEBUG : check sum: Need to transfer - File not found at Destination 2024/04/13 03:48:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:48:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:48:35 DEBUG : check sum: md5 = b98706198dc857f949009b9945761ced OK 2024/04/13 03:48:35 INFO : check sum: Copied (new) 2024/04/13 03:48:35 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:48:36 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2024/04/13 03:48:36 DEBUG : check sum: Size of src and dst objects identical 2024/04/13 03:48:36 DEBUG : check sum: Unchanged skipping 2024/04/13 03:48:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:48:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:48:36 DEBUG : Waiting for deletions to finish 2024/04/13 03:48:36 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (5.33s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:48:39 DEBUG : sizeonly: Need to transfer - File not found at Destination 2024/04/13 03:48:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:48:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:48:40 DEBUG : sizeonly: md5 = b9922110771bf02254cff1149645eef6 OK 2024/04/13 03:48:40 INFO : sizeonly: Copied (new) 2024/04/13 03:48:40 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:48:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:48:41 DEBUG : sizeonly: Sizes identical 2024/04/13 03:48:41 DEBUG : sizeonly: Unchanged skipping 2024/04/13 03:48:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:48:41 DEBUG : Waiting for deletions to finish 2024/04/13 03:48:41 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncSizeOnly (5.44s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:48:44 DEBUG : ignore-size: Need to transfer - File not found at Destination 2024/04/13 03:48:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:48:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:48:46 DEBUG : ignore-size: md5 = 442d8d5502649508410944302d9fb33f OK 2024/04/13 03:48:46 INFO : ignore-size: Copied (new) 2024/04/13 03:48:46 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:48:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:48:47 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:48:47 DEBUG : ignore-size: Unchanged skipping 2024/04/13 03:48:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:48:47 DEBUG : Waiting for deletions to finish 2024/04/13 03:48:47 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (5.71s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:48:51 DEBUG : existing: md5 = 5d1703fcad5916036bfb846e5d53d4ae OK 2024/04/13 03:48:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:48:52 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:48:52 DEBUG : existing: Unchanged skipping 2024/04/13 03:48:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:48:52 DEBUG : Waiting for deletions to finish 2024/04/13 03:48:52 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:48:52 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2024/04/13 03:48:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:48:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:48:54 DEBUG : existing: md5 = 887861f66409f05fc7b4d60e3a040a44 OK 2024/04/13 03:48:54 INFO : existing: Copied (replaced existing) 2024/04/13 03:48:54 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (7.27s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:48:57 DEBUG : existing: Need to transfer - File not found at Destination 2024/04/13 03:48:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:48:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:48:59 DEBUG : existing: md5 = 6dd6095e6a55d5471a60264fa2dfe5ad OK 2024/04/13 03:48:59 INFO : existing: Copied (new) 2024/04/13 03:48:59 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:48:59 DEBUG : existing: Destination exists, skipping 2024/04/13 03:48:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:48:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:48:59 DEBUG : Waiting for deletions to finish 2024/04/13 03:48:59 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (5.40s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:49:05 DEBUG : b/potato: md5 = 04708338567ce63f662747bd01baa884 OK 2024/04/13 03:49:09 DEBUG : c/non empty space: md5 = a11764e243bbe2b34c85c6ebcf8b668e OK 2024/04/13 03:49:09 DEBUG : d: Making directory 2024/04/13 03:49:11 DEBUG : a: Making directory with metadata 2024/04/13 03:49:12 INFO : a: Made directory with metadata (mtime=2024-04-13T03:49:02.594969241Z) 2024/04/13 03:49:13 INFO : c: Set directory modification time (using SetModTime) 2024/04/13 03:49:13 DEBUG : a/potato2: Need to transfer - File not found at Destination 2024/04/13 03:49:13 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:49:13 DEBUG : c/non empty space: Unchanged skipping 2024/04/13 03:49:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:49:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:49:15 DEBUG : a/potato2: md5 = 97b496ecb7e51ff2d7c1e07fb121c410 OK 2024/04/13 03:49:15 INFO : a/potato2: Copied (new) 2024/04/13 03:49:15 DEBUG : Waiting for deletions to finish 2024/04/13 03:49:16 INFO : b/potato: Deleted 2024/04/13 03:49:16 INFO : d: Removing directory 2024/04/13 03:49:17 INFO : b: Removing directory 2024/04/13 03:49:17 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2024/04/13 03:49:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:49:21 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2024/04/13 03:49:22 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (21.69s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:49:26 DEBUG : empty space: md5 = e7ab2aac93bffa77d69a23753553398d OK 2024/04/13 03:49:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:49:26 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:49:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:49:26 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2024/04/13 03:49:26 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:49:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:49:27 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:49:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:49:28 DEBUG : empty space: md5 = 18d0c34d6e809c661353e29090bc63e8 OK 2024/04/13 03:49:28 INFO : empty space: Copied (replaced existing) 2024/04/13 03:49:28 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (7.29s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", 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-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:49:34 DEBUG : foo: md5 = bf2c8f2391bdcafaa66b898a548be19d OK 2024/04/13 03:49:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:49:34 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:49:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:49:36 DEBUG : foo: md5 = cb871bf25b2db285e6a3e45121668985 OK 2024/04/13 03:49:36 INFO : foo: Copied (replaced existing) 2024/04/13 03:49:36 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (6.56s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:49:40 DEBUG : empty space: md5 = 51e650c1e3434937368ad8a41ffc4aaf OK 2024/04/13 03:49:41 DEBUG : potato: Need to transfer - File not found at Destination 2024/04/13 03:49:41 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:49:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:49:41 DEBUG : empty space: Unchanged skipping 2024/04/13 03:49:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:49:43 DEBUG : potato: md5 = bba0ff6bb9e26b28e9e6933bc545f26f OK 2024/04/13 03:49:43 INFO : potato: Copied (new) 2024/04/13 03:49:43 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (7.77s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:49:48 DEBUG : potato: md5 = bbf7e539ee15a4f8ba391bf7f68fe9da OK 2024/04/13 03:49:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:49:48 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2024/04/13 03:49:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:49:50 DEBUG : potato: md5 = f8b606c75065b4b4f581a7ada6b1a1b9 OK 2024/04/13 03:49:50 INFO : potato: Copied (replaced existing) 2024/04/13 03:49:50 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (6.36s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:49:54 DEBUG : potato: md5 = 40ae8b9b8c6e651bca371e36a82d2c76 OK 2024/04/13 03:49:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:49:55 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:49:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:49:56 DEBUG : potato: md5 = 8feba267ed8066fa451f23fcb5909c92 OK 2024/04/13 03:49:56 INFO : potato: Copied (replaced existing) 2024/04/13 03:49:56 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (6.24s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:50:00 DEBUG : potato: md5 = 4927058cce604038f029c3736ca6758b OK 2024/04/13 03:50:02 DEBUG : empty space: md5 = 1bfd3c9f7fbdf3f1de04f39386d9f57a OK 2024/04/13 03:50:03 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:50:03 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2024/04/13 03:50:03 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:50:03 DEBUG : empty space: Unchanged skipping 2024/04/13 03:50:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:50:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:50:03 DEBUG : Waiting for deletions to finish 2024/04/13 03:50:03 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (7.17s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:50:08 DEBUG : potato: md5 = 35a065ee79fc2a49f23db5d22db297dc OK 2024/04/13 03:50:10 DEBUG : empty space: md5 = d42aec911326cf7e90c8a317cb1f6304 OK 2024/04/13 03:50:10 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:50:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:50:10 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:50:10 DEBUG : empty space: Unchanged skipping 2024/04/13 03:50:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:50:12 DEBUG : potato2: md5 = 307bce7e2ab321017d5478f141ed999c OK 2024/04/13 03:50:12 INFO : potato2: Copied (new) 2024/04/13 03:50:12 DEBUG : Waiting for deletions to finish 2024/04/13 03:50:13 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (10.29s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:50:19 DEBUG : b/potato: md5 = 56297385d5d50312476aa6c4e99e5dc1 OK 2024/04/13 03:50:23 DEBUG : c/non empty space: md5 = 6f50b8604b2548ec633127ee46cffa74 OK 2024/04/13 03:50:23 DEBUG : d: Making directory 2024/04/13 03:50:24 DEBUG : d/e: Making directory 2024/04/13 03:50:26 DEBUG : a: Making directory with metadata 2024/04/13 03:50:28 INFO : a: Made directory with metadata (mtime=2024-04-13T03:50:16.494923949Z) 2024/04/13 03:50:29 INFO : c: Set directory modification time (using SetModTime) 2024/04/13 03:50:29 DEBUG : a/potato2: Need to transfer - File not found at Destination 2024/04/13 03:50:29 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:50:29 DEBUG : c/non empty space: Unchanged skipping 2024/04/13 03:50:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:50:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:50:30 DEBUG : a/potato2: md5 = 15999b5ef294bca300879d8c8c10f168 OK 2024/04/13 03:50:30 INFO : a/potato2: Copied (new) 2024/04/13 03:50:30 DEBUG : Waiting for deletions to finish 2024/04/13 03:50:31 INFO : b/potato: Deleted 2024/04/13 03:50:31 INFO : d/e: Removing directory 2024/04/13 03:50:32 INFO : d: Removing directory 2024/04/13 03:50:33 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2024/04/13 03:50:33 INFO : b: Removing directory 2024/04/13 03:50:34 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2024/04/13 03:50:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:50:38 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2024/04/13 03:50:39 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (24.47s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:50:44 DEBUG : b/potato: md5 = 65dcc4a1595ce5c9e50b448617c6751d OK 2024/04/13 03:50:47 DEBUG : c/non empty space: md5 = 6937c8f757a765df4d9b24f407e40b7f OK 2024/04/13 03:50:47 DEBUG : d: Making directory 2024/04/13 03:50:49 DEBUG : a: Making directory with metadata 2024/04/13 03:50:50 INFO : a: Made directory with metadata (mtime=2024-04-13T03:50:40.95891026Z) 2024/04/13 03:50:51 INFO : c: Set directory modification time (using SetModTime) 2024/04/13 03:50:51 DEBUG : a/potato2: Need to transfer - File not found at Destination 2024/04/13 03:50:51 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:50:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:50:51 DEBUG : c/non empty space: Unchanged skipping 2024/04/13 03:50:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:50:53 DEBUG : a/potato2: md5 = da0d5008933da4d19c6581dcc33f875f OK 2024/04/13 03:50:53 INFO : a/potato2: Copied (new) 2024/04/13 03:50:53 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': not deleting files as there were IO errors 2024/04/13 03:50:53 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:50:58 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2024/04/13 03:50:59 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2024/04/13 03:51:00 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (21.41s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:51:04 DEBUG : potato: md5 = 64ce085f234861de62f0d7d7b2643ced OK 2024/04/13 03:51:06 DEBUG : empty space: md5 = 19f666f20aa8662aba4f5fff87326b67 OK 2024/04/13 03:51:06 DEBUG : Waiting for deletions to finish 2024/04/13 03:51:06 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:51:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:51:06 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:51:06 DEBUG : empty space: Unchanged skipping 2024/04/13 03:51:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:51:07 INFO : potato: Deleted 2024/04/13 03:51:08 DEBUG : potato2: md5 = 1e7adb979ba2fd6b695c4c320ba57dc2 OK 2024/04/13 03:51:08 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (9.25s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:51:13 DEBUG : potato: md5 = 4ee2774f428fe22f3f8166b1034adef1 OK 2024/04/13 03:51:15 DEBUG : empty space: md5 = c4bb5ea233da66323fde7566f7aa1c54 OK 2024/04/13 03:51:15 DEBUG : Waiting for deletions to finish 2024/04/13 03:51:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:51:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:51:16 INFO : potato: Deleted 2024/04/13 03:51:16 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:51:16 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:51:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:51:16 DEBUG : empty space: Unchanged skipping 2024/04/13 03:51:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:51:18 DEBUG : potato2: md5 = b17d95a4fd6220d8f8f5b6b4a5613332 OK 2024/04/13 03:51:18 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (10.14s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:51:23 DEBUG : potato: md5 = 3a725a4d42cae826c71ed7790073201e OK 2024/04/13 03:51:24 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:51:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:51:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:51:26 DEBUG : potato2: md5 = 102b688969859c7a1a4b62583a5b8ac1 OK 2024/04/13 03:51:26 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (7.32s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:51:31 DEBUG : potato2: md5 = e64575635adba28d29003b5df5c07a39 OK 2024/04/13 03:51:33 DEBUG : empty space: md5 = 7bac5ff69fa78cafc7bd3b5982c7c2ba OK 2024/04/13 03:51:33 DEBUG : enormous: Excluded (Size Filter) 2024/04/13 03:51:33 DEBUG : enormous: Excluded 2024/04/13 03:51:33 DEBUG : potato2: Excluded (Size Filter) 2024/04/13 03:51:33 DEBUG : potato2: Excluded 2024/04/13 03:51:34 DEBUG : potato2: Excluded (Size Filter) 2024/04/13 03:51:34 DEBUG : potato2: Excluded 2024/04/13 03:51:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:51:34 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:51:34 DEBUG : empty space: Unchanged skipping 2024/04/13 03:51:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:51:34 DEBUG : Waiting for deletions to finish 2024/04/13 03:51:34 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:51:34 DEBUG : enormous: Excluded (Size Filter) 2024/04/13 03:51:34 DEBUG : enormous: Excluded 2024/04/13 03:51:34 DEBUG : potato2: Excluded (Size Filter) 2024/04/13 03:51:34 DEBUG : potato2: Excluded 2024/04/13 03:51:34 DEBUG : potato2: Excluded (Size Filter) 2024/04/13 03:51:34 DEBUG : potato2: Excluded 2024/04/13 03:51:34 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2024/04/13 03:51:34 DEBUG : empty space: Unchanged skipping 2024/04/13 03:51:34 DEBUG : Local file system at /tmp/rclone2772693830: Waiting for checks to finish 2024/04/13 03:51:34 DEBUG : Local file system at /tmp/rclone2772693830: Waiting for transfers to finish 2024/04/13 03:51:34 DEBUG : Waiting for deletions to finish 2024/04/13 03:51:34 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncWithExclude (9.14s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:51:40 DEBUG : potato2: md5 = c0dca98d66f261f66d9f730ef7b94ea4 OK 2024/04/13 03:51:42 DEBUG : empty space: md5 = 2c0687faddc513212f87e15cc4640fd1 OK 2024/04/13 03:51:43 DEBUG : enormous: md5 = 20a148ec08883e097b55171c576c453c OK 2024/04/13 03:51:44 DEBUG : enormous: Excluded (Size Filter) 2024/04/13 03:51:44 DEBUG : enormous: Excluded 2024/04/13 03:51:44 DEBUG : potato2: Excluded (Size Filter) 2024/04/13 03:51:44 DEBUG : potato2: Excluded 2024/04/13 03:51:44 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:51:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:51:44 DEBUG : empty space: Unchanged skipping 2024/04/13 03:51:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:51:44 DEBUG : Waiting for deletions to finish 2024/04/13 03:51:45 INFO : enormous: Deleted 2024/04/13 03:51:45 INFO : potato2: Deleted 2024/04/13 03:51:45 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:51:46 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2024/04/13 03:51:46 DEBUG : Local file system at /tmp/rclone2772693830: Waiting for checks to finish 2024/04/13 03:51:46 DEBUG : empty space: Unchanged skipping 2024/04/13 03:51:46 DEBUG : Local file system at /tmp/rclone2772693830: Waiting for transfers to finish 2024/04/13 03:51:46 DEBUG : Waiting for deletions to finish 2024/04/13 03:51:46 INFO : potato2: Deleted 2024/04/13 03:51:46 INFO : enormous: Deleted 2024/04/13 03:51:46 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (10.47s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:51:50 DEBUG : one: md5 = f447ad74467b7af143fd0848006ce1f8 OK 2024/04/13 03:51:52 DEBUG : two: md5 = 5e58f14e5f60f4342a625804b832c4fe OK 2024/04/13 03:51:54 DEBUG : three: md5 = 01c1e01a368c734226d20af90fa5fd07 OK 2024/04/13 03:51:56 DEBUG : four: md5 = 27de624e450ff392fb4b4c11c590b029 OK 2024/04/13 03:51:56 DEBUG : five: Need to transfer - File not found at Destination 2024/04/13 03:51:56 DEBUG : four: Sizes differ (src 4 vs dst 8) 2024/04/13 03:51:56 DEBUG : one: Destination is newer than source, skipping 2024/04/13 03:51:56 DEBUG : three: Sizes identical 2024/04/13 03:51:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:51:56 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2024/04/13 03:51:56 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2024/04/13 03:51:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:51:58 DEBUG : two: md5 = dccd02b38a2ee77b3e191d0f9097c46e OK 2024/04/13 03:51:58 INFO : two: Copied (replaced existing) 2024/04/13 03:51:58 DEBUG : four: md5 = 992b04672ff75cd4dba5c7e3b22fe68f OK 2024/04/13 03:51:58 INFO : four: Copied (replaced existing) 2024/04/13 03:51:58 DEBUG : five: md5 = e16c2428094891e4acdbe3e1fe544614 OK 2024/04/13 03:51:58 INFO : five: Copied (new) 2024/04/13 03:51:58 DEBUG : Waiting for deletions to finish sync_test.go:1244: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (15.23s) === 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-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" sync_test.go:1327: Can track renames: false 2024/04/13 03:52:03 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Ignoring --track-renames as the source and destination do not have a common hash 2024/04/13 03:52:04 DEBUG : potato: Need to transfer - File not found at Destination 2024/04/13 03:52:04 DEBUG : yam: Need to transfer - File not found at Destination 2024/04/13 03:52:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:52:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:52:06 DEBUG : yam: md5 = 61aff6928d009fc96e578b31978dfd46 OK 2024/04/13 03:52:06 INFO : yam: Copied (new) 2024/04/13 03:52:07 DEBUG : potato: md5 = 6da234c36d490e03d93928e6fe242877 OK 2024/04/13 03:52:07 INFO : potato: Copied (new) 2024/04/13 03:52:07 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:52:07 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Ignoring --track-renames as the source and destination do not have a common hash 2024/04/13 03:52:07 DEBUG : yaml: Need to transfer - File not found at Destination 2024/04/13 03:52:07 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:52:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:52:07 DEBUG : potato: Unchanged skipping 2024/04/13 03:52:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:52:09 DEBUG : yaml: md5 = 56bfbc4298b56a40965a8d4867458034 OK 2024/04/13 03:52:09 INFO : yaml: Copied (new) 2024/04/13 03:52:09 DEBUG : Waiting for deletions to finish 2024/04/13 03:52:10 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (10.16s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" sync_test.go:1399: Can track renames: true 2024/04/13 03:52:14 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Making map for --track-renames 2024/04/13 03:52:14 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Finished making map for --track-renames 2024/04/13 03:52:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:52:14 DEBUG : yam: Need to transfer - No matching file found at Destination 2024/04/13 03:52:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for renames to finish 2024/04/13 03:52:14 DEBUG : potato: Need to transfer - No matching file found at Destination 2024/04/13 03:52:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:52:16 DEBUG : potato: md5 = 811e0fa7d9c53cd80b46d51522a2e496 OK 2024/04/13 03:52:16 INFO : potato: Copied (new) 2024/04/13 03:52:18 DEBUG : yam: md5 = 601f6830a15bffa338de9a75863a7421 OK 2024/04/13 03:52:18 INFO : yam: Copied (new) 2024/04/13 03:52:18 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:52:18 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:52:18 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Making map for --track-renames 2024/04/13 03:52:18 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Finished making map for --track-renames 2024/04/13 03:52:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:52:18 DEBUG : potato: Unchanged skipping 2024/04/13 03:52:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for renames to finish 2024/04/13 03:52:20 INFO : yam: Moved (server-side) to: yaml 2024/04/13 03:52:20 INFO : yaml: Renamed from "yam" 2024/04/13 03:52:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:52:20 DEBUG : Waiting for deletions to finish 2024/04/13 03:52:20 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (9.56s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" sync_test.go:1438: Can track renames: true 2024/04/13 03:52:23 DEBUG : sub: Making directory with metadata 2024/04/13 03:52:25 INFO : sub: Made directory with metadata (mtime=2024-04-13T03:52:23.646858955Z) 2024/04/13 03:52:25 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Making map for --track-renames 2024/04/13 03:52:25 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Finished making map for --track-renames 2024/04/13 03:52:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:52:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for renames to finish 2024/04/13 03:52:25 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2024/04/13 03:52:25 DEBUG : potato: Need to transfer - No matching file found at Destination 2024/04/13 03:52:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:52:26 DEBUG : sub/yam: md5 = feba6b7070e109bf7097b0171f0e45af OK 2024/04/13 03:52:26 INFO : sub/yam: Copied (new) 2024/04/13 03:52:27 DEBUG : potato: md5 = 7cc86a14a30479547d34cf4b77cfe3ff OK 2024/04/13 03:52:27 INFO : potato: Copied (new) 2024/04/13 03:52:27 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:52:28 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:52:28 DEBUG : potato: Unchanged skipping 2024/04/13 03:52:28 INFO : sub: Set directory modification time (using SetModTime) 2024/04/13 03:52:29 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Making map for --track-renames 2024/04/13 03:52:29 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Finished making map for --track-renames 2024/04/13 03:52:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:52:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for renames to finish 2024/04/13 03:52:30 INFO : sub/yam: Moved (server-side) to: yam 2024/04/13 03:52:30 INFO : yam: Renamed from "sub/yam" 2024/04/13 03:52:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:52:30 DEBUG : Waiting for deletions to finish 2024/04/13 03:52:30 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (12.26s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:52:35 DEBUG : Creating backend with remote "/tmp/rclone2772693830/dir1" 2024/04/13 03:52:35 DEBUG : Config file has changed externally - reloading 2024/04/13 03:52:35 DEBUG : Creating backend with remote "/tmp/rclone2772693830/dir2" 2024/04/13 03:52:35 DEBUG : Local file system at /tmp/rclone2772693830/dir2: Using server-side directory move 2024/04/13 03:52:35 INFO : Local file system at /tmp/rclone2772693830/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2024/04/13 03:52:35 DEBUG : file1.txt: Need to transfer - File not found at Destination 2024/04/13 03:52:35 DEBUG : Local file system at /tmp/rclone2772693830/dir2: Waiting for checks to finish 2024/04/13 03:52:35 INFO : file1.txt: Moved (server-side) 2024/04/13 03:52:35 DEBUG : Local file system at /tmp/rclone2772693830/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.61s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:52:36 DEBUG : nested: Making directory with metadata 2024/04/13 03:52:38 INFO : nested: Made directory with metadata (mtime=2024-04-13T03:52:36.510853174Z) 2024/04/13 03:52:38 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:52:39 INFO : sub dir: Made directory with metadata (mtime=2024-04-13T03:52:36.510853174Z) 2024/04/13 03:52:39 DEBUG : nested/sub dir: Making directory with metadata 2024/04/13 03:52:39 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:52:40 INFO : nested/sub dir: Made directory with metadata (mtime=2024-04-13T03:52:36.510853174Z) 2024/04/13 03:52:40 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2024/04/13 03:52:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:52:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:52:41 DEBUG : sub dir/hello world: md5 = fda13caa41273ace33f9f4d69c28a9ff OK 2024/04/13 03:52:41 INFO : sub dir/hello world: Copied (new) 2024/04/13 03:52:41 INFO : sub dir/hello world: Deleted 2024/04/13 03:52:42 DEBUG : nested/sub dir/file: md5 = e2aa21d8a29db30aeeb5a491c987a5c5 OK 2024/04/13 03:52:42 INFO : nested/sub dir/file: Copied (new) 2024/04/13 03:52:42 INFO : nested/sub dir/file: Deleted 2024/04/13 03:52:42 INFO : sub dir: Removing directory 2024/04/13 03:52:42 INFO : nested/sub dir: Removing directory 2024/04/13 03:52:42 INFO : nested: Removing directory 2024/04/13 03:52:42 DEBUG : Local file system at /tmp/rclone2772693830: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:52:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/04/13 03:52:47 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2024/04/13 03:52:48 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (13.73s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:52:50 DEBUG : nested: Making directory with metadata 2024/04/13 03:52:51 INFO : nested: Made directory with metadata (mtime=2024-04-13T03:52:50.242847145Z) 2024/04/13 03:52:51 DEBUG : sub dir: Making directory with metadata 2024/04/13 03:52:53 INFO : sub dir: Made directory with metadata (mtime=2024-04-13T03:52:50.242847145Z) 2024/04/13 03:52:53 DEBUG : nested/sub dir: Making directory with metadata 2024/04/13 03:52:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/04/13 03:52:54 INFO : nested/sub dir: Made directory with metadata (mtime=2024-04-13T03:52:50.242847145Z) 2024/04/13 03:52:54 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2024/04/13 03:52:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:52:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:52:55 DEBUG : sub dir/hello world: md5 = b06faf78e310e248cc9c1faff2f708b2 OK 2024/04/13 03:52:55 INFO : sub dir/hello world: Copied (new) 2024/04/13 03:52:55 INFO : sub dir/hello world: Deleted 2024/04/13 03:52:56 DEBUG : nested/sub dir/file: md5 = 6f1518adecf9331ff307fe5a9ef5f51e OK 2024/04/13 03:52:56 INFO : nested/sub dir/file: Copied (new) 2024/04/13 03:52:56 INFO : nested/sub dir/file: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:52:59 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/04/13 03:53:01 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2024/04/13 03:53:02 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (13.83s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:53:04 DEBUG : existing: Need to transfer - File not found at Destination 2024/04/13 03:53:04 DEBUG : existing-b: Need to transfer - File not found at Destination 2024/04/13 03:53:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:53:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:53:06 DEBUG : existing: md5 = 3d3200aeeb5766e7e91b30affef31adb OK 2024/04/13 03:53:06 INFO : existing: Copied (new) 2024/04/13 03:53:06 INFO : existing: Deleted 2024/04/13 03:53:06 DEBUG : existing-b: md5 = c7e3e5b428b777de8c1b4176dd2303a7 OK 2024/04/13 03:53:06 INFO : existing-b: Copied (new) 2024/04/13 03:53:06 INFO : existing-b: Deleted 2024/04/13 03:53:07 DEBUG : existing: Destination exists, skipping 2024/04/13 03:53:07 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2024/04/13 03:53:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:53:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:53:07 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (6.74s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:53:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kigohun2bupigay3lasowoj5" 2024/04/13 03:53:10 DEBUG : Creating backend with remote "TestDrive:crypt/3acgh74ptuulhomn0vkot4htm3s1ojb9khrrrtsjm1nbmeiiqj4rb85s80i7nfrs8buvth3qkue1s" 2024/04/13 03:53:14 DEBUG : potato2: md5 = da42f39e77525f42b4a6bbee2db6afa9 OK 2024/04/13 03:53:15 DEBUG : empty space: md5 = 4e07a6be7cc99b84a1da7ebc48611a8f OK 2024/04/13 03:53:17 DEBUG : potato3: md5 = 41f92c9252c11f9aa8f3d76542b28143 OK sync_test.go:1494: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8' -> Encrypted drive 'TestCryptDrive:rclone-test-kigohun2bupigay3lasowoj5' 2024/04/13 03:53:21 DEBUG : empty space: md5 = bef56e8b4197c4a281000db43800df74 OK 2024/04/13 03:53:23 DEBUG : potato3: md5 = c6657a617a0dd9a3427d68ac556dd3e8 OK 2024/04/13 03:53:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kigohun2bupigay3lasowoj5': Using server-side directory move 2024/04/13 03:53:23 INFO : Encrypted drive 'TestCryptDrive:rclone-test-kigohun2bupigay3lasowoj5': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2024/04/13 03:53:23 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:53:23 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2024/04/13 03:53:23 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2024/04/13 03:53:23 DEBUG : empty space: Unchanged skipping 2024/04/13 03:53:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kigohun2bupigay3lasowoj5': Waiting for checks to finish 2024/04/13 03:53:24 INFO : potato3: Deleted 2024/04/13 03:53:24 INFO : empty space: Deleted 2024/04/13 03:53:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kigohun2bupigay3lasowoj5': Waiting for transfers to finish 2024/04/13 03:53:24 INFO : potato2: Moved (server-side) 2024/04/13 03:53:25 INFO : potato3: Moved (server-side) 2024/04/13 03:53:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hutejog5pozagez8dahuzoq2" 2024/04/13 03:53:26 DEBUG : Creating backend with remote "TestDrive:crypt/e0107ptobfq6o7plu79n1ejhci5l2dshlmvrc80qm3mqjjc697gmcuj7rlfj2qc88r90sfd8bulvu" 2024/04/13 03:53:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hutejog5pozagez8dahuzoq2': Using server-side directory move 2024/04/13 03:53:28 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hutejog5pozagez8dahuzoq2': Server side directory move succeeded 2024/04/13 03:53:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hutejog5pozagez8dahuzoq2': Purge remote 2024/04/13 03:53:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kigohun2bupigay3lasowoj5': Purge remote 2024/04/13 03:53:30 purge failed: directory not found --- PASS: TestServerSideMove (20.50s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:53:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yoxohow1mikuwob6qanefub9" 2024/04/13 03:53:31 DEBUG : Creating backend with remote "TestDrive:crypt/dat4r6g0r9urk70egqi4rqvoks8ko3hoqkc8vu8o5qcsatoqajp3lef21j57jgo5ocdcqgva6u8ak" 2024/04/13 03:53:34 DEBUG : potato2: md5 = 82b9bc3a09aa6aabb2e37fb6fb1befbc OK 2024/04/13 03:53:36 DEBUG : empty space: md5 = 92bb93b15fe0f7ecf130702ad5b8cc5a OK 2024/04/13 03:53:38 DEBUG : potato3: md5 = 24a30aa4488ccd0b9605902b2e94f8cd OK sync_test.go:1494: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8' -> Encrypted drive 'TestCryptDrive:rclone-test-yoxohow1mikuwob6qanefub9' 2024/04/13 03:53:41 DEBUG : empty space: md5 = a58633b58c24ba0ce4bb0af2427a1e21 OK 2024/04/13 03:53:43 DEBUG : potato3: md5 = 20b54ffe66ad6ffb87969d7b9f3b3e66 OK 2024/04/13 03:53:44 DEBUG : empty space: Excluded (Size Filter) 2024/04/13 03:53:44 DEBUG : empty space: Excluded 2024/04/13 03:53:44 DEBUG : empty space: Excluded (Size Filter) 2024/04/13 03:53:44 DEBUG : empty space: Excluded 2024/04/13 03:53:44 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:53:44 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2024/04/13 03:53:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yoxohow1mikuwob6qanefub9': Waiting for checks to finish 2024/04/13 03:53:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yoxohow1mikuwob6qanefub9': Waiting for transfers to finish 2024/04/13 03:53:45 INFO : potato3: Deleted 2024/04/13 03:53:45 INFO : potato2: Moved (server-side) 2024/04/13 03:53:46 INFO : potato3: Moved (server-side) 2024/04/13 03:53:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jagobaf8jojutaw1qiralec3" 2024/04/13 03:53:46 DEBUG : Creating backend with remote "TestDrive:crypt/0mjn780pfj4t0u0nmb236qgpt5q5hoktl470btmmhfb3ssl1bn6tipgsl6r016hngqmb2s18m1mke" 2024/04/13 03:53:48 DEBUG : empty space: Excluded (Size Filter) 2024/04/13 03:53:48 DEBUG : empty space: Excluded 2024/04/13 03:53:48 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:53:48 DEBUG : potato3: Need to transfer - File not found at Destination 2024/04/13 03:53:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jagobaf8jojutaw1qiralec3': Waiting for checks to finish 2024/04/13 03:53:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jagobaf8jojutaw1qiralec3': Waiting for transfers to finish 2024/04/13 03:53:50 INFO : potato3: Moved (server-side) 2024/04/13 03:53:51 INFO : potato2: Moved (server-side) 2024/04/13 03:53:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jagobaf8jojutaw1qiralec3': Purge remote 2024/04/13 03:53:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yoxohow1mikuwob6qanefub9': Purge remote --- PASS: TestServerSideMoveWithFilter (23.83s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:53:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobikoc2rebahul4wukugaj4" 2024/04/13 03:53:55 DEBUG : Creating backend with remote "TestDrive:crypt/bgfb5roemrph3gj3885sqsg18s0vo22blat81m2mvebstr9rmjtape6dodrmmboneidjn3fp3vd4e" 2024/04/13 03:53:58 DEBUG : potato2: md5 = 49edc9de3da57e55b0070ec8200dc404 OK 2024/04/13 03:54:00 DEBUG : empty space: md5 = 5e8241c8844c91a1b08ad3f465c83a56 OK 2024/04/13 03:54:02 DEBUG : potato3: md5 = 4cc57ffea4f7c91f4f916039d1352996 OK 2024/04/13 03:54:02 DEBUG : tomatoDir: Making directory sync_test.go:1494: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8' -> Encrypted drive 'TestCryptDrive:rclone-test-tobikoc2rebahul4wukugaj4' 2024/04/13 03:54:07 DEBUG : empty space: md5 = 22a1f30feaba286f6a8cd79c98df676f OK 2024/04/13 03:54:09 DEBUG : potato3: md5 = e930480d223c22502c5e6b6046b8d494 OK 2024/04/13 03:54:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobikoc2rebahul4wukugaj4': Using server-side directory move 2024/04/13 03:54:09 INFO : Encrypted drive 'TestCryptDrive:rclone-test-tobikoc2rebahul4wukugaj4': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2024/04/13 03:54:10 DEBUG : potato2: Need to transfer - File not found at Destination 2024/04/13 03:54:10 DEBUG : tomatoDir: Making directory with metadata 2024/04/13 03:54:11 INFO : tomatoDir: Made directory with metadata (mtime=2024-04-13T03:54:02.689Z) 2024/04/13 03:54:11 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2024/04/13 03:54:11 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2024/04/13 03:54:11 DEBUG : empty space: Unchanged skipping 2024/04/13 03:54:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobikoc2rebahul4wukugaj4': Waiting for checks to finish 2024/04/13 03:54:11 INFO : potato2: Moved (server-side) 2024/04/13 03:54:12 INFO : empty space: Deleted 2024/04/13 03:54:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobikoc2rebahul4wukugaj4': Waiting for transfers to finish 2024/04/13 03:54:12 INFO : potato3: Deleted 2024/04/13 03:54:13 INFO : potato3: Moved (server-side) 2024/04/13 03:54:13 INFO : tomatoDir: Removing directory 2024/04/13 03:54:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': deleted 1 directories 2024/04/13 03:54:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bajizeg9civajen9jepujik4" 2024/04/13 03:54:15 DEBUG : Creating backend with remote "TestDrive:crypt/pafrgsi4qgk10ega87chtk83gg4dit7ojv2fmhl5k2fbqtlsh8v5v50r4sb5lngmj3d353b6ehqkk" 2024/04/13 03:54:16 DEBUG : tomatoDir: Making directory 2024/04/13 03:54:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bajizeg9civajen9jepujik4': Using server-side directory move 2024/04/13 03:54:18 INFO : Encrypted drive 'TestCryptDrive:rclone-test-bajizeg9civajen9jepujik4': Server side directory move succeeded 2024/04/13 03:54:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bajizeg9civajen9jepujik4': Purge remote 2024/04/13 03:54:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobikoc2rebahul4wukugaj4': Purge remote 2024/04/13 03:54:20 purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (26.33s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" sync_test.go:1699: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.56s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:54:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/rclone-sync-test" 2024/04/13 03:54:22 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncOverlap (4.55s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:54:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/rclone-sync-test" 2024/04/13 03:54:26 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2024/04/13 03:54:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/rclone-sync-test-include/layer2" 2024/04/13 03:54:30 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2024/04/13 03:54:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/rclone-sync-test-ignore-file" 2024/04/13 03:54:34 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2024/04/13 03:54:39 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = e6a3ee54ebc783665fef206190f5e178 OK 2024/04/13 03:54:40 DEBUG : rclone-sync-test-ignore-file: Excluded 2024/04/13 03:54:41 DEBUG : rclone-sync-test: Excluded 2024/04/13 03:54:41 DEBUG : rclone-sync-test-include: Making directory with metadata 2024/04/13 03:54:42 INFO : rclone-sync-test-include: Made directory with metadata (mtime=2024-04-13T03:54:32.214Z) 2024/04/13 03:54:43 DEBUG : rclone-sync-test-include/layer2: Excluded 2024/04/13 03:54:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/rclone-sync-test': Waiting for checks to finish 2024/04/13 03:54:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/rclone-sync-test': Waiting for transfers to finish 2024/04/13 03:54:43 DEBUG : Waiting for deletions to finish 2024/04/13 03:54:43 INFO : There was nothing to transfer 2024/04/13 03:54:44 DEBUG : rclone-sync-test-ignore-file: Excluded 2024/04/13 03:54:44 DEBUG : rclone-sync-test: Excluded 2024/04/13 03:54:44 DEBUG : rclone-sync-test-include: Directory modification time the same (differ by 0s, within tolerance 1ms) 2024/04/13 03:54:45 DEBUG : rclone-sync-test-include/layer2: Excluded 2024/04/13 03:54:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:54:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:54:45 DEBUG : Waiting for deletions to finish 2024/04/13 03:54:45 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:54:45 DEBUG : rclone-sync-test-ignore-file: Excluded 2024/04/13 03:54:46 DEBUG : rclone-sync-test: Excluded 2024/04/13 03:54:46 DEBUG : rclone-sync-test-include: Making directory with metadata 2024/04/13 03:54:47 INFO : rclone-sync-test-include: Made directory with metadata (mtime=2024-04-13T03:54:32.214Z) 2024/04/13 03:54:48 DEBUG : rclone-sync-test-include/layer2: Excluded 2024/04/13 03:54:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/rclone-sync-test-include/layer2': Waiting for checks to finish 2024/04/13 03:54:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/rclone-sync-test-include/layer2': Waiting for transfers to finish 2024/04/13 03:54:48 DEBUG : Waiting for deletions to finish 2024/04/13 03:54:48 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:54:49 DEBUG : rclone-sync-test-ignore-file: Excluded 2024/04/13 03:54:49 DEBUG : rclone-sync-test: Excluded 2024/04/13 03:54:49 DEBUG : rclone-sync-test-include: Directory modification time the same (differ by 0s, within tolerance 1ms) 2024/04/13 03:54:50 DEBUG : rclone-sync-test-include/layer2: Excluded 2024/04/13 03:54:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 03:54:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 03:54:50 DEBUG : Waiting for deletions to finish 2024/04/13 03:54:50 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:54:51 DEBUG : : Excluded 2024/04/13 03:54:51 DEBUG : rclone-sync-test-ignore-file: Excluded 2024/04/13 03:54:51 DEBUG : rclone-sync-test: Excluded 2024/04/13 03:54:51 DEBUG : rclone-sync-test-include: Making directory with metadata 2024/04/13 03:54:53 INFO : rclone-sync-test-include: Made directory with metadata (mtime=2024-04-13T03:54:32.214Z) 2024/04/13 03:54:53 DEBUG : rclone-sync-test-include/layer2: Excluded 2024/04/13 03:54:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/rclone-sync-test-ignore-file': Waiting for checks to finish 2024/04/13 03:54:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/rclone-sync-test-ignore-file': Waiting for transfers to finish 2024/04/13 03:54:53 DEBUG : Waiting for deletions to finish 2024/04/13 03:54:53 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:54:58 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4: Rmdir: contains trashed file: "khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0" 2024/04/13 03:54:59 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2024/04/13 03:55:01 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0" 2024/04/13 03:55:01 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" 2024/04/13 03:55:02 DEBUG : i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0: Rmdir: contains trashed file: "khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0" --- PASS: TestSyncOverlapWithFilter (46.79s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:55:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst" 2024/04/13 03:55:13 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/31u3jie661vd5p8j7rtc3hgbh0" 2024/04/13 03:55:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/CompareDest" 2024/04/13 03:55:15 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/gveqi14airsml4bgu7krj116o8" 2024/04/13 03:55:17 DEBUG : one: Need to transfer - File not found at Destination 2024/04/13 03:55:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:55:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:55:20 DEBUG : one: md5 = ead8f12f3634275de407adfbc612e067 OK 2024/04/13 03:55:20 INFO : one: Copied (new) 2024/04/13 03:55:20 DEBUG : Waiting for deletions to finish 2024/04/13 03:55:22 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/04/13 03:55:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:55:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:55:24 DEBUG : one: md5 = 653c122fab43611aaa6e8b81c9907eb9 OK 2024/04/13 03:55:24 INFO : one: Copied (replaced existing) 2024/04/13 03:55:24 DEBUG : Waiting for deletions to finish 2024/04/13 03:55:26 DEBUG : dst/one: md5 = c0cd0620e1facf53578e0f01810c7fd5 OK 2024/04/13 03:55:29 DEBUG : CompareDest/one: md5 = 03e131cfeb2b92c5f8391b4a657adc3e OK 2024/04/13 03:55:30 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/04/13 03:55:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:55:31 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:55:31 DEBUG : one: Destination found in --compare-dest, skipping 2024/04/13 03:55:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:55:31 DEBUG : Waiting for deletions to finish 2024/04/13 03:55:31 INFO : There was nothing to transfer 2024/04/13 03:55:33 DEBUG : CompareDest/two: md5 = 731aede8ba3ca054d1956a1e03ee5666 OK 2024/04/13 03:55:35 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:55:35 DEBUG : two: Destination found in --compare-dest, skipping 2024/04/13 03:55:35 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/04/13 03:55:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:55:35 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:55:35 DEBUG : one: Destination found in --compare-dest, skipping 2024/04/13 03:55:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:55:35 DEBUG : Waiting for deletions to finish 2024/04/13 03:55:35 INFO : There was nothing to transfer 2024/04/13 03:55:36 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:55:36 DEBUG : two: Destination found in --compare-dest, skipping 2024/04/13 03:55:36 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/04/13 03:55:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:55:36 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:55:36 DEBUG : one: Destination found in --compare-dest, skipping 2024/04/13 03:55:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:55:36 DEBUG : Waiting for deletions to finish 2024/04/13 03:55:36 INFO : There was nothing to transfer sync_test.go:1964: No hash on uploaded file so skipping compare timestamp test 2024/04/13 03:55:38 DEBUG : two: Sizes differ (src 5 vs dst 3) 2024/04/13 03:55:38 DEBUG : two: Need to transfer - File not found at Destination 2024/04/13 03:55:38 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/04/13 03:55:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:55:38 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:55:38 DEBUG : one: Destination found in --compare-dest, skipping 2024/04/13 03:55:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:55:40 DEBUG : two: md5 = 581a5d24485cfff5078f261471ade8fa OK 2024/04/13 03:55:40 INFO : two: Copied (new) 2024/04/13 03:55:40 DEBUG : Waiting for deletions to finish 2024/04/13 03:55:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/04/13 03:55:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:55:46 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:55:46 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncCompareDest (33.78s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:55:50 DEBUG : pre-dest1/1: md5 = f23c17a7df966e39dce256b5e397c821 OK 2024/04/13 03:55:53 DEBUG : pre-dest2/2: md5 = 9cfd6755fc589c4ade927a6bf622bd54 OK 2024/04/13 03:55:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dest" 2024/04/13 03:55:54 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/rg03c1jvnehrrc617i0lnqjddc" 2024/04/13 03:55:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/pre-dest1" 2024/04/13 03:55:55 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/bbnblvh6k061ssopqrp18kd7gc" 2024/04/13 03:55:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/pre-dest2" 2024/04/13 03:55:56 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/dgicm1h6b5ejvlltm8eeif0bnk" 2024/04/13 03:55:58 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:55:58 DEBUG : 1: Destination found in --compare-dest, skipping 2024/04/13 03:55:59 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:55:59 DEBUG : 2: Destination found in --compare-dest, skipping 2024/04/13 03:55:59 DEBUG : 3: Need to transfer - File not found at Destination 2024/04/13 03:55:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dest': Waiting for checks to finish 2024/04/13 03:55:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dest': Waiting for transfers to finish 2024/04/13 03:56:02 DEBUG : 3: md5 = 29ceb835a69671e69902502dbcae37df OK 2024/04/13 03:56:02 INFO : 3: Copied (new) 2024/04/13 03:56:02 DEBUG : Waiting for deletions to finish 2024/04/13 03:56:07 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2024/04/13 03:56:08 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2024/04/13 03:56:09 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (23.96s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:56:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst" 2024/04/13 03:56:11 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/31u3jie661vd5p8j7rtc3hgbh0" 2024/04/13 03:56:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/CopyDest" 2024/04/13 03:56:13 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/d09o6po3f7bm6ce32vdgs8h9ls" 2024/04/13 03:56:15 DEBUG : one: Need to transfer - File not found at Destination 2024/04/13 03:56:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:56:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:56:18 DEBUG : one: md5 = e1c2ee212102605cc07ec36ab4df467c OK 2024/04/13 03:56:18 INFO : one: Copied (new) 2024/04/13 03:56:18 DEBUG : Waiting for deletions to finish 2024/04/13 03:56:20 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/04/13 03:56:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:56:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:56:21 DEBUG : one: md5 = b03322e3bd5fa1a0c814a772a984e2eb OK 2024/04/13 03:56:21 INFO : one: Copied (replaced existing) 2024/04/13 03:56:21 DEBUG : Waiting for deletions to finish 2024/04/13 03:56:24 DEBUG : dst/one: md5 = 19395ae1047c07395c0bc9aba9fecd7f OK 2024/04/13 03:56:27 DEBUG : CopyDest/one: md5 = 5d6e9949504da92a1938d55cd8f538a7 OK 2024/04/13 03:56:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/BackupDir" 2024/04/13 03:56:28 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/s6dbk3lfi7c9kfvo6j7bla9m0g" 2024/04/13 03:56:30 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/04/13 03:56:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:56:31 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:56:31 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/04/13 03:56:33 INFO : one: Moved (server-side) 2024/04/13 03:56:35 INFO : one: Copied (server-side copy) 2024/04/13 03:56:35 DEBUG : one: Destination found in --copy-dest, using server-side copy 2024/04/13 03:56:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:56:35 DEBUG : Waiting for deletions to finish 2024/04/13 03:56:37 DEBUG : CopyDest/two: md5 = 6baf4fcbb3539c7ead07dc486987bac0 OK 2024/04/13 03:56:39 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:56:40 INFO : two: Copied (server-side copy) 2024/04/13 03:56:40 DEBUG : two: Destination found in --copy-dest, using server-side copy 2024/04/13 03:56:40 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:56:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:56:40 DEBUG : one: Unchanged skipping 2024/04/13 03:56:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:56:40 DEBUG : Waiting for deletions to finish 2024/04/13 03:56:41 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:56:41 DEBUG : one: Unchanged skipping 2024/04/13 03:56:41 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:56:41 DEBUG : two: Unchanged skipping 2024/04/13 03:56:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:56:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:56:41 DEBUG : Waiting for deletions to finish 2024/04/13 03:56:41 INFO : There was nothing to transfer 2024/04/13 03:56:44 DEBUG : CopyDest/three: md5 = 1f5eba1287c99b90efec6cb3963a8374 OK 2024/04/13 03:56:45 DEBUG : three: Sizes differ (src 7 vs dst 5) 2024/04/13 03:56:45 DEBUG : three: Destination not found in --copy-dest 2024/04/13 03:56:45 DEBUG : three: Need to transfer - File not found at Destination 2024/04/13 03:56:45 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:56:45 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/04/13 03:56:45 DEBUG : two: Unchanged skipping 2024/04/13 03:56:45 DEBUG : one: Unchanged skipping 2024/04/13 03:56:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:56:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:56:47 DEBUG : three: md5 = 71c6bcb6af24f2b2e249b377a825922e OK 2024/04/13 03:56:47 INFO : three: Copied (new) 2024/04/13 03:56:47 DEBUG : Waiting for deletions to finish 2024/04/13 03:56:54 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2024/04/13 03:56:54 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:56:54 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/04/13 03:56:55 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/04/13 03:56:55 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2024/04/13 03:56:55 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:56:57 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (46.97s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:57:01 DEBUG : dst/one: md5 = 48efba4e1fdff17cb38a9b2c77c96e12 OK 2024/04/13 03:57:03 DEBUG : dst/two: md5 = fdc26c40d3f04b76780d5d8241a70918 OK 2024/04/13 03:57:04 DEBUG : dst/three.txt: md5 = c80fc05944a5a86cb121a3878876eb64 OK 2024/04/13 03:57:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst" 2024/04/13 03:57:05 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/31u3jie661vd5p8j7rtc3hgbh0" 2024/04/13 03:57:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/backup" 2024/04/13 03:57:06 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/1nrff024r7pq65ecp72fc28jb0" 2024/04/13 03:57:08 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/04/13 03:57:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:57:08 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:57:08 DEBUG : two: Unchanged skipping 2024/04/13 03:57:11 INFO : one: Moved (server-side) 2024/04/13 03:57:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:57:13 DEBUG : one: md5 = a49dde0f9117c786dafcb4b3695c7f14 OK 2024/04/13 03:57:13 INFO : one: Copied (new) 2024/04/13 03:57:13 DEBUG : Waiting for deletions to finish 2024/04/13 03:57:14 INFO : three.txt: Moved (server-side) 2024/04/13 03:57:14 INFO : three.txt: Moved into backup dir 2024/04/13 03:57:18 DEBUG : dst/three.txt: md5 = 77026af065cac55993010be4115e0982 OK 2024/04/13 03:57:19 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:57:19 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/04/13 03:57:19 DEBUG : two: Unchanged skipping 2024/04/13 03:57:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:57:20 INFO : one: Deleted 2024/04/13 03:57:21 INFO : one: Moved (server-side) 2024/04/13 03:57:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:57:22 DEBUG : one: md5 = 29415b4d3fbc5b74f143055d25d938b6 OK 2024/04/13 03:57:22 INFO : one: Copied (new) 2024/04/13 03:57:22 DEBUG : Waiting for deletions to finish 2024/04/13 03:57:24 INFO : three.txt: Deleted 2024/04/13 03:57:25 INFO : three.txt: Moved (server-side) 2024/04/13 03:57:25 INFO : three.txt: Moved into backup dir 2024/04/13 03:57:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:57:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/04/13 03:57:31 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2024/04/13 03:57:31 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:57:31 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:57:31 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" --- PASS: TestSyncBackupDir (34.32s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:57:35 DEBUG : dst/one: md5 = 816691ebbe1f10616394c89c26925c7e OK 2024/04/13 03:57:37 DEBUG : dst/two: md5 = ad0217035dad0f3820110eb719a88748 OK 2024/04/13 03:57:39 DEBUG : dst/three.txt: md5 = cf610840b27d2427e5ce74fc1385b090 OK 2024/04/13 03:57:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst" 2024/04/13 03:57:40 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/31u3jie661vd5p8j7rtc3hgbh0" 2024/04/13 03:57:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/backup" 2024/04/13 03:57:41 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/1nrff024r7pq65ecp72fc28jb0" 2024/04/13 03:57:43 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/04/13 03:57:43 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:57:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:57:43 DEBUG : two: Unchanged skipping 2024/04/13 03:57:46 INFO : one: Moved (server-side) to: one.bak 2024/04/13 03:57:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:57:48 DEBUG : one: md5 = e9dee0403cd9cb1cb322f2d26036b5dd OK 2024/04/13 03:57:48 INFO : one: Copied (new) 2024/04/13 03:57:48 DEBUG : Waiting for deletions to finish 2024/04/13 03:57:49 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/04/13 03:57:49 INFO : three.txt: Moved into backup dir 2024/04/13 03:57:51 DEBUG : dst/three.txt: md5 = 37a174009634eb4cf7ea1916828e1628 OK 2024/04/13 03:57:52 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/04/13 03:57:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:57:52 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:57:52 DEBUG : two: Unchanged skipping 2024/04/13 03:57:53 INFO : one.bak: Deleted 2024/04/13 03:57:55 INFO : one: Moved (server-side) to: one.bak 2024/04/13 03:57:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:57:57 DEBUG : one: md5 = 33d71bbd124f69ead054d2aec623dc70 OK 2024/04/13 03:57:57 INFO : one: Copied (new) 2024/04/13 03:57:57 DEBUG : Waiting for deletions to finish 2024/04/13 03:57:58 INFO : three.txt.bak: Deleted 2024/04/13 03:57:59 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/04/13 03:57:59 INFO : three.txt: Moved into backup dir 2024/04/13 03:58:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:58:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/04/13 03:58:05 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/04/13 03:58:05 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2024/04/13 03:58:05 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/04/13 03:58:05 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirWithSuffix (33.65s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:58:09 DEBUG : dst/one: md5 = 6ba9f0c7711e7be74868c8ccd71c5a0f OK 2024/04/13 03:58:11 DEBUG : dst/two: md5 = e0a5fa668446726970a8f20fe988162d OK 2024/04/13 03:58:13 DEBUG : dst/three.txt: md5 = d5d7f3c5210c8b9b2c63f7d538c33c6b OK 2024/04/13 03:58:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst" 2024/04/13 03:58:13 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/31u3jie661vd5p8j7rtc3hgbh0" 2024/04/13 03:58:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/backup" 2024/04/13 03:58:14 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/1nrff024r7pq65ecp72fc28jb0" 2024/04/13 03:58:16 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/04/13 03:58:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:58:16 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:16 DEBUG : two: Unchanged skipping 2024/04/13 03:58:19 INFO : one: Moved (server-side) to: one-2019-01-01 2024/04/13 03:58:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:58:21 DEBUG : one: md5 = 6e415f83f587f5a05e4cfb58d2f102c4 OK 2024/04/13 03:58:21 INFO : one: Copied (new) 2024/04/13 03:58:21 DEBUG : Waiting for deletions to finish 2024/04/13 03:58:22 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2024/04/13 03:58:22 INFO : three.txt: Moved into backup dir 2024/04/13 03:58:25 DEBUG : dst/three.txt: md5 = 868304521d3cf56bcd2f26761540e2b9 OK 2024/04/13 03:58:26 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:26 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/04/13 03:58:26 DEBUG : two: Unchanged skipping 2024/04/13 03:58:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:58:27 INFO : one-2019-01-01: Deleted 2024/04/13 03:58:28 INFO : one: Moved (server-side) to: one-2019-01-01 2024/04/13 03:58:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:58:30 DEBUG : one: md5 = a829fb287750ab0d37db8da74937d15f OK 2024/04/13 03:58:30 INFO : one: Copied (new) 2024/04/13 03:58:30 DEBUG : Waiting for deletions to finish 2024/04/13 03:58:31 INFO : three-2019-01-01.txt: Deleted 2024/04/13 03:58:32 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2024/04/13 03:58:32 INFO : three.txt: Moved into backup dir 2024/04/13 03:58:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:58:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/04/13 03:58:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2024/04/13 03:58:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2024/04/13 03:58:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2024/04/13 03:58:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (34.15s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:58:43 DEBUG : dst/one: md5 = e4f19baa9f7ec25314fa7e8de46a7757 OK 2024/04/13 03:58:45 DEBUG : dst/two: md5 = 7650d8b4c19437249b576a07e680f15b OK 2024/04/13 03:58:47 DEBUG : dst/three.txt: md5 = c4eb5c2980392dc42c554d5b8cb38aea OK 2024/04/13 03:58:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst" 2024/04/13 03:58:47 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/31u3jie661vd5p8j7rtc3hgbh0" 2024/04/13 03:58:49 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/04/13 03:58:49 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:49 DEBUG : two: Unchanged skipping 2024/04/13 03:58:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:58:50 INFO : one: Moved (server-side) to: one.bak 2024/04/13 03:58:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:58:52 DEBUG : one: md5 = 9380eb18dc7a5be203493c9fa084a5d3 OK 2024/04/13 03:58:52 INFO : one: Copied (new) 2024/04/13 03:58:52 DEBUG : Waiting for deletions to finish 2024/04/13 03:58:53 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/04/13 03:58:53 INFO : three.txt: Moved into backup dir 2024/04/13 03:58:55 DEBUG : dst/three.txt: md5 = cbc96047e3639ae877addfcefa391100 OK 2024/04/13 03:58:56 DEBUG : three.txt.bak: Excluded (Path Filter) 2024/04/13 03:58:56 DEBUG : three.txt.bak: Excluded 2024/04/13 03:58:56 DEBUG : one.bak: Excluded (Path Filter) 2024/04/13 03:58:56 DEBUG : one.bak: Excluded 2024/04/13 03:58:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for checks to finish 2024/04/13 03:58:56 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/04/13 03:58:56 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:58:56 DEBUG : two: Unchanged skipping 2024/04/13 03:58:58 INFO : one.bak: Deleted 2024/04/13 03:58:58 INFO : one: Moved (server-side) to: one.bak 2024/04/13 03:58:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst': Waiting for transfers to finish 2024/04/13 03:59:00 DEBUG : one: md5 = 0f04ec3c931276efca7ea4994318aa6e OK 2024/04/13 03:59:00 INFO : one: Copied (new) 2024/04/13 03:59:00 DEBUG : Waiting for deletions to finish 2024/04/13 03:59:01 INFO : three.txt.bak: Deleted 2024/04/13 03:59:02 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/04/13 03:59:02 INFO : three.txt: Moved into backup dir 2024/04/13 03:59:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:59:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/04/13 03:59:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2024/04/13 03:59:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2024/04/13 03:59:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/04/13 03:59:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncBackupDirSuffixOnly (28.77s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:59:12 DEBUG : dst/one: md5 = d26a64495c935f0281e65f399bd38456 OK 2024/04/13 03:59:13 DEBUG : dst/two: md5 = 92d11353d941cc1143532ed818762120 OK 2024/04/13 03:59:15 DEBUG : dst/three.txt: md5 = 62b100fe00ee71b5a9107260c45ec660 OK 2024/04/13 03:59:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst" 2024/04/13 03:59:16 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/31u3jie661vd5p8j7rtc3hgbh0" 2024/04/13 03:59:17 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/04/13 03:59:19 INFO : one: Moved (server-side) to: one.bak 2024/04/13 03:59:21 DEBUG : one: md5 = 0a52f22cb584fb14fbd6c41a07433435 OK 2024/04/13 03:59:21 INFO : one: Copied (new) 2024/04/13 03:59:21 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:59:21 DEBUG : two: Unchanged skipping 2024/04/13 03:59:21 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2024/04/13 03:59:22 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/04/13 03:59:24 DEBUG : three.txt: md5 = cf56f3680d55b6e86248b0878076459d OK 2024/04/13 03:59:24 INFO : three.txt: Copied (new) 2024/04/13 03:59:26 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/04/13 03:59:27 INFO : one.bak: Deleted 2024/04/13 03:59:28 INFO : one: Moved (server-side) to: one.bak 2024/04/13 03:59:30 DEBUG : one: md5 = 8f621d06c2a76d493569bc3310df805f OK 2024/04/13 03:59:30 INFO : one: Copied (new) 2024/04/13 03:59:30 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:59:30 DEBUG : two: Unchanged skipping 2024/04/13 03:59:30 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2024/04/13 03:59:32 INFO : three.txt.bak: Deleted 2024/04/13 03:59:33 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/04/13 03:59:34 DEBUG : three.txt: md5 = a7001b5c876560cecf38fe5369cbc28f OK 2024/04/13 03:59:34 INFO : three.txt: Copied (new) 2024/04/13 03:59:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2024/04/13 03:59:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 03:59:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/04/13 03:59:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/04/13 03:59:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/04/13 03:59:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2024/04/13 03:59:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncSuffix (32.41s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 03:59:44 DEBUG : dst/one: md5 = 6ab90bb2ce120e89a2f473e489df5331 OK 2024/04/13 03:59:46 DEBUG : dst/two: md5 = fca67bd30944cdc0d4a6dadec905281c OK 2024/04/13 03:59:48 DEBUG : dst/three.txt: md5 = e7fc6432b2373e306338bb0d1737e329 OK 2024/04/13 03:59:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8/dst" 2024/04/13 03:59:49 DEBUG : Config file has changed externally - reloading 2024/04/13 03:59:49 DEBUG : Creating backend with remote "TestDrive:crypt/sb0i11u8r65gohi0s8hngale08v5l7m9rc7er87cbnaanh4b691j7hjhgtikpq00mqifsed6dqgcu/31u3jie661vd5p8j7rtc3hgbh0" 2024/04/13 03:59:50 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/04/13 03:59:51 INFO : one: Moved (server-side) to: one-2019-01-01 2024/04/13 03:59:53 DEBUG : one: md5 = c6e09ca40ebe7b5c93cf6a21d862963a OK 2024/04/13 03:59:53 INFO : one: Copied (new) 2024/04/13 03:59:53 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 03:59:53 DEBUG : two: Unchanged skipping 2024/04/13 03:59:54 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2024/04/13 03:59:55 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2024/04/13 03:59:57 DEBUG : three.txt: md5 = 36da065e26374f9229552f3ba0e92664 OK 2024/04/13 03:59:57 INFO : three.txt: Copied (new) 2024/04/13 03:59:59 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/04/13 04:00:00 INFO : one-2019-01-01: Deleted 2024/04/13 04:00:01 INFO : one: Moved (server-side) to: one-2019-01-01 2024/04/13 04:00:03 DEBUG : one: md5 = f2c15fa6f73ec3531064b0ddc8d62366 OK 2024/04/13 04:00:03 INFO : one: Copied (new) 2024/04/13 04:00:03 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:00:03 DEBUG : two: Unchanged skipping 2024/04/13 04:00:03 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2024/04/13 04:00:05 INFO : three-2019-01-01.txt: Deleted 2024/04/13 04:00:05 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2024/04/13 04:00:08 DEBUG : three.txt: md5 = 27ebb3dc254398e8f341e5cb9257e1e7 OK 2024/04/13 04:00:08 INFO : three.txt: Copied (new) 2024/04/13 04:00:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/04/13 04:00:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2024/04/13 04:00:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2024/04/13 04:00:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/04/13 04:00:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2024/04/13 04:00:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2024/04/13 04:00:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (34.29s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 04:00:17 DEBUG : Testêé: md5 = e549f4998c6d8b259fb901c9d2761c6d OK 2024/04/13 04:00:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 04:00:18 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2024/04/13 04:00:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 04:00:19 DEBUG : Testêé: md5 = 8ef3c5090930e482bcec8feec714bb6d OK 2024/04/13 04:00:19 INFO : Testêé: Copied (replaced existing) to: Testêé 2024/04/13 04:00:19 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (5.88s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 04:00:22 DEBUG : existing: Need to transfer - File not found at Destination 2024/04/13 04:00:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 04:00:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 04:00:23 DEBUG : existing: md5 = 7265dce2ba028b29448fa93bea466122 OK 2024/04/13 04:00:23 INFO : existing: Copied (new) 2024/04/13 04:00:23 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 04:00:24 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2024/04/13 04:00:24 ERROR : existing: Source and destination exist but do not match: immutable file modified 2024/04/13 04:00:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 04:00:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 04:00:24 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': not deleting files as there were IO errors 2024/04/13 04:00:24 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncImmutable (6.30s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 04:00:29 DEBUG : EXISTING: md5 = 3040b1636132c6f5f3163d50d1513179 OK 2024/04/13 04:00:30 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:00:30 DEBUG : existing: Unchanged skipping 2024/04/13 04:00:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 04:00:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 04:00:30 DEBUG : Waiting for deletions to finish 2024/04/13 04:00:30 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (4.22s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" sync_test.go:2420: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.62s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", 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-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", 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-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" sync_test.go:2459: This test only runs on local --- PASS: TestMaxTransfer (1.73s) --- SKIP: TestMaxTransfer/Hard (0.56s) --- SKIP: TestMaxTransfer/Soft (0.57s) --- SKIP: TestMaxTransfer/Cautious (0.60s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 04:00:36 DEBUG : both0: md5 = 1018179353ffd4f33e438cf1b95a8c7f OK 2024/04/13 04:00:38 DEBUG : only0: md5 = 4455ffd5c156e8c555c41a743e7444a6 OK 2024/04/13 04:00:40 DEBUG : both1: md5 = 96659461e4dab897a59acf4f3552ad59 OK 2024/04/13 04:00:41 DEBUG : only1: md5 = 7a48deb2c9a46985f87597bf666f5be9 OK 2024/04/13 04:00:43 DEBUG : both2: md5 = f70cebadfed5369ff924fc7c88d1daeb OK 2024/04/13 04:00:45 DEBUG : only2: md5 = 7354ef00036992041ead905ec39bc90d OK 2024/04/13 04:00:47 DEBUG : both3: md5 = e57d0edca03359695ae6ad85294aeb1e OK 2024/04/13 04:00:49 DEBUG : only3: md5 = bd4561dfacd8acc17d7633ff7b12ef8c OK 2024/04/13 04:00:51 DEBUG : both4: md5 = 155c095d8f14ea04363ed734792df8e0 OK 2024/04/13 04:00:53 DEBUG : only4: md5 = f5451731f62c816b8c416bc433c1b423 OK 2024/04/13 04:00:54 DEBUG : both5: md5 = 342d646bb95c4f6d495181573029f8d1 OK 2024/04/13 04:00:56 DEBUG : only5: md5 = 77cadd7d7ac960b1cb37a121f3a3d892 OK 2024/04/13 04:00:58 DEBUG : both6: md5 = 3d3966c9832f2b7e42e9aaebb3dc2b36 OK 2024/04/13 04:01:00 DEBUG : only6: md5 = 7b6e79cae4ac3d5c48af2d2533774ea5 OK 2024/04/13 04:01:02 DEBUG : both7: md5 = b43439eb83f339083ca9bf784a683ef9 OK 2024/04/13 04:01:04 DEBUG : only7: md5 = 0ae4e4ba154138c55e1524fe2f64fe45 OK 2024/04/13 04:01:06 DEBUG : both8: md5 = ba9f5fd5257e51622fcc56bb71e18a5e OK 2024/04/13 04:01:08 DEBUG : only8: md5 = 61520447b026c96763f9f9d9bb1ab71f OK 2024/04/13 04:01:10 DEBUG : both9: md5 = b806cee7fe48acd8b2c7f03f4a4c68b5 OK 2024/04/13 04:01:12 DEBUG : only9: md5 = c93ebf0e77b625488cd772ecffa594ff OK 2024/04/13 04:01:15 DEBUG : both10: md5 = a9777e2dcaab92dc3b1b865469bc255f OK 2024/04/13 04:01:17 DEBUG : only10: md5 = 8103e97f9d4a3e8cca64fa7175aee50f OK 2024/04/13 04:01:19 DEBUG : both11: md5 = 07dbce854029a944aa3f0051bf97055e OK 2024/04/13 04:01:21 DEBUG : only11: md5 = dc5d600f3798d48bda544b9de8f8136b OK 2024/04/13 04:01:23 DEBUG : both12: md5 = bd2c227334c8e2b653d1d606d41ba65d OK 2024/04/13 04:01:25 DEBUG : only12: md5 = 5e65f472274890585a0f77710f2da7d7 OK 2024/04/13 04:01:27 DEBUG : both13: md5 = c26eef1830627762d22fa3fb4bba4320 OK 2024/04/13 04:01:29 DEBUG : only13: md5 = aedec7d2180af7631a54c3b94421150f OK 2024/04/13 04:01:31 DEBUG : both14: md5 = b4a22fb0f15c5ac19ea9e708bdca1758 OK 2024/04/13 04:01:33 DEBUG : only14: md5 = 9eda2bfd5f53a21cad732d2ad9bda248 OK 2024/04/13 04:01:35 DEBUG : both15: md5 = 7c53d2bdc4d8c9eb57f7a4de86081bf7 OK 2024/04/13 04:01:37 DEBUG : only15: md5 = 063b9c104f591d560e2f71ddcee97a80 OK 2024/04/13 04:01:39 DEBUG : both16: md5 = 1970cb625057af0fa150f2145814b103 OK 2024/04/13 04:01:41 DEBUG : only16: md5 = e6eeca35843e5ae3ac762446130749ae OK 2024/04/13 04:01:42 DEBUG : both17: md5 = df5c5deaf2f08c54320f4651da20f8ef OK 2024/04/13 04:01:44 DEBUG : only17: md5 = 81ccffc2cbceb507ed659b11b471f9a0 OK 2024/04/13 04:01:46 DEBUG : both18: md5 = cc6ed331df59f41348196d6cb99c02d3 OK 2024/04/13 04:01:48 DEBUG : only18: md5 = 5606545040b14313b6edbfd9d084a1a7 OK 2024/04/13 04:01:50 DEBUG : both19: md5 = 0ff1a1681ae1e196fa789570064c3ab5 OK 2024/04/13 04:01:52 DEBUG : only19: md5 = a7b1a08faf55d33697cff471ec485f47 OK 2024/04/13 04:01:53 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 04:01:53 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both0: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both12: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both10: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both14: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both1: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both11: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both17: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both13: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both19: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both2: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both3: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both4: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both5: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both6: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both7: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both8: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:01:53 DEBUG : both9: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both15: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both16: Unchanged skipping 2024/04/13 04:01:53 DEBUG : both18: Unchanged skipping 2024/04/13 04:01:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 04:01:53 DEBUG : Waiting for deletions to finish 2024/04/13 04:01:54 INFO : only2: Deleted 2024/04/13 04:01:54 INFO : only3: Deleted 2024/04/13 04:01:54 INFO : only18: Deleted 2024/04/13 04:01:54 INFO : only10: Deleted 2024/04/13 04:01:55 INFO : only9: Deleted 2024/04/13 04:01:55 INFO : only6: Deleted 2024/04/13 04:01:55 INFO : only19: Deleted 2024/04/13 04:01:55 INFO : only0: Deleted 2024/04/13 04:01:55 INFO : only12: Deleted 2024/04/13 04:01:56 INFO : only13: Deleted 2024/04/13 04:01:56 INFO : only14: Deleted 2024/04/13 04:01:56 INFO : only16: Deleted 2024/04/13 04:01:56 INFO : only4: Deleted 2024/04/13 04:01:56 INFO : only5: Deleted 2024/04/13 04:01:57 INFO : only11: Deleted 2024/04/13 04:01:57 INFO : only15: Deleted 2024/04/13 04:01:57 INFO : only17: Deleted 2024/04/13 04:01:57 INFO : only7: Deleted 2024/04/13 04:01:57 INFO : only8: Deleted 2024/04/13 04:01:57 INFO : only1: Deleted 2024/04/13 04:01:57 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (100.33s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 04:02:16 DEBUG : both0: md5 = a1769c3707ce1e2250e3f8bd9e97d6b2 OK 2024/04/13 04:02:18 DEBUG : only0: md5 = 9256d1fd12b43e82c19932c89fa97658 OK 2024/04/13 04:02:20 DEBUG : both1: md5 = 219dd74d0cb61f65df4be84d8b41ebd2 OK 2024/04/13 04:02:22 DEBUG : only1: md5 = 4197a5eed22b5f87a65027991e6d3ee8 OK 2024/04/13 04:02:24 DEBUG : both2: md5 = cfba6379ec3fb82e27271fa43aeb7da6 OK 2024/04/13 04:02:26 DEBUG : only2: md5 = 975bd01daecf9747d7dc63313e411ae0 OK 2024/04/13 04:02:28 DEBUG : both3: md5 = e9e136de1ca8578f75a7d218aa24ff70 OK 2024/04/13 04:02:30 DEBUG : only3: md5 = a6032a358be8119a21d5d28f2bd8e78c OK 2024/04/13 04:02:32 DEBUG : both4: md5 = 38ff55c884847bb4342c39a8f6f171de OK 2024/04/13 04:02:34 DEBUG : only4: md5 = 35cc27b9c5b89a8a95d2dafa479bd2ee OK 2024/04/13 04:02:35 DEBUG : both5: md5 = 6273dfda5a25ca3bf8de0bc93ef218ae OK 2024/04/13 04:02:37 DEBUG : only5: md5 = e9e5c9df1a200d463527cd5a174b3d03 OK 2024/04/13 04:02:39 DEBUG : both6: md5 = df4ad39a4fc00e9a39b7879a8cbd0f64 OK 2024/04/13 04:02:41 DEBUG : only6: md5 = f16ad4ff1c30f2a6e3e3a35dd6069f98 OK 2024/04/13 04:02:43 DEBUG : both7: md5 = d8db401793320bbb330d9afd9aa16139 OK 2024/04/13 04:02:45 DEBUG : only7: md5 = 623863a9bc98e0b14324c5128854cade OK 2024/04/13 04:02:47 DEBUG : both8: md5 = c541cf4df38dcd3eb7e51026a35ac60b OK 2024/04/13 04:02:49 DEBUG : only8: md5 = 7d64a1725a113abe72b2394451fdc74d OK 2024/04/13 04:02:51 DEBUG : both9: md5 = f52f16d8acb22fddc4dcd95ec0fb9972 OK 2024/04/13 04:02:52 DEBUG : only9: md5 = 9d9f04c693f07022d22c61b0a006abcf OK 2024/04/13 04:02:55 DEBUG : both10: md5 = cd6673a030afcbff6bcd95c5994035a3 OK 2024/04/13 04:02:56 DEBUG : only10: md5 = 1687b258cecc9201f03cb7da4c384532 OK 2024/04/13 04:02:58 DEBUG : both11: md5 = ac3449bcde19c8013fda17fd9af954ea OK 2024/04/13 04:03:00 DEBUG : only11: md5 = ebfb3e55e76116789f321a6a53d398c2 OK 2024/04/13 04:03:02 DEBUG : both12: md5 = 45da9d360a677ea186930764ee336132 OK 2024/04/13 04:03:04 DEBUG : only12: md5 = 2a71ca6b5f7b0a54ae987ed2d3896411 OK 2024/04/13 04:03:06 DEBUG : both13: md5 = 38fd379775948965b03f6a7c21520927 OK 2024/04/13 04:03:08 DEBUG : only13: md5 = 052b6bcd5cad260d4cb2ece9a6ae4e6a OK 2024/04/13 04:03:10 DEBUG : both14: md5 = f4b8c19da6e0969dd8422b9135e8e476 OK 2024/04/13 04:03:12 DEBUG : only14: md5 = 84419588cbb3957c9b20077a485e4cea OK 2024/04/13 04:03:13 DEBUG : both15: md5 = e6539895a3163b02bf6cd8e9cc4bb8c4 OK 2024/04/13 04:03:15 DEBUG : only15: md5 = 9aaf40a5e57ca888c669ede5bf7f9149 OK 2024/04/13 04:03:17 DEBUG : both16: md5 = 702f259d46e7abd3de832d2bb37ad9a1 OK 2024/04/13 04:03:19 DEBUG : only16: md5 = e0cc5c28380b7680ac76f89c0f04c2e7 OK 2024/04/13 04:03:21 DEBUG : both17: md5 = fad3d162aef9200719b7445b97d71ae1 OK 2024/04/13 04:03:23 DEBUG : only17: md5 = a955314b51943aa682928b49d78278ef OK 2024/04/13 04:03:25 DEBUG : both18: md5 = 7948550538b3535d509b62f3a4f2bcf6 OK 2024/04/13 04:03:27 DEBUG : only18: md5 = a1d49eb8b6cf9256467497078e09fb6c OK 2024/04/13 04:03:29 DEBUG : both19: md5 = 97f492439311eab948f796135cf112dc OK 2024/04/13 04:03:31 DEBUG : only19: md5 = b9f31fba18ad063e67884dbe056a3b76 OK 2024/04/13 04:03:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for checks to finish 2024/04/13 04:03:32 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both0: Unchanged skipping 2024/04/13 04:03:32 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both10: Unchanged skipping 2024/04/13 04:03:32 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both13: Unchanged skipping 2024/04/13 04:03:32 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both14: Unchanged skipping 2024/04/13 04:03:32 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both15: Unchanged skipping 2024/04/13 04:03:32 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both1: Unchanged skipping 2024/04/13 04:03:32 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both17: Unchanged skipping 2024/04/13 04:03:32 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both11: Unchanged skipping 2024/04/13 04:03:32 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both19: Unchanged skipping 2024/04/13 04:03:32 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both2: Unchanged skipping 2024/04/13 04:03:32 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both3: Unchanged skipping 2024/04/13 04:03:32 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both4: Unchanged skipping 2024/04/13 04:03:32 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both18: Unchanged skipping 2024/04/13 04:03:32 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both6: Unchanged skipping 2024/04/13 04:03:32 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both7: Unchanged skipping 2024/04/13 04:03:32 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both8: Unchanged skipping 2024/04/13 04:03:32 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/04/13 04:03:32 DEBUG : both9: Unchanged skipping 2024/04/13 04:03:32 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : both12: Unchanged skipping 2024/04/13 04:03:32 DEBUG : both5: Unchanged skipping 2024/04/13 04:03:32 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : both16: Unchanged skipping 2024/04/13 04:03:32 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2024/04/13 04:03:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Waiting for transfers to finish 2024/04/13 04:03:33 DEBUG : only0: md5 = 562a7e4d5799f6fe24da36d10ce52d15 OK 2024/04/13 04:03:33 INFO : only0: Copied (replaced existing) 2024/04/13 04:03:33 DEBUG : only14: md5 = bafad26fd9f1c6014b38f701940b968d OK 2024/04/13 04:03:33 INFO : only14: Copied (replaced existing) 2024/04/13 04:03:33 DEBUG : only11: md5 = a21736b4f61ea8c9b8ad7e4eed4fa9d7 OK 2024/04/13 04:03:33 INFO : only11: Copied (replaced existing) 2024/04/13 04:03:34 DEBUG : only13: md5 = 6eb3ccfc742387f000ea559095739f5a OK 2024/04/13 04:03:34 INFO : only13: Copied (replaced existing) 2024/04/13 04:03:35 DEBUG : only16: md5 = adc30b508ede5e0d3ccbd8dc5d15f9e9 OK 2024/04/13 04:03:35 INFO : only16: Copied (replaced existing) 2024/04/13 04:03:35 DEBUG : only15: md5 = 6831c298b4e958c9fb1c13b1a19e0932 OK 2024/04/13 04:03:35 INFO : only15: Copied (replaced existing) 2024/04/13 04:03:35 DEBUG : only17: md5 = a8dbd35cc258cd6d2240b4838422323a OK 2024/04/13 04:03:35 INFO : only17: Copied (replaced existing) 2024/04/13 04:03:35 DEBUG : only18: md5 = 548a40d40e52e50f4818a64a7ee4b4a5 OK 2024/04/13 04:03:35 INFO : only18: Copied (replaced existing) 2024/04/13 04:03:37 DEBUG : only2: md5 = c31725c47a3095f86bcd2c17df7f9c48 OK 2024/04/13 04:03:37 INFO : only2: Copied (replaced existing) 2024/04/13 04:03:37 DEBUG : only19: md5 = 46bfceec8959401760e1180938c75222 OK 2024/04/13 04:03:37 INFO : only19: Copied (replaced existing) 2024/04/13 04:03:37 DEBUG : only3: md5 = 05f983744ee1054befb574d7d48199cb OK 2024/04/13 04:03:37 INFO : only3: Copied (replaced existing) 2024/04/13 04:03:37 DEBUG : only4: md5 = 66c039d7686777a91e76836d7617811b OK 2024/04/13 04:03:37 INFO : only4: Copied (replaced existing) 2024/04/13 04:03:39 DEBUG : only10: md5 = 70134363625d93da5c6b516c64e50e5f OK 2024/04/13 04:03:39 INFO : only10: Copied (replaced existing) 2024/04/13 04:03:39 DEBUG : only12: md5 = 378d587246eeb1912f10f4f2f2649ca4 OK 2024/04/13 04:03:39 INFO : only12: Copied (replaced existing) 2024/04/13 04:03:39 DEBUG : only1: md5 = 50abaa3d7b9d7c42bec2ee1f7b89cbd1 OK 2024/04/13 04:03:39 INFO : only1: Copied (replaced existing) 2024/04/13 04:03:39 DEBUG : only7: md5 = fea67e2d836aec7f15d0ad69f278a585 OK 2024/04/13 04:03:39 INFO : only7: Copied (replaced existing) 2024/04/13 04:03:40 DEBUG : only9: md5 = f454b8e5fc42e2483eaa0c7631ada7ad OK 2024/04/13 04:03:40 INFO : only9: Copied (replaced existing) 2024/04/13 04:03:40 DEBUG : only6: md5 = 2549b5e42f6fb83ffd319366c2b268e3 OK 2024/04/13 04:03:40 INFO : only6: Copied (replaced existing) 2024/04/13 04:03:41 DEBUG : only8: md5 = 9d8288afcc899fc3c88b79e898b52bad OK 2024/04/13 04:03:41 INFO : only8: Copied (replaced existing) 2024/04/13 04:03:41 DEBUG : only5: md5 = dc977e139ef5922098a6db442478588f OK 2024/04/13 04:03:41 INFO : only5: Copied (replaced existing) 2024/04/13 04:03:41 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (119.94s) === RUN TestNothingToTransfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 04:04:14 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/04/13 04:04:14 DEBUG : sub dir: Making directory with metadata 2024/04/13 04:04:15 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8'", Local "Local file system at /tmp/rclone2772693830", Modify Window "1ms" 2024/04/13 04:04:42 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/04/13 04:04:43 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2024/04/13 04:04:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2024/04/13 04:04:45 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/04/13 04:04:46 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/04/13 04:04:48 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/04/13 04:04:49 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/04/13 04:04:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/04/13 04:04:51 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransfer (38.86s) PASS 2024/04/13 04:04:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zamokil8fudulup9kafataf8': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 18m30.042837701s (try 1/5)