"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5) 2022/01/09 05:02:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0" 2022/01/09 05:02:15 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2022/01/09 05:02:15 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c" 2022/01/09 05:02:15 DEBUG : TestDrive: Loaded invalid token from config file - ignoring 2022/01/09 05:02:15 DEBUG : Saving config "token" in section "TestDrive" of the config file 2022/01/09 05:02:15 DEBUG : TestDrive: Saved new token in config file 2022/01/09 05:02:17 DEBUG : Creating backend with remote "/tmp/rclone1389598915" 2022/01/09 05:02:17 DEBUG : Config file has changed externaly - reloading === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.07s) === 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:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:02:19 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2022/01/09 05:02:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:02:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish --- PASS: TestCopyWithDryRun (2.50s) === RUN TestCopy run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:02:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:02:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:02:23 DEBUG : sub dir/hello world: md5 = 51f5a255eec3c927bcb549e6aeb6efec OK 2022/01/09 05:02:23 INFO : sub dir/hello world: Copied (new) 2022/01/09 05:02:26 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (6.84s) === RUN TestCopyMissingDirectory run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:02:26 DEBUG : Creating backend with remote "/non-existing" 2022/01/09 05:02:26 DEBUG : Config file has changed externaly - reloading 2022/01/09 05:02:27 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2022/01/09 05:02:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:02:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish --- PASS: TestCopyMissingDirectory (0.83s) === RUN TestCopyNoTraverse run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:02:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:02:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:02:31 DEBUG : sub dir/hello world: md5 = 698dabfcef33e758867577fdaa1e13b6 OK 2022/01/09 05:02:31 INFO : sub dir/hello world: Copied (new) 2022/01/09 05:02:33 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (6.64s) === RUN TestCopyCheckFirst run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:02:34 INFO : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Running all checks before starting transfers 2022/01/09 05:02:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:02:34 INFO : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Checks finished, now starting transfers 2022/01/09 05:02:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:02:37 DEBUG : sub dir/hello world: md5 = 0482cb5da060d08d2dde4f3d15b78c5d OK 2022/01/09 05:02:37 INFO : sub dir/hello world: Copied (new) 2022/01/09 05:02:40 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (7.23s) === RUN TestSyncNoTraverse run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:02:41 ERROR : Ignoring --no-traverse with sync 2022/01/09 05:02:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:02:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:02:44 DEBUG : sub dir/hello world: md5 = c4a9a6989c50689961158ec69e114088 OK 2022/01/09 05:02:44 INFO : sub dir/hello world: Copied (new) 2022/01/09 05:02:44 DEBUG : Waiting for deletions to finish 2022/01/09 05:02:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (6.21s) === RUN TestCopyWithDepth run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:02:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:02:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:02:49 DEBUG : hello world2: md5 = 732c111171606f278ed737a6ff4cc7cd OK 2022/01/09 05:02:49 INFO : hello world2: Copied (new) --- PASS: TestCopyWithDepth (3.78s) === RUN TestCopyWithFilesFrom run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:02:51 DEBUG : hello world2: Excluded 2022/01/09 05:02:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:02:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:02:53 DEBUG : potato2: md5 = fba1277adda6cfb8589256456689361a OK 2022/01/09 05:02:53 INFO : potato2: Copied (new) --- PASS: TestCopyWithFilesFrom (3.49s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:02:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:02:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:02:57 DEBUG : potato2: md5 = 3b93cd9913596b3a0b38204478265018 OK 2022/01/09 05:02:57 INFO : potato2: Copied (new) --- PASS: TestCopyWithFilesFromAndNoTraverse (3.60s) === RUN TestCopyEmptyDirectories run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:02:58 DEBUG : sub dir2: Making directory 2022/01/09 05:02:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:02:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:03:02 DEBUG : sub dir/hello world: md5 = ee284b4bc85e015e58960e79ea3c5e64 OK 2022/01/09 05:03:02 INFO : sub dir/hello world: Copied (new) 2022/01/09 05:03:02 DEBUG : sub dir2: Making directory 2022/01/09 05:03:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': copied 1 directories 2022/01/09 05:03:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (8.62s) === RUN TestMoveEmptyDirectories run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:03:07 DEBUG : sub dir2: Making directory 2022/01/09 05:03:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:03:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:03:10 DEBUG : sub dir/hello world: md5 = 49fc71b2cc90fbb4e61e15d336894e81 OK 2022/01/09 05:03:10 INFO : sub dir/hello world: Copied (new) 2022/01/09 05:03:10 INFO : sub dir/hello world: Deleted 2022/01/09 05:03:10 DEBUG : sub dir: Making directory 2022/01/09 05:03:10 DEBUG : sub dir2: Making directory 2022/01/09 05:03:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': copied 2 directories 2022/01/09 05:03:14 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (8.68s) === RUN TestSyncEmptyDirectories run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:03:16 DEBUG : sub dir2: Making directory 2022/01/09 05:03:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:03:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:03:18 DEBUG : sub dir/hello world: md5 = 63503be9932121248b71933055d17afd OK 2022/01/09 05:03:18 INFO : sub dir/hello world: Copied (new) 2022/01/09 05:03:18 DEBUG : sub dir2: Making directory 2022/01/09 05:03:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': copied 1 directories 2022/01/09 05:03:20 DEBUG : Waiting for deletions to finish 2022/01/09 05:03:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (8.40s) === RUN TestServerSideCopy run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:03:27 DEBUG : sub dir/hello world: md5 = 5a568be0aa3326a24359e18321aae4b3 OK 2022/01/09 05:03:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jodujuk4gevixek1redicev3" 2022/01/09 05:03:27 DEBUG : Creating backend with remote "TestDrive:crypt/668ime118oqr5dac1nsggg2h6sl980tkqit6qdpv3i77kcbm1kgvmjvs20lac87k1sq8mqds1lf2a" sync_test.go:275: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0' -> Encrypted drive 'TestCryptDrive:rclone-test-jodujuk4gevixek1redicev3' 2022/01/09 05:03:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jodujuk4gevixek1redicev3': Waiting for checks to finish 2022/01/09 05:03:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jodujuk4gevixek1redicev3': Waiting for transfers to finish 2022/01/09 05:03:33 INFO : sub dir/hello world: Copied (server-side copy) 2022/01/09 05:03:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jodujuk4gevixek1redicev3': Purge remote 2022/01/09 05:03:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (13.05s) === RUN TestCopyAfterDelete run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:03:40 DEBUG : sub dir/hello world: md5 = 6a24b3f6a0114e3afc6c91a4d82a48e3 OK 2022/01/09 05:03:40 ERROR : : error listing: directory not found 2022/01/09 05:03:40 DEBUG : Local file system at /tmp/rclone1389598915: Making directory 2022/01/09 05:03:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:03:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:03:43 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (6.98s) === RUN TestCopyRedownload run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:03:47 DEBUG : sub dir/hello world: md5 = e79e7ebfcf319c83dc3c0919b177dcc0 OK 2022/01/09 05:03:48 DEBUG : Local file system at /tmp/rclone1389598915: Waiting for checks to finish 2022/01/09 05:03:48 DEBUG : Local file system at /tmp/rclone1389598915: Waiting for transfers to finish 2022/01/09 05:03:49 INFO : sub dir/hello world: Copied (new) 2022/01/09 05:03:51 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (8.14s) === RUN TestSyncBasedOnCheckSum run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:03:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:03:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:03:54 DEBUG : check sum: md5 = b7e4cc99e09e7fb8a2d072246da9bcd5 OK 2022/01/09 05:03:54 INFO : check sum: Copied (new) 2022/01/09 05:03:54 DEBUG : Waiting for deletions to finish 2022/01/09 05:03:55 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2022/01/09 05:03:55 DEBUG : check sum: Size of src and dst objects identical 2022/01/09 05:03:55 DEBUG : check sum: Unchanged skipping 2022/01/09 05:03:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:03:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:03:55 DEBUG : Waiting for deletions to finish 2022/01/09 05:03:55 INFO : There was nothing to transfer --- PASS: TestSyncBasedOnCheckSum (4.27s) === RUN TestSyncSizeOnly run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:03:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:03:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:03:58 DEBUG : sizeonly: md5 = c29cc446d0bbc2c5dba8562fbccb98c6 OK 2022/01/09 05:03:58 INFO : sizeonly: Copied (new) 2022/01/09 05:03:58 DEBUG : Waiting for deletions to finish 2022/01/09 05:03:59 DEBUG : sizeonly: Sizes identical 2022/01/09 05:03:59 DEBUG : sizeonly: Unchanged skipping 2022/01/09 05:03:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:03:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:03:59 DEBUG : Waiting for deletions to finish 2022/01/09 05:03:59 INFO : There was nothing to transfer --- PASS: TestSyncSizeOnly (3.93s) === RUN TestSyncIgnoreSize run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:04:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:04:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:04:02 DEBUG : ignore-size: md5 = 17b9326d150aa45f4b98e1ced30fdb48 OK 2022/01/09 05:04:02 INFO : ignore-size: Copied (new) 2022/01/09 05:04:02 DEBUG : Waiting for deletions to finish 2022/01/09 05:04:03 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:04:03 DEBUG : ignore-size: Unchanged skipping 2022/01/09 05:04:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:04:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:04:03 DEBUG : Waiting for deletions to finish 2022/01/09 05:04:03 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreSize (4.32s) === RUN TestSyncIgnoreTimes run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:04:06 DEBUG : existing: md5 = 56f48e06093355837526bb1a80563b48 OK 2022/01/09 05:04:07 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:04:07 DEBUG : existing: Unchanged skipping 2022/01/09 05:04:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:04:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:04:07 DEBUG : Waiting for deletions to finish 2022/01/09 05:04:07 INFO : There was nothing to transfer 2022/01/09 05:04:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:04:07 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2022/01/09 05:04:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:04:09 DEBUG : existing: md5 = 73fc64dec565ed340b55493e74d9f2b5 OK 2022/01/09 05:04:09 INFO : existing: Copied (replaced existing) 2022/01/09 05:04:09 DEBUG : Waiting for deletions to finish --- PASS: TestSyncIgnoreTimes (5.61s) === RUN TestSyncIgnoreExisting run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:04:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:04:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:04:12 DEBUG : existing: md5 = bfcac569c19e3dc613332964ce09091c OK 2022/01/09 05:04:12 INFO : existing: Copied (new) 2022/01/09 05:04:12 DEBUG : Waiting for deletions to finish 2022/01/09 05:04:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:04:13 DEBUG : existing: Destination exists, skipping 2022/01/09 05:04:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:04:13 DEBUG : Waiting for deletions to finish 2022/01/09 05:04:13 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreExisting (4.29s) === RUN TestSyncIgnoreErrors run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:04:17 DEBUG : b/potato: md5 = 74cb768132f0f4629d7c6d8a66d7432e OK 2022/01/09 05:04:20 DEBUG : c/non empty space: md5 = b29130125763dc534aaf65cf04257a6f OK 2022/01/09 05:04:20 DEBUG : d: Making directory 2022/01/09 05:04:23 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:04:23 DEBUG : c/non empty space: Unchanged skipping 2022/01/09 05:04:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:04:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:04:25 DEBUG : a/potato2: md5 = e2adc5c64470a8c285d239c9b147736d OK 2022/01/09 05:04:25 INFO : a/potato2: Copied (new) 2022/01/09 05:04:25 DEBUG : Waiting for deletions to finish 2022/01/09 05:04:26 INFO : b/potato: Deleted 2022/01/09 05:04:26 INFO : d: Removing directory 2022/01/09 05:04:27 INFO : b: Removing directory 2022/01/09 05:04:27 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2022/01/09 05:04:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': deleted 2 directories 2022/01/09 05:04:31 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2022/01/09 05:04:32 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (18.34s) === RUN TestSyncAfterChangingModtimeOnly run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:04:35 DEBUG : empty space: md5 = 2c4a7c0c85223e04a301bfb0e860bc46 OK 2022/01/09 05:04:35 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 2022/01/09 05:04:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:04:35 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2022/01/09 05:04:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:04:35 DEBUG : Waiting for deletions to finish 2022/01/09 05:04:36 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 2022/01/09 05:04:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:04:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:04:38 DEBUG : empty space: md5 = 003dee6eddbedb68275fccf604ea4579 OK 2022/01/09 05:04:38 INFO : empty space: Copied (replaced existing) 2022/01/09 05:04:38 DEBUG : Waiting for deletions to finish --- PASS: TestSyncAfterChangingModtimeOnly (6.47s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" sync_test.go:577: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.53s) === RUN TestSyncDoesntUpdateModtime run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:04:42 DEBUG : foo: md5 = aa8e635beb2a9286322b9222e0748419 OK 2022/01/09 05:04:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:04:42 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 2022/01/09 05:04:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:04:44 DEBUG : foo: md5 = 42873b3e26c306f1639b25a4a520a6aa OK 2022/01/09 05:04:44 INFO : foo: Copied (replaced existing) 2022/01/09 05:04:44 DEBUG : Waiting for deletions to finish --- PASS: TestSyncDoesntUpdateModtime (5.19s) === RUN TestSyncAfterAddingAFile run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:04:47 DEBUG : empty space: md5 = af942e8624884230b09f741caa52222f OK 2022/01/09 05:04:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:04:47 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:04:47 DEBUG : empty space: Unchanged skipping 2022/01/09 05:04:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:04:49 DEBUG : potato: md5 = f7672aefe9a8d3046a917641d1fffb79 OK 2022/01/09 05:04:49 INFO : potato: Copied (new) 2022/01/09 05:04:49 DEBUG : Waiting for deletions to finish --- PASS: TestSyncAfterAddingAFile (6.04s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:04:53 DEBUG : potato: md5 = b4c5cd968b84bc5d9c462963da605f45 OK 2022/01/09 05:04:53 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2022/01/09 05:04:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:04:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:04:55 DEBUG : potato: md5 = bb2f7f346633507de5385c367d5d7d82 OK 2022/01/09 05:04:55 INFO : potato: Copied (replaced existing) 2022/01/09 05:04:55 DEBUG : Waiting for deletions to finish --- PASS: TestSyncAfterChangingFilesSizeOnly (5.21s) === RUN TestSyncAfterChangingContentsOnly run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:04:58 DEBUG : potato: md5 = 0b8bd50c05cf0c85dddd88507ff6fe6e OK 2022/01/09 05:04:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:04:59 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 2022/01/09 05:04:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:05:00 DEBUG : potato: md5 = 2581f817e12de38ec5dff09988523450 OK 2022/01/09 05:05:00 INFO : potato: Copied (replaced existing) 2022/01/09 05:05:00 DEBUG : Waiting for deletions to finish --- PASS: TestSyncAfterChangingContentsOnly (5.37s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:05:03 DEBUG : potato: md5 = b7c411f89a3c27a14ac237175462fed2 OK 2022/01/09 05:05:05 DEBUG : empty space: md5 = c8ebf5cb01536b387f691dfd7a8b7c3a OK 2022/01/09 05:05:05 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2022/01/09 05:05:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:05:05 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:05:05 DEBUG : empty space: Unchanged skipping 2022/01/09 05:05:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:05:05 DEBUG : Waiting for deletions to finish 2022/01/09 05:05:05 NOTICE: potato: Skipped delete as --dry-run is set (size 21) --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.95s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:05:09 DEBUG : potato: md5 = 59757f3fa4ce065de1740319eab59bf0 OK 2022/01/09 05:05:11 DEBUG : empty space: md5 = 420ec5db0ffceeff790e6ae037262ae7 OK 2022/01/09 05:05:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:05:12 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:05:12 DEBUG : empty space: Unchanged skipping 2022/01/09 05:05:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:05:13 DEBUG : potato2: md5 = 70119a758246bc9fbeb0b1cda713d361 OK 2022/01/09 05:05:13 INFO : potato2: Copied (new) 2022/01/09 05:05:13 DEBUG : Waiting for deletions to finish 2022/01/09 05:05:14 INFO : potato: Deleted --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.42s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:05:19 DEBUG : b/potato: md5 = c187a36975f449a9380c57f1697999af OK 2022/01/09 05:05:22 DEBUG : c/non empty space: md5 = 6a7f41b7a77c1b2933047304b7579ec9 OK 2022/01/09 05:05:22 DEBUG : d: Making directory 2022/01/09 05:05:23 DEBUG : d/e: Making directory 2022/01/09 05:05:25 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:05:25 DEBUG : pacer: Rate limited, increasing sleep to 1.609195719s 2022/01/09 05:05:25 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:05:25 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:05:25 DEBUG : c/non empty space: Unchanged skipping 2022/01/09 05:05:25 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:05:25 DEBUG : pacer: Rate limited, increasing sleep to 1.861811021s 2022/01/09 05:05:27 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:05:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:05:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:05:31 DEBUG : a/potato2: md5 = 9c5e789b8cfe3dcb89ac9aa2da7a2dfd OK 2022/01/09 05:05:31 INFO : a/potato2: Copied (new) 2022/01/09 05:05:31 DEBUG : Waiting for deletions to finish 2022/01/09 05:05:32 INFO : b/potato: Deleted 2022/01/09 05:05:32 INFO : d/e: Removing directory 2022/01/09 05:05:33 INFO : d: Removing directory 2022/01/09 05:05:33 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2022/01/09 05:05:34 INFO : b: Removing directory 2022/01/09 05:05:34 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2022/01/09 05:05:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': deleted 3 directories 2022/01/09 05:05:36 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:05:36 DEBUG : pacer: Rate limited, increasing sleep to 1.596210917s 2022/01/09 05:05:37 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:05:37 DEBUG : pacer: Rate limited, increasing sleep to 2.5839496s 2022/01/09 05:05:39 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:05:42 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2022/01/09 05:05:43 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (27.48s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:05:46 DEBUG : b/potato: md5 = 9e1225e593271dea3eed6ca39d83f163 OK 2022/01/09 05:05:49 DEBUG : c/non empty space: md5 = 3bdb0542fe12165fda41af95d9ca096c OK 2022/01/09 05:05:49 DEBUG : d: Making directory 2022/01/09 05:05:49 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:05:49 DEBUG : pacer: Rate limited, increasing sleep to 1.377559599s 2022/01/09 05:05:50 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:05:52 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:05:52 DEBUG : c/non empty space: Unchanged skipping 2022/01/09 05:05:53 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:05:53 DEBUG : pacer: Rate limited, increasing sleep to 1.132007425s 2022/01/09 05:05:54 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:05:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:05:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:05:55 DEBUG : a/potato2: md5 = 294c7fec359fefa76908a2f6e602e6f1 OK 2022/01/09 05:05:55 INFO : a/potato2: Copied (new) 2022/01/09 05:05:55 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': not deleting files as there were IO errors 2022/01/09 05:05:55 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': not deleting directories as there were IO errors 2022/01/09 05:05:58 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:05:58 DEBUG : pacer: Rate limited, increasing sleep to 1.041883421s 2022/01/09 05:05:59 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:05:59 DEBUG : pacer: Rate limited, increasing sleep to 2.028698837s 2022/01/09 05:06:00 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:06:02 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2022/01/09 05:06:03 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2022/01/09 05:06:04 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (21.36s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:06:07 DEBUG : potato: md5 = 25b9ad8c43a8e4780612211f36aee2fe OK 2022/01/09 05:06:09 DEBUG : empty space: md5 = 4653e63b42c238f3b0364f4066302e34 OK 2022/01/09 05:06:09 DEBUG : Waiting for deletions to finish 2022/01/09 05:06:09 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:06:09 DEBUG : empty space: Unchanged skipping 2022/01/09 05:06:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:06:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:06:09 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:06:09 DEBUG : pacer: Rate limited, increasing sleep to 1.919580965s 2022/01/09 05:06:09 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:06:10 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:06:10 DEBUG : pacer: Rate limited, increasing sleep to 1.965923809s 2022/01/09 05:06:13 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:06:13 DEBUG : potato2: md5 = 383b03c0cc7d43c6f12f6fb2252dd8ce OK 2022/01/09 05:06:13 INFO : potato2: Copied (new) 2022/01/09 05:06:14 INFO : potato: Deleted --- PASS: TestSyncDeleteDuring (11.22s) === RUN TestSyncDeleteBefore run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:06:18 DEBUG : potato: md5 = 3ede203c4d4d1b6a5713d79647ad6d18 OK 2022/01/09 05:06:19 DEBUG : empty space: md5 = 92ff5cc1a9282ec5884af86993f42bf2 OK 2022/01/09 05:06:20 DEBUG : Waiting for deletions to finish 2022/01/09 05:06:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:06:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:06:21 INFO : potato: Deleted 2022/01/09 05:06:21 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:06:21 DEBUG : empty space: Unchanged skipping 2022/01/09 05:06:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:06:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:06:23 DEBUG : potato2: md5 = bdc410f167a089b4693f39e70cc766f7 OK 2022/01/09 05:06:23 INFO : potato2: Copied (new) --- PASS: TestSyncDeleteBefore (8.84s) === RUN TestCopyDeleteBefore run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:06:27 DEBUG : potato: md5 = 9fcfde3e3f5e7f9ddd4ac13c6186cc12 OK 2022/01/09 05:06:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:06:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:06:29 DEBUG : potato2: md5 = d01ef3db829bcc015523524df77a7b55 OK 2022/01/09 05:06:29 INFO : potato2: Copied (new) --- PASS: TestCopyDeleteBefore (5.95s) === RUN TestSyncWithExclude run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:06:33 DEBUG : potato2: md5 = 46d3434aea03a96766fcb93ebcedc2a7 OK 2022/01/09 05:06:34 DEBUG : empty space: md5 = a2da90e51f6467aaa660dcbd912dba09 OK 2022/01/09 05:06:34 DEBUG : enormous: Excluded 2022/01/09 05:06:34 DEBUG : potato2: Excluded 2022/01/09 05:06:35 DEBUG : potato2: Excluded 2022/01/09 05:06:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:06:35 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:06:35 DEBUG : empty space: Unchanged skipping 2022/01/09 05:06:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:06:35 DEBUG : Waiting for deletions to finish 2022/01/09 05:06:35 INFO : There was nothing to transfer 2022/01/09 05:06:35 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:06:35 DEBUG : pacer: Rate limited, increasing sleep to 1.593364765s 2022/01/09 05:06:35 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:06:35 DEBUG : pacer: Rate limited, increasing sleep to 2.845625918s 2022/01/09 05:06:37 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:06:37 DEBUG : enormous: Excluded 2022/01/09 05:06:37 DEBUG : potato2: Excluded 2022/01/09 05:06:40 DEBUG : potato2: Excluded 2022/01/09 05:06:40 DEBUG : Local file system at /tmp/rclone1389598915: Waiting for checks to finish 2022/01/09 05:06:40 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2022/01/09 05:06:40 DEBUG : empty space: Unchanged skipping 2022/01/09 05:06:40 DEBUG : Local file system at /tmp/rclone1389598915: Waiting for transfers to finish 2022/01/09 05:06:40 DEBUG : Waiting for deletions to finish 2022/01/09 05:06:40 INFO : There was nothing to transfer --- PASS: TestSyncWithExclude (10.71s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:06:43 DEBUG : potato2: md5 = 756c4e46fa24c808e9c3cb4e2627e71c OK 2022/01/09 05:06:45 DEBUG : empty space: md5 = 4cd15f91b8ada4fc8ae09ff6d7414def OK 2022/01/09 05:06:47 DEBUG : enormous: md5 = e463bf1e84381efca6702bcd7c74d610 OK 2022/01/09 05:06:47 DEBUG : enormous: Excluded 2022/01/09 05:06:47 DEBUG : potato2: Excluded 2022/01/09 05:06:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:06:48 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:06:48 DEBUG : empty space: Unchanged skipping 2022/01/09 05:06:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:06:48 DEBUG : Waiting for deletions to finish 2022/01/09 05:06:48 INFO : enormous: Deleted 2022/01/09 05:06:48 INFO : potato2: Deleted 2022/01/09 05:06:48 INFO : There was nothing to transfer 2022/01/09 05:06:49 DEBUG : Local file system at /tmp/rclone1389598915: Waiting for checks to finish 2022/01/09 05:06:49 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2022/01/09 05:06:49 DEBUG : empty space: Unchanged skipping 2022/01/09 05:06:49 DEBUG : Local file system at /tmp/rclone1389598915: Waiting for transfers to finish 2022/01/09 05:06:49 DEBUG : Waiting for deletions to finish 2022/01/09 05:06:49 INFO : enormous: Deleted 2022/01/09 05:06:49 INFO : potato2: Deleted 2022/01/09 05:06:49 INFO : There was nothing to transfer --- PASS: TestSyncWithExcludeAndDeleteExcluded (8.37s) === RUN TestSyncWithUpdateOlder run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:06:52 DEBUG : one: md5 = 7d2685fd2c82718b241b7f5b98f85f13 OK 2022/01/09 05:06:53 DEBUG : two: md5 = a830603a17042e6514beb08ad9db97ba OK 2022/01/09 05:06:55 DEBUG : three: md5 = 3842622ca03351cf8f1a9f48b521a002 OK 2022/01/09 05:06:57 DEBUG : four: md5 = 2ac827072a2c5b72969008e12309623a OK 2022/01/09 05:06:57 DEBUG : four: Sizes differ (src 4 vs dst 8) 2022/01/09 05:06:57 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2022/01/09 05:06:57 DEBUG : three: Sizes identical 2022/01/09 05:06:57 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2022/01/09 05:06:57 DEBUG : one: Destination is newer than source, skipping 2022/01/09 05:06:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:06:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:06:57 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:06:57 DEBUG : pacer: Rate limited, increasing sleep to 1.195409286s 2022/01/09 05:06:58 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:06:58 DEBUG : four: md5 = 985f64bfae67305a9b0d8de32d96229b OK 2022/01/09 05:06:58 INFO : four: Copied (replaced existing) 2022/01/09 05:06:59 DEBUG : two: md5 = ec9e1c6787fd416012ce9f3d4d69ea2b OK 2022/01/09 05:06:59 INFO : two: Copied (replaced existing) 2022/01/09 05:07:00 DEBUG : five: md5 = 0fe293bb0438d7d6156b5ac8ac50ed2f OK 2022/01/09 05:07:00 INFO : five: Copied (new) 2022/01/09 05:07:00 DEBUG : Waiting for deletions to finish sync_test.go:992: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (14.44s) === RUN TestSyncWithMaxDuration sync_test.go:1009: Skipping test on non local remote --- SKIP: TestSyncWithMaxDuration (0.00s) === RUN TestSyncWithTrackRenames run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" sync_test.go:1058: Can track renames: false 2022/01/09 05:07:04 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Ignoring --track-renames as the source and destination do not have a common hash 2022/01/09 05:07:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:07:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:07:06 DEBUG : yam: md5 = 2ca2a7126b865c119fa1bf71505520a8 OK 2022/01/09 05:07:06 INFO : yam: Copied (new) 2022/01/09 05:07:07 DEBUG : potato: md5 = 8ef89410e47cce992014b81fec655710 OK 2022/01/09 05:07:07 INFO : potato: Copied (new) 2022/01/09 05:07:07 DEBUG : Waiting for deletions to finish 2022/01/09 05:07:07 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Ignoring --track-renames as the source and destination do not have a common hash 2022/01/09 05:07:07 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:07:07 DEBUG : potato: Unchanged skipping 2022/01/09 05:07:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:07:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:07:09 DEBUG : yaml: md5 = 9c19c8de76dc429eaf13fe5c226bf538 OK 2022/01/09 05:07:09 INFO : yaml: Copied (new) 2022/01/09 05:07:09 DEBUG : Waiting for deletions to finish 2022/01/09 05:07:10 INFO : yam: Deleted --- PASS: TestSyncWithTrackRenames (7.59s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" sync_test.go:1127: Can track renames: true 2022/01/09 05:07:12 INFO : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Making map for --track-renames 2022/01/09 05:07:12 INFO : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Finished making map for --track-renames 2022/01/09 05:07:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:07:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for renames to finish 2022/01/09 05:07:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:07:14 DEBUG : potato: md5 = 3d400571f384654ee4a652570b141fce OK 2022/01/09 05:07:14 INFO : potato: Copied (new) 2022/01/09 05:07:14 DEBUG : yam: md5 = aeb719a27374527bcbcf92053709491d OK 2022/01/09 05:07:14 INFO : yam: Copied (new) 2022/01/09 05:07:14 DEBUG : Waiting for deletions to finish 2022/01/09 05:07:15 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:07:15 DEBUG : potato: Unchanged skipping 2022/01/09 05:07:15 INFO : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Making map for --track-renames 2022/01/09 05:07:15 INFO : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Finished making map for --track-renames 2022/01/09 05:07:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:07:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for renames to finish 2022/01/09 05:07:15 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:07:15 DEBUG : pacer: Rate limited, increasing sleep to 1.642194172s 2022/01/09 05:07:16 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:07:16 INFO : yam: Moved (server-side) to: yaml 2022/01/09 05:07:16 INFO : yaml: Renamed from "yam" 2022/01/09 05:07:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:07:16 DEBUG : Waiting for deletions to finish 2022/01/09 05:07:16 INFO : There was nothing to transfer 2022/01/09 05:07:18 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:07:18 DEBUG : pacer: Rate limited, increasing sleep to 1.08839624s 2022/01/09 05:07:19 DEBUG : pacer: Reducing sleep to 0s --- PASS: TestSyncWithTrackRenamesStrategyModtime (7.87s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" sync_test.go:1163: Can track renames: true 2022/01/09 05:07:20 INFO : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Making map for --track-renames 2022/01/09 05:07:20 INFO : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Finished making map for --track-renames 2022/01/09 05:07:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:07:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for renames to finish 2022/01/09 05:07:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:07:23 DEBUG : sub/yam: md5 = 9dae35beee5e22e6dd5491c855989c95 OK 2022/01/09 05:07:23 INFO : sub/yam: Copied (new) 2022/01/09 05:07:23 DEBUG : potato: md5 = 56ac57742c274419ba76c103a3afee3f OK 2022/01/09 05:07:23 INFO : potato: Copied (new) 2022/01/09 05:07:23 DEBUG : Waiting for deletions to finish 2022/01/09 05:07:24 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:07:24 DEBUG : potato: Unchanged skipping 2022/01/09 05:07:24 INFO : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Making map for --track-renames 2022/01/09 05:07:24 INFO : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Finished making map for --track-renames 2022/01/09 05:07:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:07:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for renames to finish 2022/01/09 05:07:24 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:07:24 DEBUG : pacer: Rate limited, increasing sleep to 1.371012909s 2022/01/09 05:07:24 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:07:24 DEBUG : pacer: Rate limited, increasing sleep to 2.407859238s 2022/01/09 05:07:26 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:07:29 INFO : sub/yam: Moved (server-side) to: yam 2022/01/09 05:07:29 INFO : yam: Renamed from "sub/yam" 2022/01/09 05:07:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:07:29 DEBUG : Waiting for deletions to finish 2022/01/09 05:07:29 INFO : There was nothing to transfer 2022/01/09 05:07:30 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:07:30 DEBUG : pacer: Rate limited, increasing sleep to 1.616951806s 2022/01/09 05:07:30 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:07:30 DEBUG : pacer: Rate limited, increasing sleep to 2.856998269s 2022/01/09 05:07:33 DEBUG : pacer: Reducing sleep to 0s --- PASS: TestSyncWithTrackRenamesStrategyLeaf (16.88s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:07:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:07:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:07:37 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:07:37 DEBUG : pacer: Rate limited, increasing sleep to 1.635142778s 2022/01/09 05:07:38 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:07:41 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:07:41 DEBUG : pacer: Rate limited, increasing sleep to 1.133956396s 2022/01/09 05:07:41 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:07:41 DEBUG : sub dir/hello world: md5 = df38f42798f20e68361848a09298cbb4 OK 2022/01/09 05:07:41 INFO : sub dir/hello world: Copied (new) 2022/01/09 05:07:41 INFO : sub dir/hello world: Deleted 2022/01/09 05:07:44 DEBUG : nested/sub dir/file: md5 = 7ddde3097077f283921e5f4ea430237f OK 2022/01/09 05:07:44 INFO : nested/sub dir/file: Copied (new) 2022/01/09 05:07:44 INFO : nested/sub dir/file: Deleted 2022/01/09 05:07:44 INFO : sub dir: Removing directory 2022/01/09 05:07:44 INFO : nested/sub dir: Removing directory 2022/01/09 05:07:44 INFO : nested: Removing directory 2022/01/09 05:07:44 DEBUG : Local file system at /tmp/rclone1389598915: deleted 3 directories 2022/01/09 05:07:46 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:07:46 DEBUG : pacer: Rate limited, increasing sleep to 1.317319147s 2022/01/09 05:07:46 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:07:46 DEBUG : pacer: Rate limited, increasing sleep to 2.500836961s 2022/01/09 05:07:46 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:07:47 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:07:47 DEBUG : pacer: Rate limited, increasing sleep to 1.504799004s 2022/01/09 05:07:48 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:07:48 DEBUG : pacer: Rate limited, increasing sleep to 2.451745655s 2022/01/09 05:07:49 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:07:53 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2022/01/09 05:07:54 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2022/01/09 05:07:55 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (19.12s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:07:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:07:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:07:59 DEBUG : sub dir/hello world: md5 = fa7c53f76af2709500eed364cb0c4153 OK 2022/01/09 05:07:59 INFO : sub dir/hello world: Copied (new) 2022/01/09 05:07:59 INFO : sub dir/hello world: Deleted 2022/01/09 05:08:01 DEBUG : nested/sub dir/file: md5 = 0747a979d42036dbe706fc22ef3e163d OK 2022/01/09 05:08:01 INFO : nested/sub dir/file: Copied (new) 2022/01/09 05:08:01 INFO : nested/sub dir/file: Deleted 2022/01/09 05:08:04 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:08:04 DEBUG : pacer: Rate limited, increasing sleep to 1.509453291s 2022/01/09 05:08:04 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:08:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2022/01/09 05:08:07 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2022/01/09 05:08:08 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (13.36s) === RUN TestMoveWithIgnoreExisting run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:08:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:08:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:08:11 DEBUG : existing: md5 = 92d92faaca5911f07348949f21eb4e8d OK 2022/01/09 05:08:11 INFO : existing: Copied (new) 2022/01/09 05:08:11 INFO : existing: Deleted 2022/01/09 05:08:12 DEBUG : existing-b: md5 = 913d8f8667c28bff6351da41725274b5 OK 2022/01/09 05:08:12 INFO : existing-b: Copied (new) 2022/01/09 05:08:12 INFO : existing-b: Deleted 2022/01/09 05:08:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:08:12 DEBUG : existing: Destination exists, skipping 2022/01/09 05:08:12 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2022/01/09 05:08:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:08:12 INFO : There was nothing to transfer --- PASS: TestMoveWithIgnoreExisting (5.47s) === RUN TestServerSideMove run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:08:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fepuhiw0galirad9vinuwik1" 2022/01/09 05:08:15 DEBUG : Config file has changed externaly - reloading 2022/01/09 05:08:15 DEBUG : Creating backend with remote "TestDrive:crypt/jnqmesou9boicmp06jbdgeeqg1180edogq61d0rf4pfmkpc3tug5ti3dh3j347m3pq6ti2uoec4aq" 2022/01/09 05:08:16 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:08:16 DEBUG : pacer: Rate limited, increasing sleep to 1.86797914s 2022/01/09 05:08:16 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:08:19 DEBUG : potato2: md5 = 0238cf55a693771dc14d13332377b186 OK 2022/01/09 05:08:21 DEBUG : empty space: md5 = a7c66aaa4509685405229ce5bdb332fa OK 2022/01/09 05:08:23 DEBUG : potato3: md5 = eab4d794ef7c96f7bdedf83609af8e01 OK sync_test.go:1215: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0' -> Encrypted drive 'TestCryptDrive:rclone-test-fepuhiw0galirad9vinuwik1' 2022/01/09 05:08:25 DEBUG : empty space: md5 = 8a46c9af950bd910c560f31e612eff27 OK 2022/01/09 05:08:27 DEBUG : potato3: md5 = 8a0b3b1d3b186c6f61402c54956fb4d3 OK 2022/01/09 05:08:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fepuhiw0galirad9vinuwik1': Using server-side directory move 2022/01/09 05:08:27 INFO : Encrypted drive 'TestCryptDrive:rclone-test-fepuhiw0galirad9vinuwik1': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2022/01/09 05:08:28 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2022/01/09 05:08:28 DEBUG : empty space: Unchanged skipping 2022/01/09 05:08:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fepuhiw0galirad9vinuwik1': Waiting for checks to finish 2022/01/09 05:08:28 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2022/01/09 05:08:28 INFO : empty space: Deleted 2022/01/09 05:08:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fepuhiw0galirad9vinuwik1': Waiting for transfers to finish 2022/01/09 05:08:29 INFO : potato3: Deleted 2022/01/09 05:08:29 INFO : potato2: Moved (server-side) 2022/01/09 05:08:29 INFO : potato3: Moved (server-side) 2022/01/09 05:08:29 INFO : There was nothing to transfer 2022/01/09 05:08:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rejaner1motuluh2xabivev1" 2022/01/09 05:08:30 DEBUG : Creating backend with remote "TestDrive:crypt/7c4t57r0585hv2pqdarla4oj3blmi55v47erj3buhci4s076geplde1ibcebbd8ke0vl298kqr808" 2022/01/09 05:08:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rejaner1motuluh2xabivev1': Using server-side directory move 2022/01/09 05:08:32 INFO : Encrypted drive 'TestCryptDrive:rclone-test-rejaner1motuluh2xabivev1': Server side directory move succeeded 2022/01/09 05:08:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rejaner1motuluh2xabivev1': Purge remote 2022/01/09 05:08:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fepuhiw0galirad9vinuwik1': Purge remote 2022/01/09 05:08:34 purge failed: directory not found --- PASS: TestServerSideMove (20.24s) === RUN TestServerSideMoveWithFilter run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:08:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suzutey5gecunis2tibetuk1" 2022/01/09 05:08:35 DEBUG : Creating backend with remote "TestDrive:crypt/pf5nqjuc19ajeskimf4khsmjq7h4nl9a2i1q9hjfpojtl2bc8kq0mgmmmvo5dvvfane6lht34j598" 2022/01/09 05:08:37 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:08:37 DEBUG : pacer: Rate limited, increasing sleep to 1.662692015s 2022/01/09 05:08:37 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:08:40 DEBUG : potato2: md5 = c4fa40fb84b58cfdcf31a752b8c82070 OK 2022/01/09 05:08:41 DEBUG : empty space: md5 = fbb5114387a80c920ae4cecc3e5d485b OK 2022/01/09 05:08:43 DEBUG : potato3: md5 = 0bc2e7f212d087ff563bae443ff133cc OK sync_test.go:1215: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0' -> Encrypted drive 'TestCryptDrive:rclone-test-suzutey5gecunis2tibetuk1' 2022/01/09 05:08:46 DEBUG : empty space: md5 = 26aeefe4e35d44773a00c8cb6eb3846c OK 2022/01/09 05:08:48 DEBUG : potato3: md5 = 04d7c15e21414958708ac34f4066dcf6 OK 2022/01/09 05:08:48 DEBUG : empty space: Excluded 2022/01/09 05:08:48 DEBUG : empty space: Excluded 2022/01/09 05:08:48 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2022/01/09 05:08:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suzutey5gecunis2tibetuk1': Waiting for checks to finish 2022/01/09 05:08:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suzutey5gecunis2tibetuk1': Waiting for transfers to finish 2022/01/09 05:08:48 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:08:48 DEBUG : pacer: Rate limited, increasing sleep to 1.317442899s 2022/01/09 05:08:49 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:08:49 INFO : potato2: Moved (server-side) 2022/01/09 05:08:49 INFO : potato3: Deleted 2022/01/09 05:08:51 INFO : potato3: Moved (server-side) 2022/01/09 05:08:51 INFO : There was nothing to transfer 2022/01/09 05:08:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qiqubut7zewobaj7hiniviy0" 2022/01/09 05:08:51 DEBUG : Creating backend with remote "TestDrive:crypt/n6kal7e5vu323id0dthgbhanrkeve80ip3qgossikdo0po6d5h8sf6emgpic59lhlngf2q5dikfrk" 2022/01/09 05:08:52 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:08:52 DEBUG : pacer: Rate limited, increasing sleep to 1.093246867s 2022/01/09 05:08:52 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:08:54 DEBUG : empty space: Excluded 2022/01/09 05:08:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qiqubut7zewobaj7hiniviy0': Waiting for checks to finish 2022/01/09 05:08:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qiqubut7zewobaj7hiniviy0': Waiting for transfers to finish 2022/01/09 05:08:54 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:08:54 DEBUG : pacer: Rate limited, increasing sleep to 1.300594012s 2022/01/09 05:08:54 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:08:54 DEBUG : pacer: Rate limited, increasing sleep to 2.53022486s 2022/01/09 05:08:56 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:08:59 INFO : potato2: Moved (server-side) 2022/01/09 05:09:00 INFO : potato3: Moved (server-side) 2022/01/09 05:09:00 INFO : There was nothing to transfer 2022/01/09 05:09:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qiqubut7zewobaj7hiniviy0': Purge remote 2022/01/09 05:09:00 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:09:00 DEBUG : pacer: Rate limited, increasing sleep to 1.150937509s 2022/01/09 05:09:01 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:09:01 DEBUG : pacer: Rate limited, increasing sleep to 2.266401004s 2022/01/09 05:09:02 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:09:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suzutey5gecunis2tibetuk1': Purge remote --- PASS: TestServerSideMoveWithFilter (29.31s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:09:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lovitec6bejumul4zetejum1" 2022/01/09 05:09:04 DEBUG : Creating backend with remote "TestDrive:crypt/cbif6scpnt21rngvl3ptiiq9agbrffire4qgntqu27ud764b38n9bt9966ar8ob1mm1e7ldsgu1kc" 2022/01/09 05:09:07 DEBUG : potato2: md5 = 2109eaf3b4b15531b1407485f7f39a56 OK 2022/01/09 05:09:09 DEBUG : empty space: md5 = f22919bf128da994023be184e47548cc OK 2022/01/09 05:09:11 DEBUG : potato3: md5 = 94d311d4803d42f449d661978c060e17 OK 2022/01/09 05:09:11 DEBUG : tomatoDir: Making directory sync_test.go:1215: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0' -> Encrypted drive 'TestCryptDrive:rclone-test-lovitec6bejumul4zetejum1' 2022/01/09 05:09:15 DEBUG : empty space: md5 = e95798d1f89334cb991d5010f3fb01d0 OK 2022/01/09 05:09:17 DEBUG : potato3: md5 = b4d50d4a0651fc8bfe3047affdbd0c3f OK 2022/01/09 05:09:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lovitec6bejumul4zetejum1': Using server-side directory move 2022/01/09 05:09:17 INFO : Encrypted drive 'TestCryptDrive:rclone-test-lovitec6bejumul4zetejum1': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2022/01/09 05:09:17 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2022/01/09 05:09:17 DEBUG : empty space: Unchanged skipping 2022/01/09 05:09:17 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2022/01/09 05:09:17 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:09:17 DEBUG : pacer: Rate limited, increasing sleep to 1.702700056s 2022/01/09 05:09:17 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:09:17 DEBUG : pacer: Rate limited, increasing sleep to 1.108890513s 2022/01/09 05:09:17 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:09:17 DEBUG : pacer: Rate limited, increasing sleep to 2.506815001s 2022/01/09 05:09:17 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:09:17 DEBUG : pacer: Rate limited, increasing sleep to 2.796769742s 2022/01/09 05:09:18 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:09:18 DEBUG : pacer: Rate limited, increasing sleep to 4.937716633s 2022/01/09 05:09:18 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:09:18 DEBUG : pacer: Rate limited, increasing sleep to 4.20840422s 2022/01/09 05:09:19 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:09:19 INFO : empty space: Deleted 2022/01/09 05:09:20 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:09:20 INFO : potato3: Deleted 2022/01/09 05:09:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lovitec6bejumul4zetejum1': Waiting for checks to finish 2022/01/09 05:09:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lovitec6bejumul4zetejum1': Waiting for transfers to finish 2022/01/09 05:09:25 INFO : potato3: Moved (server-side) 2022/01/09 05:09:25 INFO : potato2: Moved (server-side) 2022/01/09 05:09:25 INFO : tomatoDir: Removing directory 2022/01/09 05:09:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': deleted 1 directories 2022/01/09 05:09:26 INFO : There was nothing to transfer 2022/01/09 05:09:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mixelul2yibuyub4rayagaz7" 2022/01/09 05:09:27 DEBUG : Creating backend with remote "TestDrive:crypt/aa3jceguajsa4t7nf1tc34bo3ia14jj7v5id2bbjaa06liscjhjo6jcdmh20i4phqosqbeskka88q" 2022/01/09 05:09:28 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:09:28 DEBUG : pacer: Rate limited, increasing sleep to 1.481771334s 2022/01/09 05:09:28 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:09:30 DEBUG : tomatoDir: Making directory 2022/01/09 05:09:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mixelul2yibuyub4rayagaz7': Using server-side directory move 2022/01/09 05:09:32 INFO : Encrypted drive 'TestCryptDrive:rclone-test-mixelul2yibuyub4rayagaz7': Server side directory move succeeded 2022/01/09 05:09:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mixelul2yibuyub4rayagaz7': Purge remote 2022/01/09 05:09:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lovitec6bejumul4zetejum1': Purge remote 2022/01/09 05:09:35 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:09:35 DEBUG : pacer: Rate limited, increasing sleep to 1.366114477s 2022/01/09 05:09:35 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:09:35 purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (31.08s) === RUN TestServerSideMoveOverlap run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" sync_test.go:1399: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.58s) === RUN TestSyncOverlap run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:09:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/rclone-sync-test" 2022/01/09 05:09:36 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2022/01/09 05:09:37 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:09:37 DEBUG : pacer: Rate limited, increasing sleep to 1.037554147s 2022/01/09 05:09:37 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:09:39 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:09:39 DEBUG : pacer: Rate limited, increasing sleep to 1.411750381s 2022/01/09 05:09:39 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:09:39 DEBUG : pacer: Rate limited, increasing sleep to 2.599342841s 2022/01/09 05:09:41 DEBUG : pacer: Reducing sleep to 0s --- PASS: TestSyncOverlap (5.02s) === RUN TestSyncCompareDest run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:09:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst" 2022/01/09 05:09:41 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c/31u3jie661vd5p8j7rtc3hgbh0" 2022/01/09 05:09:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/CompareDest" 2022/01/09 05:09:43 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c/gveqi14airsml4bgu7krj116o8" 2022/01/09 05:09:44 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:09:44 DEBUG : pacer: Rate limited, increasing sleep to 1.864536104s 2022/01/09 05:09:45 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:09:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:09:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:09:48 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:09:48 DEBUG : pacer: Rate limited, increasing sleep to 1.694423894s 2022/01/09 05:09:48 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:09:51 DEBUG : one: md5 = d4065b5457c54d6faf5ae5da25ce0f89 OK 2022/01/09 05:09:51 INFO : one: Copied (new) 2022/01/09 05:09:51 DEBUG : Waiting for deletions to finish 2022/01/09 05:09:53 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:09:53 DEBUG : pacer: Rate limited, increasing sleep to 1.682978866s 2022/01/09 05:09:53 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:09:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:09:53 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/01/09 05:09:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:09:55 DEBUG : one: md5 = 640e0a07a5eff794bef0e2fba3fb5078 OK 2022/01/09 05:09:55 INFO : one: Copied (replaced existing) 2022/01/09 05:09:55 DEBUG : Waiting for deletions to finish 2022/01/09 05:09:57 DEBUG : dst/one: md5 = 4f8bf7e1f6397c03224ca2ce4178fcf4 OK 2022/01/09 05:09:58 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:09:58 DEBUG : pacer: Rate limited, increasing sleep to 1.540735838s 2022/01/09 05:09:58 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:10:01 DEBUG : CompareDest/one: md5 = 851540b00690957512e0c39a3fe0fd27 OK 2022/01/09 05:10:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:10:02 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:10:02 DEBUG : pacer: Rate limited, increasing sleep to 1.681490481s 2022/01/09 05:10:03 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:10:03 DEBUG : pacer: Rate limited, increasing sleep to 2.076455331s 2022/01/09 05:10:04 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:10:06 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:10:06 DEBUG : one: Destination found in --compare-dest, skipping 2022/01/09 05:10:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:10:06 DEBUG : Waiting for deletions to finish 2022/01/09 05:10:06 INFO : There was nothing to transfer 2022/01/09 05:10:07 DEBUG : pacer: low level retry 1/1 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:10:07 DEBUG : pacer: Rate limited, increasing sleep to 1.325096368s run.go:283: Retry Put of "CompareDest/two" to Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': 1/10 (googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:10:10 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:10:12 DEBUG : CompareDest/two: md5 = 57621584be4f95f2599432ecb211bee1 OK 2022/01/09 05:10:14 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:10:14 DEBUG : two: Destination found in --compare-dest, skipping 2022/01/09 05:10:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:10:14 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:10:14 DEBUG : one: Destination found in --compare-dest, skipping 2022/01/09 05:10:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:10:14 DEBUG : Waiting for deletions to finish 2022/01/09 05:10:14 INFO : There was nothing to transfer 2022/01/09 05:10:15 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:10:15 DEBUG : two: Destination found in --compare-dest, skipping 2022/01/09 05:10:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:10:16 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:10:16 DEBUG : one: Destination found in --compare-dest, skipping 2022/01/09 05:10:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:10:16 DEBUG : Waiting for deletions to finish 2022/01/09 05:10:16 INFO : There was nothing to transfer sync_test.go:1543: No hash on uploaded file so skipping compare timestamp test 2022/01/09 05:10:16 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:10:16 DEBUG : pacer: Rate limited, increasing sleep to 1.287148336s 2022/01/09 05:10:17 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:10:19 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:10:19 DEBUG : pacer: Rate limited, increasing sleep to 1.320958419s 2022/01/09 05:10:19 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:10:19 DEBUG : two: Sizes differ (src 5 vs dst 3) 2022/01/09 05:10:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:10:20 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:10:20 DEBUG : one: Destination found in --compare-dest, skipping 2022/01/09 05:10:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:10:20 DEBUG : two: md5 = 4813f989764175ca39c405955118475e OK 2022/01/09 05:10:20 INFO : two: Copied (new) 2022/01/09 05:10:20 DEBUG : Waiting for deletions to finish 2022/01/09 05:10:25 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/09 05:10:25 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/09 05:10:26 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/09 05:10:26 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/09 05:10:27 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:10:27 DEBUG : pacer: Rate limited, increasing sleep to 1.721809981s 2022/01/09 05:10:27 DEBUG : pacer: Reducing sleep to 0s --- PASS: TestSyncCompareDest (45.89s) === RUN TestSyncMultipleCompareDest run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:10:31 DEBUG : pre-dest1/1: md5 = cece96a8abd33d31ba0a3e1937869ca7 OK 2022/01/09 05:10:33 DEBUG : pre-dest2/2: md5 = 0935f80dc5287b692c5632a0ef567b57 OK 2022/01/09 05:10:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dest" 2022/01/09 05:10:34 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c/rg03c1jvnehrrc617i0lnqjddc" 2022/01/09 05:10:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/pre-dest1" 2022/01/09 05:10:36 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c/bbnblvh6k061ssopqrp18kd7gc" 2022/01/09 05:10:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/pre-dest2" 2022/01/09 05:10:37 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c/dgicm1h6b5ejvlltm8eeif0bnk" 2022/01/09 05:10:39 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:10:39 DEBUG : pacer: Rate limited, increasing sleep to 1.689087194s 2022/01/09 05:10:39 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:10:39 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:10:39 DEBUG : 1: Destination found in --compare-dest, skipping 2022/01/09 05:10:41 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:10:41 DEBUG : 2: Destination found in --compare-dest, skipping 2022/01/09 05:10:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dest': Waiting for checks to finish 2022/01/09 05:10:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dest': Waiting for transfers to finish 2022/01/09 05:10:44 DEBUG : 3: md5 = 53fbda9d26a279d3c04dcf8d970b7f95 OK 2022/01/09 05:10:44 INFO : 3: Copied (new) 2022/01/09 05:10:44 DEBUG : Waiting for deletions to finish 2022/01/09 05:10:46 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:10:46 DEBUG : pacer: Rate limited, increasing sleep to 1.648390249s 2022/01/09 05:10:46 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:10:47 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:10:47 DEBUG : pacer: Rate limited, increasing sleep to 1.140650242s 2022/01/09 05:10:47 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:10:47 DEBUG : pacer: Rate limited, increasing sleep to 2.818063388s 2022/01/09 05:10:47 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:10:47 DEBUG : pacer: Rate limited, increasing sleep to 4.441844831s 2022/01/09 05:10:48 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:10:48 DEBUG : pacer: Rate limited, increasing sleep to 8.410961816s 2022/01/09 05:10:49 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:11:00 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2022/01/09 05:11:01 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2022/01/09 05:11:02 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (35.91s) === RUN TestSyncCopyDest run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:11:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst" 2022/01/09 05:11:03 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c/31u3jie661vd5p8j7rtc3hgbh0" 2022/01/09 05:11:05 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:05 DEBUG : pacer: Rate limited, increasing sleep to 1.789146324s 2022/01/09 05:11:05 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:05 DEBUG : pacer: Rate limited, increasing sleep to 2.695302981s 2022/01/09 05:11:07 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:11:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/CopyDest" 2022/01/09 05:11:07 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c/d09o6po3f7bm6ce32vdgs8h9ls" 2022/01/09 05:11:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:11:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:11:12 DEBUG : one: md5 = 0fa32390869daf7e1ff0408356eeee5e OK 2022/01/09 05:11:12 INFO : one: Copied (new) 2022/01/09 05:11:12 DEBUG : Waiting for deletions to finish 2022/01/09 05:11:13 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:13 DEBUG : pacer: Rate limited, increasing sleep to 1.281085765s 2022/01/09 05:11:14 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:14 DEBUG : pacer: Rate limited, increasing sleep to 2.55460729s 2022/01/09 05:11:15 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:11:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:11:16 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/01/09 05:11:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:11:17 DEBUG : one: md5 = 4e3f9e0588fb241da53bd65883a41a6b OK 2022/01/09 05:11:17 INFO : one: Copied (replaced existing) 2022/01/09 05:11:17 DEBUG : Waiting for deletions to finish 2022/01/09 05:11:20 DEBUG : dst/one: md5 = 37fe92c6db2a8d7288813171c750002d OK 2022/01/09 05:11:22 DEBUG : CopyDest/one: md5 = 80494aa3c456d555bb8973b840370ce0 OK 2022/01/09 05:11:23 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:23 DEBUG : pacer: Rate limited, increasing sleep to 1.841382207s 2022/01/09 05:11:23 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:11:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/BackupDir" 2022/01/09 05:11:25 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c/s6dbk3lfi7c9kfvo6j7bla9m0g" 2022/01/09 05:11:27 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:27 DEBUG : pacer: Rate limited, increasing sleep to 1.26752296s 2022/01/09 05:11:27 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:11:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:11:27 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:27 DEBUG : pacer: Rate limited, increasing sleep to 1.37364911s 2022/01/09 05:11:28 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:28 DEBUG : pacer: Rate limited, increasing sleep to 2.779111712s 2022/01/09 05:11:29 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:11:32 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:11:32 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/01/09 05:11:33 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:33 DEBUG : pacer: Rate limited, increasing sleep to 1.17633518s 2022/01/09 05:11:33 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:11:35 INFO : one: Moved (server-side) 2022/01/09 05:11:36 INFO : one: Copied (server-side copy) 2022/01/09 05:11:36 DEBUG : one: Destination found in --copy-dest, using server-side copy 2022/01/09 05:11:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:11:36 DEBUG : Waiting for deletions to finish 2022/01/09 05:11:37 DEBUG : pacer: low level retry 1/1 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:37 DEBUG : pacer: Rate limited, increasing sleep to 1.829671585s run.go:283: Retry Put of "CopyDest/two" to Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': 1/10 (googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:40 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:11:42 DEBUG : CopyDest/two: md5 = 2666c0a5f46f01fe8a3d82da235eee10 OK 2022/01/09 05:11:43 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:43 DEBUG : pacer: Rate limited, increasing sleep to 1.399051107s 2022/01/09 05:11:43 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:43 DEBUG : pacer: Rate limited, increasing sleep to 2.390125698s 2022/01/09 05:11:45 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:11:45 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:11:49 INFO : two: Copied (server-side copy) 2022/01/09 05:11:49 DEBUG : two: Destination found in --copy-dest, using server-side copy 2022/01/09 05:11:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:11:49 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:11:49 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:11:49 DEBUG : one: Unchanged skipping 2022/01/09 05:11:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:11:49 DEBUG : Waiting for deletions to finish 2022/01/09 05:11:49 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:49 DEBUG : pacer: Rate limited, increasing sleep to 1.074533657s 2022/01/09 05:11:49 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:49 DEBUG : pacer: Rate limited, increasing sleep to 2.150691107s 2022/01/09 05:11:50 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:50 DEBUG : pacer: Rate limited, increasing sleep to 4.533827732s 2022/01/09 05:11:50 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:11:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:11:51 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:51 DEBUG : pacer: Rate limited, increasing sleep to 1.081644583s 2022/01/09 05:11:51 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:51 DEBUG : pacer: Rate limited, increasing sleep to 2.506659288s 2022/01/09 05:11:51 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:11:51 DEBUG : pacer: Rate limited, increasing sleep to 4.683002786s 2022/01/09 05:11:53 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:11:53 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:11:53 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:11:53 DEBUG : one: Unchanged skipping 2022/01/09 05:11:57 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:11:57 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:11:57 DEBUG : two: Unchanged skipping 2022/01/09 05:11:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:11:57 DEBUG : Waiting for deletions to finish 2022/01/09 05:11:57 INFO : There was nothing to transfer 2022/01/09 05:12:00 DEBUG : CopyDest/three: md5 = 7729da2e59bbe37132754230fd17d271 OK 2022/01/09 05:12:00 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:12:00 DEBUG : pacer: Rate limited, increasing sleep to 1.328330379s 2022/01/09 05:12:01 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:12:01 DEBUG : three: Sizes differ (src 7 vs dst 5) 2022/01/09 05:12:01 DEBUG : three: Destination not found in --copy-dest 2022/01/09 05:12:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:12:01 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:12:01 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:12:01 DEBUG : one: Unchanged skipping 2022/01/09 05:12:01 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:12:01 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/09 05:12:01 DEBUG : two: Unchanged skipping 2022/01/09 05:12:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:12:03 DEBUG : three: md5 = 21eb2ba7726988746be1fea074b5f7b3 OK 2022/01/09 05:12:03 INFO : three: Copied (new) 2022/01/09 05:12:03 DEBUG : Waiting for deletions to finish 2022/01/09 05:12:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2022/01/09 05:12:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/09 05:12:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/09 05:12:11 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/09 05:12:11 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/09 05:12:11 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2022/01/09 05:12:12 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (69.74s) === RUN TestSyncBackupDir run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:12:15 DEBUG : dst/one: md5 = 1899515a2140d86da118b5fdd98cba2f OK 2022/01/09 05:12:17 DEBUG : dst/two: md5 = bc905de77958987f955cb92fea723044 OK 2022/01/09 05:12:18 DEBUG : dst/three.txt: md5 = c8c524f944494868db1ce17618bd59c7 OK 2022/01/09 05:12:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst" 2022/01/09 05:12:19 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c/31u3jie661vd5p8j7rtc3hgbh0" 2022/01/09 05:12:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/backup" 2022/01/09 05:12:20 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c/1nrff024r7pq65ecp72fc28jb0" 2022/01/09 05:12:21 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:12:21 DEBUG : pacer: Rate limited, increasing sleep to 1.447807566s 2022/01/09 05:12:21 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:12:21 DEBUG : pacer: Rate limited, increasing sleep to 2.721388411s 2022/01/09 05:12:23 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:12:26 DEBUG : one: Sizes differ (src 4 vs dst 3) 2022/01/09 05:12:26 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:12:26 DEBUG : two: Unchanged skipping 2022/01/09 05:12:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:12:29 INFO : one: Moved (server-side) 2022/01/09 05:12:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:12:30 DEBUG : one: md5 = 178b4ad9f0b40755f939b1703a365e57 OK 2022/01/09 05:12:30 INFO : one: Copied (new) 2022/01/09 05:12:30 DEBUG : Waiting for deletions to finish 2022/01/09 05:12:31 INFO : three.txt: Moved (server-side) 2022/01/09 05:12:31 INFO : three.txt: Moved into backup dir 2022/01/09 05:12:32 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:12:32 DEBUG : pacer: Rate limited, increasing sleep to 1.259491267s 2022/01/09 05:12:32 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:12:34 DEBUG : pacer: low level retry 1/1 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:12:34 DEBUG : pacer: Rate limited, increasing sleep to 1.108174034s run.go:283: Retry Put of "dst/three.txt" to Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': 1/10 (googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:12:36 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:12:38 DEBUG : dst/three.txt: md5 = 106c82ac7927d72cbbba6757dd231bfb OK 2022/01/09 05:12:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:12:39 DEBUG : one: Sizes differ (src 5 vs dst 4) 2022/01/09 05:12:39 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:12:39 DEBUG : two: Unchanged skipping 2022/01/09 05:12:40 INFO : one: Deleted 2022/01/09 05:12:40 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:12:40 DEBUG : pacer: Rate limited, increasing sleep to 1.264282652s 2022/01/09 05:12:40 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:12:40 DEBUG : pacer: Rate limited, increasing sleep to 2.563557168s 2022/01/09 05:12:42 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:12:42 INFO : one: Moved (server-side) 2022/01/09 05:12:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:12:44 DEBUG : one: md5 = e51504e87707ce476d2df4f731528700 OK 2022/01/09 05:12:44 INFO : one: Copied (new) 2022/01/09 05:12:44 DEBUG : Waiting for deletions to finish 2022/01/09 05:12:45 INFO : three.txt: Deleted 2022/01/09 05:12:45 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:12:45 DEBUG : pacer: Rate limited, increasing sleep to 1.613595328s 2022/01/09 05:12:45 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:12:45 DEBUG : pacer: Rate limited, increasing sleep to 2.038201133s 2022/01/09 05:12:48 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:12:48 INFO : three.txt: Moved (server-side) 2022/01/09 05:12:48 INFO : three.txt: Moved into backup dir 2022/01/09 05:12:52 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/09 05:12:52 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/09 05:12:53 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2022/01/09 05:12:53 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/09 05:12:53 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2022/01/09 05:12:53 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/09 05:12:54 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:12:54 DEBUG : pacer: Rate limited, increasing sleep to 1.502210325s 2022/01/09 05:12:54 DEBUG : pacer: Reducing sleep to 0s --- PASS: TestSyncBackupDir (41.32s) === RUN TestSyncBackupDirWithSuffix run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:12:56 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:12:56 DEBUG : pacer: Rate limited, increasing sleep to 1.167272264s 2022/01/09 05:12:56 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:12:59 DEBUG : dst/one: md5 = 20c52a942444964caed8ef4370b084d2 OK 2022/01/09 05:13:01 DEBUG : dst/two: md5 = e22e49451de4366f667445e5c27d4152 OK 2022/01/09 05:13:02 DEBUG : dst/three.txt: md5 = 5ea63a1865227f0a6ef63c48144d0120 OK 2022/01/09 05:13:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst" 2022/01/09 05:13:03 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c/31u3jie661vd5p8j7rtc3hgbh0" 2022/01/09 05:13:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/backup" 2022/01/09 05:13:04 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c/1nrff024r7pq65ecp72fc28jb0" 2022/01/09 05:13:04 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:13:04 DEBUG : pacer: Rate limited, increasing sleep to 1.226985368s 2022/01/09 05:13:05 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:13:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:13:08 DEBUG : one: Sizes differ (src 4 vs dst 3) 2022/01/09 05:13:08 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:13:08 DEBUG : two: Unchanged skipping 2022/01/09 05:13:08 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:13:08 DEBUG : pacer: Rate limited, increasing sleep to 1.361055484s 2022/01/09 05:13:08 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:13:08 DEBUG : pacer: Rate limited, increasing sleep to 2.357567248s 2022/01/09 05:13:10 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:13:13 INFO : one: Moved (server-side) to: one.bak 2022/01/09 05:13:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:13:15 DEBUG : one: md5 = a814359cbba5c448bcd3201a08a669f3 OK 2022/01/09 05:13:15 INFO : one: Copied (new) 2022/01/09 05:13:15 DEBUG : Waiting for deletions to finish 2022/01/09 05:13:16 INFO : three.txt: Moved (server-side) to: three.txt.bak 2022/01/09 05:13:16 INFO : three.txt: Moved into backup dir 2022/01/09 05:13:16 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:13:16 DEBUG : pacer: Rate limited, increasing sleep to 1.938946807s 2022/01/09 05:13:17 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:13:20 DEBUG : dst/three.txt: md5 = ed6e1df73878c82a9c4bfacf2fe97213 OK 2022/01/09 05:13:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:13:21 DEBUG : one: Sizes differ (src 5 vs dst 4) 2022/01/09 05:13:21 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:13:21 DEBUG : two: Unchanged skipping 2022/01/09 05:13:22 INFO : one.bak: Deleted 2022/01/09 05:13:22 INFO : one: Moved (server-side) to: one.bak 2022/01/09 05:13:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:13:24 DEBUG : one: md5 = 5ee7c5386b10f94846da68e8120d5a11 OK 2022/01/09 05:13:24 INFO : one: Copied (new) 2022/01/09 05:13:24 DEBUG : Waiting for deletions to finish 2022/01/09 05:13:25 INFO : three.txt.bak: Deleted 2022/01/09 05:13:25 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:13:25 DEBUG : pacer: Rate limited, increasing sleep to 1.121524855s 2022/01/09 05:13:25 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:13:25 DEBUG : pacer: Rate limited, increasing sleep to 2.525257354s 2022/01/09 05:13:27 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:13:27 INFO : three.txt: Moved (server-side) to: three.txt.bak 2022/01/09 05:13:27 INFO : three.txt: Moved into backup dir 2022/01/09 05:13:28 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:13:28 DEBUG : pacer: Rate limited, increasing sleep to 1.768670208s 2022/01/09 05:13:28 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:13:28 DEBUG : pacer: Rate limited, increasing sleep to 2.314937281s 2022/01/09 05:13:29 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:13:30 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:13:30 DEBUG : pacer: Rate limited, increasing sleep to 1.414569048s 2022/01/09 05:13:31 DEBUG : pacer: low level retry 3/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:13:31 DEBUG : pacer: Rate limited, increasing sleep to 2.185684617s 2022/01/09 05:13:32 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:13:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/09 05:13:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/09 05:13:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2022/01/09 05:13:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2022/01/09 05:13:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2022/01/09 05:13:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirWithSuffix (45.30s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:13:42 DEBUG : dst/one: md5 = cdae9ca8ead8c2e8974ceac16df2b1fc OK 2022/01/09 05:13:44 DEBUG : dst/two: md5 = 0603c0b2c4c0077aac52a5afdf921d51 OK 2022/01/09 05:13:46 DEBUG : dst/three.txt: md5 = bdcf237bf62c79ca7bdef66c0571b214 OK 2022/01/09 05:13:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst" 2022/01/09 05:13:46 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c/31u3jie661vd5p8j7rtc3hgbh0" 2022/01/09 05:13:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/backup" 2022/01/09 05:13:47 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c/1nrff024r7pq65ecp72fc28jb0" 2022/01/09 05:13:48 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:13:48 DEBUG : pacer: Rate limited, increasing sleep to 1.789542617s 2022/01/09 05:13:48 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:13:48 DEBUG : pacer: Rate limited, increasing sleep to 2.338017794s 2022/01/09 05:13:50 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:13:53 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:13:53 DEBUG : pacer: Rate limited, increasing sleep to 1.369865796s 2022/01/09 05:13:53 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:13:54 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:13:54 DEBUG : pacer: Rate limited, increasing sleep to 1.238015285s 2022/01/09 05:13:55 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:13:55 DEBUG : one: Sizes differ (src 4 vs dst 3) 2022/01/09 05:13:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:13:55 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:13:55 DEBUG : two: Unchanged skipping 2022/01/09 05:13:58 INFO : one: Moved (server-side) to: one-2019-01-01 2022/01/09 05:13:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:14:00 DEBUG : one: md5 = ed9d2373ad68747aa329245c27fd02a6 OK 2022/01/09 05:14:00 INFO : one: Copied (new) 2022/01/09 05:14:00 DEBUG : Waiting for deletions to finish 2022/01/09 05:14:01 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2022/01/09 05:14:01 INFO : three.txt: Moved into backup dir 2022/01/09 05:14:02 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:14:02 DEBUG : pacer: Rate limited, increasing sleep to 1.798930193s 2022/01/09 05:14:02 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:14:05 DEBUG : dst/three.txt: md5 = 84f9794298f7af8249b058d78a5bfe1d OK 2022/01/09 05:14:06 DEBUG : one: Sizes differ (src 5 vs dst 4) 2022/01/09 05:14:06 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:14:06 DEBUG : two: Unchanged skipping 2022/01/09 05:14:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:14:07 INFO : one-2019-01-01: Deleted 2022/01/09 05:14:07 INFO : one: Moved (server-side) to: one-2019-01-01 2022/01/09 05:14:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:14:09 DEBUG : one: md5 = fcd3669cf00c8c271aef8f6be14b949a OK 2022/01/09 05:14:09 INFO : one: Copied (new) 2022/01/09 05:14:09 DEBUG : Waiting for deletions to finish 2022/01/09 05:14:10 INFO : three-2019-01-01.txt: Deleted 2022/01/09 05:14:11 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2022/01/09 05:14:11 INFO : three.txt: Moved into backup dir 2022/01/09 05:14:11 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:14:11 DEBUG : pacer: Rate limited, increasing sleep to 1.720681594s 2022/01/09 05:14:12 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:14:18 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:14:18 DEBUG : pacer: Rate limited, increasing sleep to 1.906806621s 2022/01/09 05:14:19 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:14:21 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:14:21 DEBUG : pacer: Rate limited, increasing sleep to 1.545730014s 2022/01/09 05:14:21 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:14:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/09 05:14:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/09 05:14:24 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2022/01/09 05:14:24 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2022/01/09 05:14:24 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2022/01/09 05:14:24 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (45.61s) === RUN TestSyncBackupDirSuffixOnly run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:14:25 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:14:25 DEBUG : pacer: Rate limited, increasing sleep to 1.329430991s 2022/01/09 05:14:26 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:14:30 DEBUG : dst/one: md5 = 6fdb747fa0b12b284bcd78c50bf18438 OK 2022/01/09 05:14:31 DEBUG : dst/two: md5 = 166f7fd9ce99f3754b41899419ca3ef5 OK 2022/01/09 05:14:33 DEBUG : dst/three.txt: md5 = 4487de02a84320b5154afea22405831c OK 2022/01/09 05:14:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst" 2022/01/09 05:14:34 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c/31u3jie661vd5p8j7rtc3hgbh0" 2022/01/09 05:14:35 DEBUG : one: Sizes differ (src 4 vs dst 3) 2022/01/09 05:14:35 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:14:35 DEBUG : two: Unchanged skipping 2022/01/09 05:14:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:14:36 INFO : one: Moved (server-side) to: one.bak 2022/01/09 05:14:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:14:38 DEBUG : one: md5 = ced471bec18e758aaf22331d419d4aac OK 2022/01/09 05:14:38 INFO : one: Copied (new) 2022/01/09 05:14:38 DEBUG : Waiting for deletions to finish 2022/01/09 05:14:39 INFO : three.txt: Moved (server-side) to: three.txt.bak 2022/01/09 05:14:39 INFO : three.txt: Moved into backup dir 2022/01/09 05:14:39 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:14:39 DEBUG : pacer: Rate limited, increasing sleep to 1.174539094s 2022/01/09 05:14:40 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:14:40 DEBUG : pacer: Rate limited, increasing sleep to 2.180114183s 2022/01/09 05:14:41 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:14:45 DEBUG : dst/three.txt: md5 = 243cb2fb44a68624d094549544468d9d OK 2022/01/09 05:14:46 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:14:46 DEBUG : pacer: Rate limited, increasing sleep to 1.139185266s 2022/01/09 05:14:46 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:14:46 DEBUG : three.txt.bak: Excluded 2022/01/09 05:14:46 DEBUG : one.bak: Excluded 2022/01/09 05:14:46 DEBUG : one: Sizes differ (src 5 vs dst 4) 2022/01/09 05:14:46 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:14:46 DEBUG : two: Unchanged skipping 2022/01/09 05:14:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for checks to finish 2022/01/09 05:14:48 INFO : one.bak: Deleted 2022/01/09 05:14:50 INFO : one: Moved (server-side) to: one.bak 2022/01/09 05:14:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst': Waiting for transfers to finish 2022/01/09 05:14:52 DEBUG : one: md5 = 1b2eabcf630818f8ece8ac2ae7dbf1d8 OK 2022/01/09 05:14:52 INFO : one: Copied (new) 2022/01/09 05:14:52 DEBUG : Waiting for deletions to finish 2022/01/09 05:14:53 INFO : three.txt.bak: Deleted 2022/01/09 05:14:53 INFO : three.txt: Moved (server-side) to: three.txt.bak 2022/01/09 05:14:53 INFO : three.txt: Moved into backup dir 2022/01/09 05:14:54 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:14:54 DEBUG : pacer: Rate limited, increasing sleep to 1.562310968s 2022/01/09 05:14:54 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:14:54 DEBUG : pacer: Rate limited, increasing sleep to 2.848267687s 2022/01/09 05:14:56 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:15:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/09 05:15:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2022/01/09 05:15:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2022/01/09 05:15:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2022/01/09 05:15:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/09 05:15:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2022/01/09 05:15:03 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:15:03 DEBUG : pacer: Rate limited, increasing sleep to 1.547211122s 2022/01/09 05:15:03 DEBUG : pacer: Reducing sleep to 0s --- PASS: TestSyncBackupDirSuffixOnly (39.64s) === RUN TestSyncSuffix run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:15:05 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:15:05 DEBUG : pacer: Rate limited, increasing sleep to 1.768204629s 2022/01/09 05:15:05 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:15:09 DEBUG : dst/one: md5 = 6ec99854dffcef1c376d0ce44395b59e OK 2022/01/09 05:15:10 DEBUG : dst/two: md5 = 9f94579dc94f7aa9401c7421724a578a OK 2022/01/09 05:15:12 DEBUG : dst/three.txt: md5 = a0d86bbd6442e4c83b0f89a78a593bde OK 2022/01/09 05:15:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst" 2022/01/09 05:15:13 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c/31u3jie661vd5p8j7rtc3hgbh0" 2022/01/09 05:15:14 DEBUG : one: Sizes differ (src 4 vs dst 3) 2022/01/09 05:15:15 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:15:15 DEBUG : pacer: Rate limited, increasing sleep to 1.609986034s 2022/01/09 05:15:15 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:15:15 DEBUG : pacer: Rate limited, increasing sleep to 2.443799541s 2022/01/09 05:15:17 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:15:17 INFO : one: Moved (server-side) to: one.bak 2022/01/09 05:15:21 DEBUG : one: md5 = 75e2980e14a7aeaf4af0799f39012022 OK 2022/01/09 05:15:21 INFO : one: Copied (new) 2022/01/09 05:15:21 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:15:21 DEBUG : two: Unchanged skipping 2022/01/09 05:15:22 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2022/01/09 05:15:23 INFO : three.txt: Moved (server-side) to: three.txt.bak 2022/01/09 05:15:25 DEBUG : three.txt: md5 = c7687fdb583de1ad5e879fa5d1c4736b OK 2022/01/09 05:15:25 INFO : three.txt: Copied (new) 2022/01/09 05:15:25 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:15:25 DEBUG : pacer: Rate limited, increasing sleep to 1.782522293s 2022/01/09 05:15:25 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:15:25 DEBUG : pacer: Rate limited, increasing sleep to 2.504910432s 2022/01/09 05:15:27 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:15:30 DEBUG : one: Sizes differ (src 5 vs dst 4) 2022/01/09 05:15:30 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:15:30 DEBUG : pacer: Rate limited, increasing sleep to 1.40142867s 2022/01/09 05:15:31 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:15:33 INFO : one.bak: Deleted 2022/01/09 05:15:33 INFO : one: Moved (server-side) to: one.bak 2022/01/09 05:15:35 DEBUG : one: md5 = 4b4ec88dfa31a183d7eeb3c94b7deb57 OK 2022/01/09 05:15:35 INFO : one: Copied (new) 2022/01/09 05:15:35 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:15:35 DEBUG : two: Unchanged skipping 2022/01/09 05:15:36 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2022/01/09 05:15:37 INFO : three.txt.bak: Deleted 2022/01/09 05:15:37 INFO : three.txt: Moved (server-side) to: three.txt.bak 2022/01/09 05:15:39 DEBUG : three.txt: md5 = e615ef56be3702c8763603ae1db49334 OK 2022/01/09 05:15:39 INFO : three.txt: Copied (new) 2022/01/09 05:15:40 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:15:40 DEBUG : pacer: Rate limited, increasing sleep to 1.953791005s 2022/01/09 05:15:41 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:15:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2022/01/09 05:15:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/09 05:15:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2022/01/09 05:15:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2022/01/09 05:15:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2022/01/09 05:15:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/09 05:15:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncSuffix (45.13s) === RUN TestSyncSuffixKeepExtension run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:15:52 DEBUG : dst/one: md5 = 28810bf3b98ef788c77c8b02840611fd OK 2022/01/09 05:15:54 DEBUG : dst/two: md5 = 137516fc83debd581179baf14f55687c OK 2022/01/09 05:15:56 DEBUG : dst/three.txt: md5 = 8e7c12489384c61b84c7d73fc98befb6 OK 2022/01/09 05:15:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0/dst" 2022/01/09 05:15:56 DEBUG : Creating backend with remote "TestDrive:crypt/bq9tmsdoalumd3j0rbnciki12gt0230tv5lq13vbud5adq0kvj5t40iathrbc5m0boru2mpuorn9c/31u3jie661vd5p8j7rtc3hgbh0" 2022/01/09 05:15:58 DEBUG : one: Sizes differ (src 4 vs dst 3) 2022/01/09 05:15:59 INFO : one: Moved (server-side) to: one-2019-01-01 2022/01/09 05:16:01 DEBUG : one: md5 = 76201e0196065e7090521917bff42110 OK 2022/01/09 05:16:01 INFO : one: Copied (new) 2022/01/09 05:16:01 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:16:01 DEBUG : two: Unchanged skipping 2022/01/09 05:16:01 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2022/01/09 05:16:03 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2022/01/09 05:16:05 DEBUG : three.txt: md5 = 1105d6fc9ffc1c3c34f185c633df9b95 OK 2022/01/09 05:16:05 INFO : three.txt: Copied (new) 2022/01/09 05:16:05 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:16:05 DEBUG : pacer: Rate limited, increasing sleep to 1.376891261s 2022/01/09 05:16:05 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:16:05 DEBUG : pacer: Rate limited, increasing sleep to 2.059294296s 2022/01/09 05:16:07 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:16:10 DEBUG : one: Sizes differ (src 5 vs dst 4) 2022/01/09 05:16:10 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:16:10 DEBUG : pacer: Rate limited, increasing sleep to 1.219532736s 2022/01/09 05:16:11 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:16:11 INFO : one-2019-01-01: Deleted 2022/01/09 05:16:12 INFO : one: Moved (server-side) to: one-2019-01-01 2022/01/09 05:16:14 DEBUG : one: md5 = c74c82990b3b846af32dddf229fa9748 OK 2022/01/09 05:16:14 INFO : one: Copied (new) 2022/01/09 05:16:14 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:16:14 DEBUG : two: Unchanged skipping 2022/01/09 05:16:15 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2022/01/09 05:16:15 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:16:15 DEBUG : pacer: Rate limited, increasing sleep to 1.582220044s 2022/01/09 05:16:15 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:16:15 DEBUG : pacer: Rate limited, increasing sleep to 2.566075866s 2022/01/09 05:16:17 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:16:17 INFO : three-2019-01-01.txt: Deleted 2022/01/09 05:16:20 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2022/01/09 05:16:22 DEBUG : three.txt: md5 = 4bae3d829ab8395746906a688591799e OK 2022/01/09 05:16:22 INFO : three.txt: Copied (new) 2022/01/09 05:16:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/09 05:16:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2022/01/09 05:16:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2022/01/09 05:16:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2022/01/09 05:16:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/09 05:16:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2022/01/09 05:16:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (38.97s) === RUN TestSyncUTFNorm run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:16:31 DEBUG : Testêé: md5 = 7df7bd8a8c6431e66e99762a3d93a63a OK 2022/01/09 05:16:32 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2022/01/09 05:16:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:16:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:16:33 DEBUG : Testêé: md5 = 6e53770c71bb3973437e5c715e423c0b OK 2022/01/09 05:16:33 INFO : Testêé: Copied (replaced existing) 2022/01/09 05:16:33 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (5.84s) === RUN TestSyncImmutable run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:16:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:16:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:16:35 DEBUG : pacer: low level retry 1/1 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:16:35 DEBUG : pacer: Rate limited, increasing sleep to 1.591652703s 2022/01/09 05:16:35 DEBUG : existing: Received error: googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded - low level retry 1/10 2022/01/09 05:16:36 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:16:38 DEBUG : existing: md5 = 15c549980f57d43e4f58a61f10097339 OK 2022/01/09 05:16:38 INFO : existing: Copied (new) 2022/01/09 05:16:38 DEBUG : Waiting for deletions to finish 2022/01/09 05:16:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:16:39 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2022/01/09 05:16:39 ERROR : existing: Source and destination exist but do not match: immutable file modified 2022/01/09 05:16:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:16:39 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': not deleting files as there were IO errors 2022/01/09 05:16:39 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': not deleting directories as there were IO errors --- PASS: TestSyncImmutable (6.95s) === RUN TestSyncIgnoreCase run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:16:43 DEBUG : EXISTING: md5 = 061f73e6cf920037f4d219c3bd0b49c9 OK 2022/01/09 05:16:43 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:16:43 DEBUG : existing: Unchanged skipping 2022/01/09 05:16:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:16:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:16:43 DEBUG : Waiting for deletions to finish 2022/01/09 05:16:43 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (4.75s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" sync_test.go:1989: This test only runs on local === RUN TestMaxTransfer/Soft run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" sync_test.go:1989: This test only runs on local === RUN TestMaxTransfer/Cautious run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" sync_test.go:1989: This test only runs on local --- PASS: TestMaxTransfer (1.71s) --- SKIP: TestMaxTransfer/Hard (0.59s) --- SKIP: TestMaxTransfer/Soft (0.55s) --- SKIP: TestMaxTransfer/Cautious (0.57s) === RUN TestSyncConcurrentDelete run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:16:49 DEBUG : both0: md5 = e301af1c72519fdb56752b03fd5a13f8 OK 2022/01/09 05:16:51 DEBUG : only0: md5 = 791e34664269f9888ddad19287725c90 OK 2022/01/09 05:16:53 DEBUG : both1: md5 = 5958c918756be84092f630bb8e12b019 OK 2022/01/09 05:16:54 DEBUG : only1: md5 = 9fbed56e572b4b01aef33dd0514c2531 OK 2022/01/09 05:16:56 DEBUG : both2: md5 = 58ce101308cf82eda39771092ce9cd38 OK 2022/01/09 05:16:58 DEBUG : only2: md5 = d6b09befb36b644173bcadb4506f6a0e OK 2022/01/09 05:17:00 DEBUG : both3: md5 = 569685049e1ac09f0569495c4d7a9a24 OK 2022/01/09 05:17:02 DEBUG : only3: md5 = 9890523a6ef6dc94cdead28de845871c OK 2022/01/09 05:17:03 DEBUG : both4: md5 = 7fafc688743212e589b98d0ec1c2e20e OK 2022/01/09 05:17:05 DEBUG : only4: md5 = 760737fa7c40c312e497a2882eb2ff02 OK 2022/01/09 05:17:08 DEBUG : both5: md5 = 32c48f648bbed59a91c5cc283feeaf5e OK 2022/01/09 05:17:09 DEBUG : only5: md5 = b774b3b2d14ca3b93e089d8f0e13133a OK 2022/01/09 05:17:11 DEBUG : both6: md5 = 042b8d3e10cec8eaff6fd5b2a8a11dd1 OK 2022/01/09 05:17:13 DEBUG : only6: md5 = 6bbcd9fe3f92f4cc2e6c026cdefc388f OK 2022/01/09 05:17:15 DEBUG : both7: md5 = d1d24542a9c7fb18e4e40baaede8528a OK 2022/01/09 05:17:15 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:17:15 DEBUG : pacer: Rate limited, increasing sleep to 1.941197656s 2022/01/09 05:17:15 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:17:15 DEBUG : pacer: Rate limited, increasing sleep to 2.195150737s 2022/01/09 05:17:17 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:17:20 DEBUG : only7: md5 = da99c1de3b4834541cc584ccb511181a OK 2022/01/09 05:17:22 DEBUG : both8: md5 = 1b10e448bb904091efce843866d7e798 OK 2022/01/09 05:17:24 DEBUG : only8: md5 = deea4eb10f39ae61eff0e142520c86ee OK 2022/01/09 05:17:25 DEBUG : both9: md5 = 02689e541caaed946318c7e6b240eb79 OK 2022/01/09 05:17:27 DEBUG : only9: md5 = 9810e4bb8c7b30d261ea146ea338e29f OK 2022/01/09 05:17:29 DEBUG : both10: md5 = d46ecee32dd211844071902ff0cda7ba OK 2022/01/09 05:17:31 DEBUG : only10: md5 = 8f9ef0c1a1fdeb17f2169ab0fdc38956 OK 2022/01/09 05:17:32 DEBUG : both11: md5 = f130172cc5b643800de2da3a94ff62b6 OK 2022/01/09 05:17:33 DEBUG : pacer: low level retry 1/1 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:17:33 DEBUG : pacer: Rate limited, increasing sleep to 1.584282027s run.go:283: Retry Put of "only11" to Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': 1/10 (googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:17:35 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:17:35 DEBUG : pacer: Rate limited, increasing sleep to 2.193059987s 2022/01/09 05:17:37 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:17:40 DEBUG : only11: md5 = d6cb6f085f1824c715e9be1f81d0cdec OK 2022/01/09 05:17:42 DEBUG : both12: md5 = bb983517dc2bc77073b71c878b3563bd OK 2022/01/09 05:17:43 DEBUG : only12: md5 = be34dbe7688fbe837ce4908b40ef3df6 OK 2022/01/09 05:17:45 DEBUG : both13: md5 = 489a5a6fb15a3e3c0e7c8dbf6561df69 OK 2022/01/09 05:17:47 DEBUG : only13: md5 = 0f823b47aefb94f5675daa9d347a5f7c OK 2022/01/09 05:17:48 DEBUG : both14: md5 = 9d101ab2656ee89108153536a5289eff OK 2022/01/09 05:17:50 DEBUG : only14: md5 = c3dd397c5203277c9f49c937ec5a5225 OK 2022/01/09 05:17:51 DEBUG : both15: md5 = c368d57c4b0ae4e050b88ba5b594a686 OK 2022/01/09 05:17:53 DEBUG : only15: md5 = d671c69af4f7b59b63f8161d57a72e1c OK 2022/01/09 05:17:55 DEBUG : both16: md5 = 1572366a662e3cd52b728d876f8a7111 OK 2022/01/09 05:17:55 DEBUG : pacer: low level retry 1/1 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:17:55 DEBUG : pacer: Rate limited, increasing sleep to 1.153420742s run.go:283: Retry Put of "only16" to Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': 1/10 (googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:17:58 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:18:00 DEBUG : only16: md5 = bfacedf7c630138a54e7ece458f8fe91 OK 2022/01/09 05:18:02 DEBUG : both17: md5 = c4fc273074df8fbb779982c50682252f OK 2022/01/09 05:18:04 DEBUG : only17: md5 = 99ad14527aaf4840af69df74de4739b4 OK 2022/01/09 05:18:06 DEBUG : both18: md5 = 7d70b3e175c77f4a92993a06f6d30b03 OK 2022/01/09 05:18:07 DEBUG : only18: md5 = d59d8a15d5aeb38248be7b495ee9c4ac OK 2022/01/09 05:18:09 DEBUG : both19: md5 = 42dc0b9aaaf7a5d5e0d599577589fb26 OK 2022/01/09 05:18:11 DEBUG : only19: md5 = f7566e702dd314c8aa7cdee6cd585b70 OK 2022/01/09 05:18:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:18:12 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both1: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both11: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both12: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both13: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both10: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both14: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both0: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both16: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both18: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both19: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both2: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both3: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both4: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both5: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both17: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both15: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both7: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both6: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both8: Unchanged skipping 2022/01/09 05:18:12 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:18:12 DEBUG : both9: Unchanged skipping 2022/01/09 05:18:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:18:12 DEBUG : Waiting for deletions to finish 2022/01/09 05:18:13 INFO : only7: Deleted 2022/01/09 05:18:13 INFO : only15: Deleted 2022/01/09 05:18:13 INFO : only9: Deleted 2022/01/09 05:18:13 INFO : only14: Deleted 2022/01/09 05:18:14 INFO : only16: Deleted 2022/01/09 05:18:14 INFO : only2: Deleted 2022/01/09 05:18:14 INFO : only18: Deleted 2022/01/09 05:18:14 INFO : only19: Deleted 2022/01/09 05:18:14 INFO : only17: Deleted 2022/01/09 05:18:14 INFO : only3: Deleted 2022/01/09 05:18:14 INFO : only0: Deleted 2022/01/09 05:18:14 INFO : only4: Deleted 2022/01/09 05:18:15 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:18:15 DEBUG : pacer: Rate limited, increasing sleep to 1.137842204s 2022/01/09 05:18:15 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:18:15 DEBUG : pacer: Rate limited, increasing sleep to 2.576822226s 2022/01/09 05:18:15 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:18:15 DEBUG : pacer: Rate limited, increasing sleep to 4.067843964s 2022/01/09 05:18:15 DEBUG : pacer: Reducing sleep to 0s 2022/01/09 05:18:15 INFO : only1: Deleted 2022/01/09 05:18:15 INFO : only10: Deleted 2022/01/09 05:18:17 INFO : only8: Deleted 2022/01/09 05:18:17 INFO : only11: Deleted 2022/01/09 05:18:17 INFO : only5: Deleted 2022/01/09 05:18:17 INFO : only12: Deleted 2022/01/09 05:18:18 INFO : only13: Deleted 2022/01/09 05:18:18 INFO : only6: Deleted 2022/01/09 05:18:18 INFO : There was nothing to transfer --- PASS: TestSyncConcurrentDelete (106.74s) === RUN TestSyncConcurrentTruncate run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0'", Local "Local file system at /tmp/rclone1389598915", Modify Window "1ms" 2022/01/09 05:18:36 DEBUG : both0: md5 = a7ea10b17667096655e5c4814384d5b1 OK 2022/01/09 05:18:38 DEBUG : only0: md5 = db0a62739c953805ef27c837fd2a2c33 OK 2022/01/09 05:18:39 DEBUG : both1: md5 = d677aa3b24bf59c95ea0dca6aafd16b0 OK 2022/01/09 05:18:41 DEBUG : only1: md5 = e7bb47510521991b5ec4bcd20d52f484 OK 2022/01/09 05:18:43 DEBUG : both2: md5 = aa52004f331fef91eacea43934ef3009 OK 2022/01/09 05:18:44 DEBUG : only2: md5 = 428364a3790fefd7b168cec379780005 OK 2022/01/09 05:18:46 DEBUG : both3: md5 = 7f41d81e15647792e8a48a6b866e6657 OK 2022/01/09 05:18:47 DEBUG : only3: md5 = 161b5add6ac112e4f40af4dcaf15bffd OK 2022/01/09 05:18:49 DEBUG : both4: md5 = ae7c890cafaf887798be514fdec46fdd OK 2022/01/09 05:18:51 DEBUG : only4: md5 = 3a56cc7c61e86c5d841bda2b0be5e6f0 OK 2022/01/09 05:18:53 DEBUG : both5: md5 = b5ab554741e76f9083223c2e8ccad7d0 OK 2022/01/09 05:18:54 DEBUG : only5: md5 = 495005670b3bbce25207e83874be1b2d OK 2022/01/09 05:18:56 DEBUG : both6: md5 = 61584f20864beee87ed170984f7798d6 OK 2022/01/09 05:18:58 DEBUG : only6: md5 = cb6b995ecb7e125a08f34f5cbd6b91a0 OK 2022/01/09 05:19:00 DEBUG : both7: md5 = 615bb15ee2b189f3434da4020beef161 OK 2022/01/09 05:19:01 DEBUG : only7: md5 = 3e9796af60a4731bbaaf2a2a6f444548 OK 2022/01/09 05:19:03 DEBUG : both8: md5 = 488143ef6eb97852120f3c9ed720213e OK 2022/01/09 05:19:05 DEBUG : only8: md5 = d576a1ca30c34ed96f1b765e1bffffc5 OK 2022/01/09 05:19:07 DEBUG : both9: md5 = 4080b48a0807fae6ecd9a67358fc3dd9 OK 2022/01/09 05:19:08 DEBUG : only9: md5 = a6fdd4900701c3cd078ba6d005d2de1a OK 2022/01/09 05:19:10 DEBUG : both10: md5 = c551304b66b86b100db742e223e2446a OK 2022/01/09 05:19:11 DEBUG : only10: md5 = be55a4794ca5722f188f1469994c3871 OK 2022/01/09 05:19:13 DEBUG : both11: md5 = 63acff20d61a14407e22f552e7adba57 OK 2022/01/09 05:19:15 DEBUG : only11: md5 = 2516ac9258821f35f0e136d9fed9c1ee OK 2022/01/09 05:19:17 DEBUG : both12: md5 = 08cb603e1eade249b7be074dec80fab5 OK 2022/01/09 05:19:19 DEBUG : only12: md5 = 82564a077ed84403ee87ca36f79f3873 OK 2022/01/09 05:19:20 DEBUG : both13: md5 = 8973ef1759911da77c28a898158295e9 OK 2022/01/09 05:19:22 DEBUG : only13: md5 = 6441cb1241caa87462b55dbdef0b642e OK 2022/01/09 05:19:24 DEBUG : both14: md5 = 0aae911890e040f8906c68d3a07dc63e OK 2022/01/09 05:19:25 DEBUG : only14: md5 = 567c866d737e7b65025c077fd54384b3 OK 2022/01/09 05:19:27 DEBUG : both15: md5 = 491b8705c073f41ee389523820d7527d OK 2022/01/09 05:19:29 DEBUG : only15: md5 = 3921c0b627a7a0cdce78c17097c2f8b8 OK 2022/01/09 05:19:30 DEBUG : both16: md5 = 34c46ff94f6abab518c20c92338fc07c OK 2022/01/09 05:19:32 DEBUG : only16: md5 = 3346a1aac8cc1b56af60ac5019d78ddc OK 2022/01/09 05:19:34 DEBUG : both17: md5 = bb184b685049184f7257a2171eafe9a8 OK 2022/01/09 05:19:36 DEBUG : only17: md5 = 54250b37c492e663d1afdd3db4df0a67 OK 2022/01/09 05:19:37 DEBUG : both18: md5 = 2e94ded149f3f1f3b759be9ff8fe8e59 OK 2022/01/09 05:19:39 DEBUG : only18: md5 = 21cc86b3850bccc442e0019b71cd69de OK 2022/01/09 05:19:41 DEBUG : both19: md5 = 4fd7b81f8ca922660f411129b8343f8c OK 2022/01/09 05:19:42 DEBUG : only19: md5 = 5471034afd8b66c92ae5bc9c629cd852 OK 2022/01/09 05:19:43 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both0: Unchanged skipping 2022/01/09 05:19:43 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both11: Unchanged skipping 2022/01/09 05:19:43 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both12: Unchanged skipping 2022/01/09 05:19:43 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both13: Unchanged skipping 2022/01/09 05:19:43 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both1: Unchanged skipping 2022/01/09 05:19:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for checks to finish 2022/01/09 05:19:43 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both15: Unchanged skipping 2022/01/09 05:19:43 DEBUG : both16: Unchanged skipping 2022/01/09 05:19:43 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both10: Unchanged skipping 2022/01/09 05:19:43 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both18: Unchanged skipping 2022/01/09 05:19:43 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both19: Unchanged skipping 2022/01/09 05:19:43 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both3: Unchanged skipping 2022/01/09 05:19:43 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both14: Unchanged skipping 2022/01/09 05:19:43 DEBUG : both17: Unchanged skipping 2022/01/09 05:19:43 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both5: Unchanged skipping 2022/01/09 05:19:43 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both6: Unchanged skipping 2022/01/09 05:19:43 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both7: Unchanged skipping 2022/01/09 05:19:43 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both2: Unchanged skipping 2022/01/09 05:19:43 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both4: Unchanged skipping 2022/01/09 05:19:43 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/09 05:19:43 DEBUG : both9: Unchanged skipping 2022/01/09 05:19:43 DEBUG : both8: Unchanged skipping 2022/01/09 05:19:43 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2022/01/09 05:19:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Waiting for transfers to finish 2022/01/09 05:19:44 DEBUG : only0: md5 = 74a32bb16af69dc846d16a67b82bbb87 OK 2022/01/09 05:19:44 INFO : only0: Copied (replaced existing) 2022/01/09 05:19:45 DEBUG : only11: md5 = b53b367e9e81e2373252b29fc135345e OK 2022/01/09 05:19:45 INFO : only11: Copied (replaced existing) 2022/01/09 05:19:45 DEBUG : only10: md5 = 3b6509c0f5e23f774da3235ae9cbd52f OK 2022/01/09 05:19:45 INFO : only10: Copied (replaced existing) 2022/01/09 05:19:45 DEBUG : only1: md5 = 090528784ecb17b5a371196c39d35e7a OK 2022/01/09 05:19:45 INFO : only1: Copied (replaced existing) 2022/01/09 05:19:46 DEBUG : only12: md5 = 47716a97b7c5d4740e98e9135942abf9 OK 2022/01/09 05:19:46 INFO : only12: Copied (replaced existing) 2022/01/09 05:19:46 DEBUG : only13: md5 = 9de5b9524e1af6bd2ef5d05bae0ae684 OK 2022/01/09 05:19:46 INFO : only13: Copied (replaced existing) 2022/01/09 05:19:46 DEBUG : only14: md5 = 8e82092d2d3295c5f42680123ce57ad9 OK 2022/01/09 05:19:46 INFO : only14: Copied (replaced existing) 2022/01/09 05:19:46 DEBUG : only15: md5 = 25a1b927cb753e9a294976930c531b1c OK 2022/01/09 05:19:46 INFO : only15: Copied (replaced existing) 2022/01/09 05:19:47 DEBUG : only16: md5 = a9ce90b5bd8c0eaeec2576bfd32970ee OK 2022/01/09 05:19:47 INFO : only16: Copied (replaced existing) 2022/01/09 05:19:47 DEBUG : only17: md5 = 7cdc06d37f34d7998e39c00ccda7b939 OK 2022/01/09 05:19:47 INFO : only17: Copied (replaced existing) 2022/01/09 05:19:47 DEBUG : only18: md5 = 7e1c3d614bb180ad5105246deb868868 OK 2022/01/09 05:19:47 INFO : only18: Copied (replaced existing) 2022/01/09 05:19:47 DEBUG : only2: md5 = ddac4c1deb361089b49e06ddada49575 OK 2022/01/09 05:19:47 INFO : only2: Copied (replaced existing) 2022/01/09 05:19:48 DEBUG : only3: md5 = 3d7f3be55aa44ee844ee362acd1750d5 OK 2022/01/09 05:19:48 INFO : only3: Copied (replaced existing) 2022/01/09 05:19:48 DEBUG : only5: md5 = 925654ab85d5388906e5248ae7aa443e OK 2022/01/09 05:19:48 INFO : only5: Copied (replaced existing) 2022/01/09 05:19:49 DEBUG : only4: md5 = 42b9bfad5c0e15e871b528388a5607e8 OK 2022/01/09 05:19:49 INFO : only4: Copied (replaced existing) 2022/01/09 05:19:49 DEBUG : only6: md5 = 20b86ef530e2947e8d01da7495883f91 OK 2022/01/09 05:19:49 INFO : only6: Copied (replaced existing) 2022/01/09 05:19:50 DEBUG : only7: md5 = ebfd9beb26b17ad6d93c4b06c3cd16cf OK 2022/01/09 05:19:50 INFO : only7: Copied (replaced existing) 2022/01/09 05:19:50 DEBUG : only8: md5 = 1918631c264307d15f6a414176f3ceb0 OK 2022/01/09 05:19:50 INFO : only8: Copied (replaced existing) 2022/01/09 05:19:50 DEBUG : only9: md5 = c5c75bbf660ceed55579bdefc98d5e55 OK 2022/01/09 05:19:50 INFO : only9: Copied (replaced existing) 2022/01/09 05:19:50 DEBUG : only19: md5 = 49cf8ad3ec0f9ff9b240ac07f5509ec2 OK 2022/01/09 05:19:50 INFO : only19: Copied (replaced existing) 2022/01/09 05:19:50 DEBUG : Waiting for deletions to finish 2022/01/09 05:19:55 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:19:55 DEBUG : pacer: Rate limited, increasing sleep to 1.539186033s 2022/01/09 05:19:56 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/01/09 05:19:56 DEBUG : pacer: Rate limited, increasing sleep to 2.07455735s 2022/01/09 05:19:58 DEBUG : pacer: Reducing sleep to 0s --- PASS: TestSyncConcurrentTruncate (107.65s) PASS 2022/01/09 05:20:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-noqatup0kaqiqit6kobiniy0': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 18m7.890451684s (try 1/5)