"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5) 2022/01/13 06:12:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5" 2022/01/13 06:12:26 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2022/01/13 06:12:26 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o" 2022/01/13 06:12:27 DEBUG : Creating backend with remote "/tmp/rclone2772509430" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.02s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:12: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/13 06:12:28 DEBUG : pacer: Rate limited, increasing sleep to 1.364811915s 2022/01/13 06:12:28 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:12:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:12:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:12:30 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2022/01/13 06:12: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/13 06:12:30 DEBUG : pacer: Rate limited, increasing sleep to 1.055932923s 2022/01/13 06:12:31 DEBUG : pacer: Reducing sleep to 0s --- PASS: TestCopyWithDryRun (3.37s) === RUN TestCopy run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:12:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:12:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:12:34 DEBUG : sub dir/hello world: md5 = 08d9d20fcd53921c3a054ab27964b321 OK 2022/01/13 06:12:34 INFO : sub dir/hello world: Copied (new) 2022/01/13 06:12:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (6.40s) === RUN TestCopyMissingDirectory run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:12:37 DEBUG : Creating backend with remote "/non-existing" 2022/01/13 06:12:37 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2022/01/13 06:12:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:12:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish --- PASS: TestCopyMissingDirectory (0.82s) === RUN TestCopyNoTraverse run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:12:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:12:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:12:41 DEBUG : sub dir/hello world: md5 = 6afaa12498099bf67d97889443cf7c62 OK 2022/01/13 06:12:41 INFO : sub dir/hello world: Copied (new) 2022/01/13 06:12:43 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (5.56s) === RUN TestCopyCheckFirst run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:12:44 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Running all checks before starting transfers 2022/01/13 06:12:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:12:44 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Checks finished, now starting transfers 2022/01/13 06:12:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:12:46 DEBUG : sub dir/hello world: md5 = 61c31b3def3d8efa0143f4a0e653c152 OK 2022/01/13 06:12:46 INFO : sub dir/hello world: Copied (new) 2022/01/13 06:12:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (5.62s) === RUN TestSyncNoTraverse run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:12:49 ERROR : Ignoring --no-traverse with sync 2022/01/13 06:12:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:12:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:12:52 DEBUG : sub dir/hello world: md5 = ab55d8478ab3d4e93da959a4e256adfa OK 2022/01/13 06:12:52 INFO : sub dir/hello world: Copied (new) 2022/01/13 06:12:52 DEBUG : Waiting for deletions to finish 2022/01/13 06:12:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (5.63s) === RUN TestCopyWithDepth run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:12:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:12:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:12:57 DEBUG : hello world2: md5 = 9948365cb0daacde17803086f545b8c1 OK 2022/01/13 06:12:57 INFO : hello world2: Copied (new) --- PASS: TestCopyWithDepth (3.20s) === RUN TestCopyWithFilesFrom run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:12:58 DEBUG : hello world2: Excluded 2022/01/13 06:12:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:12:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:13:00 DEBUG : potato2: md5 = 1f9197fddc922c817b55e39fb9b35574 OK 2022/01/13 06:13:00 INFO : potato2: Copied (new) --- PASS: TestCopyWithFilesFrom (3.20s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:13:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:13:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:13:03 DEBUG : potato2: md5 = 38bcda30071715bbb4b3e3c109110c1e OK 2022/01/13 06:13:03 INFO : potato2: Copied (new) --- PASS: TestCopyWithFilesFromAndNoTraverse (3.11s) === RUN TestCopyEmptyDirectories run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:13:04 DEBUG : sub dir2: Making directory 2022/01/13 06:13:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:13:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:13:07 DEBUG : sub dir/hello world: md5 = 30ec7e00eeac3dd0613a996344da29b5 OK 2022/01/13 06:13:07 INFO : sub dir/hello world: Copied (new) 2022/01/13 06:13:07 DEBUG : sub dir2: Making directory 2022/01/13 06:13:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': copied 1 directories 2022/01/13 06:13:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (7.31s) === RUN TestMoveEmptyDirectories run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:13:12 DEBUG : sub dir2: Making directory 2022/01/13 06:13:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:13:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:13:14 DEBUG : sub dir/hello world: md5 = 7c03c7316cd2a11e88a89e4e29b1500c OK 2022/01/13 06:13:14 INFO : sub dir/hello world: Copied (new) 2022/01/13 06:13:14 INFO : sub dir/hello world: Deleted 2022/01/13 06:13:14 DEBUG : sub dir2: Making directory 2022/01/13 06:13:15 DEBUG : sub dir: Making directory 2022/01/13 06:13:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': copied 2 directories 2022/01/13 06:13:18 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (7.32s) === RUN TestSyncEmptyDirectories run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:13:19 DEBUG : sub dir2: Making directory 2022/01/13 06:13:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:13:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:13:21 DEBUG : sub dir/hello world: md5 = 2ea9ea99e6fbb76ba77e84ed55351f1e OK 2022/01/13 06:13:21 INFO : sub dir/hello world: Copied (new) 2022/01/13 06:13:21 DEBUG : sub dir2: Making directory 2022/01/13 06:13:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': copied 1 directories 2022/01/13 06:13:22 DEBUG : Waiting for deletions to finish 2022/01/13 06:13:25 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (7.26s) === RUN TestServerSideCopy run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:13:29 DEBUG : sub dir/hello world: md5 = 0a458134c2f2367693250536f9235f09 OK 2022/01/13 06:13:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-womekak7yibohan1texeyug6" 2022/01/13 06:13:29 DEBUG : Creating backend with remote "TestDrive:crypt/a9tvpou2m74odv5iscvcpj9jiv0m1764j337nq78chrtoahdh288uei6tmqpb9pjifss9th4ljtkk" sync_test.go:275: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5' -> Encrypted drive 'TestCryptDrive:rclone-test-womekak7yibohan1texeyug6' 2022/01/13 06:13:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-womekak7yibohan1texeyug6': Waiting for checks to finish 2022/01/13 06:13:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-womekak7yibohan1texeyug6': Waiting for transfers to finish 2022/01/13 06:13:31 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/13 06:13:31 DEBUG : pacer: Rate limited, increasing sleep to 1.801342379s 2022/01/13 06:13:32 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/13 06:13:32 DEBUG : pacer: Rate limited, increasing sleep to 2.685522414s 2022/01/13 06:13:33 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:13:38 INFO : sub dir/hello world: Copied (server-side copy) 2022/01/13 06:13:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-womekak7yibohan1texeyug6': Purge remote 2022/01/13 06:13:41 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (15.76s) === RUN TestCopyAfterDelete run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:13:44 DEBUG : sub dir/hello world: md5 = e9bb7c9cc96c83673786a748f1c719dd OK 2022/01/13 06:13:44 ERROR : : error listing: directory not found 2022/01/13 06:13:45 DEBUG : Local file system at /tmp/rclone2772509430: Making directory 2022/01/13 06:13:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:13:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:13: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/13 06:13:46 DEBUG : pacer: Rate limited, increasing sleep to 1.198037625s 2022/01/13 06:13:46 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/13 06:13:46 DEBUG : pacer: Rate limited, increasing sleep to 2.51823112s 2022/01/13 06:13:48 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:13:51 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (9.64s) === RUN TestCopyRedownload run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:13:54 DEBUG : sub dir/hello world: md5 = cfced6d83d687ec7ff9c8e682989d64d OK 2022/01/13 06:13:55 DEBUG : Local file system at /tmp/rclone2772509430: Waiting for checks to finish 2022/01/13 06:13:55 DEBUG : Local file system at /tmp/rclone2772509430: Waiting for transfers to finish 2022/01/13 06:13:56 INFO : sub dir/hello world: Copied (new) 2022/01/13 06:13: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/13 06:13:57 DEBUG : pacer: Rate limited, increasing sleep to 1.524281301s 2022/01/13 06:13:58 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/13 06:13:58 DEBUG : pacer: Rate limited, increasing sleep to 2.439231208s 2022/01/13 06:13:59 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:13:59 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (10.60s) === RUN TestSyncBasedOnCheckSum run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:14:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:14:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:14:04 DEBUG : check sum: md5 = 8f0744fd0fa6d12ffccf7bbb8bf368ec OK 2022/01/13 06:14:04 INFO : check sum: Copied (new) 2022/01/13 06:14:04 DEBUG : Waiting for deletions to finish 2022/01/13 06:14:04 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2022/01/13 06:14:04 DEBUG : check sum: Size of src and dst objects identical 2022/01/13 06:14:04 DEBUG : check sum: Unchanged skipping 2022/01/13 06:14:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:14:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:14:04 DEBUG : Waiting for deletions to finish 2022/01/13 06:14:04 INFO : There was nothing to transfer --- PASS: TestSyncBasedOnCheckSum (3.68s) === RUN TestSyncSizeOnly run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:14:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:14:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:14:07 DEBUG : sizeonly: md5 = 62d9d133c73174c78918eec5f29d695d OK 2022/01/13 06:14:07 INFO : sizeonly: Copied (new) 2022/01/13 06:14:07 DEBUG : Waiting for deletions to finish 2022/01/13 06:14:08 DEBUG : sizeonly: Sizes identical 2022/01/13 06:14:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:14:08 DEBUG : sizeonly: Unchanged skipping 2022/01/13 06:14:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:14:08 DEBUG : Waiting for deletions to finish 2022/01/13 06:14:08 INFO : There was nothing to transfer --- PASS: TestSyncSizeOnly (3.73s) === RUN TestSyncIgnoreSize run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:14:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:14:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:14:11 DEBUG : ignore-size: md5 = cdb4c04133fe8acbe3037ab49bcfc3af OK 2022/01/13 06:14:11 INFO : ignore-size: Copied (new) 2022/01/13 06:14:11 DEBUG : Waiting for deletions to finish 2022/01/13 06:14:12 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:14:12 DEBUG : ignore-size: Unchanged skipping 2022/01/13 06:14:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:14:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:14:12 DEBUG : Waiting for deletions to finish 2022/01/13 06:14:12 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreSize (3.64s) === RUN TestSyncIgnoreTimes run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:14:15 DEBUG : existing: md5 = f42a88cdcfd02c795c11a91d9ccba68f OK 2022/01/13 06:14:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:14:15 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:14:15 DEBUG : existing: Unchanged skipping 2022/01/13 06:14:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:14:15 DEBUG : Waiting for deletions to finish 2022/01/13 06:14:15 INFO : There was nothing to transfer 2022/01/13 06:14:16 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2022/01/13 06:14:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:14:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:14:17 DEBUG : existing: md5 = 09f7c7a4984ca1f4bdbf99bf7e9ec9d3 OK 2022/01/13 06:14:17 INFO : existing: Copied (replaced existing) 2022/01/13 06:14:17 DEBUG : Waiting for deletions to finish 2022/01/13 06:14: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/13 06:14:17 DEBUG : pacer: Rate limited, increasing sleep to 1.681056483s 2022/01/13 06:14:17 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/13 06:14:17 DEBUG : pacer: Rate limited, increasing sleep to 2.453652529s 2022/01/13 06:14:19 DEBUG : pacer: Reducing sleep to 0s --- PASS: TestSyncIgnoreTimes (8.96s) === RUN TestSyncIgnoreExisting run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:14:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:14:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:14:24 DEBUG : existing: md5 = 70f50988a36c4bbbb467ebc9dc69f89b OK 2022/01/13 06:14:24 INFO : existing: Copied (new) 2022/01/13 06:14:24 DEBUG : Waiting for deletions to finish 2022/01/13 06:14:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:14:24 DEBUG : existing: Destination exists, skipping 2022/01/13 06:14:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:14:24 DEBUG : Waiting for deletions to finish 2022/01/13 06:14:24 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreExisting (3.68s) === RUN TestSyncIgnoreErrors run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:14:28 DEBUG : b/potato: md5 = b1a6ce5860f4a9473fb951441eadbf1c OK 2022/01/13 06:14:31 DEBUG : c/non empty space: md5 = 21196c0e53de6a6460fde59a7b3db7d7 OK 2022/01/13 06:14:31 DEBUG : d: Making directory 2022/01/13 06:14:33 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:14:33 DEBUG : c/non empty space: Unchanged skipping 2022/01/13 06:14:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:14:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:14:34 DEBUG : a/potato2: md5 = 70238af5fa3798e9a335d2271d32fa0e OK 2022/01/13 06:14:34 INFO : a/potato2: Copied (new) 2022/01/13 06:14:34 DEBUG : Waiting for deletions to finish 2022/01/13 06:14:35 INFO : b/potato: Deleted 2022/01/13 06:14:35 INFO : d: Removing directory 2022/01/13 06:14:36 INFO : b: Removing directory 2022/01/13 06:14: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/13 06:14:36 DEBUG : pacer: Rate limited, increasing sleep to 1.030316216s 2022/01/13 06:14:36 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/13 06:14:36 DEBUG : pacer: Rate limited, increasing sleep to 2.633939208s 2022/01/13 06:14:37 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/13 06:14:37 DEBUG : pacer: Rate limited, increasing sleep to 4.963637013s 2022/01/13 06:14:40 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:14:40 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2022/01/13 06:14:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': deleted 2 directories 2022/01/13 06:14:48 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2022/01/13 06:14:49 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (23.56s) === RUN TestSyncAfterChangingModtimeOnly run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:14:51 DEBUG : empty space: md5 = 1556857d070d16bd90cbf18d5cead16b OK 2022/01/13 06:14:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:14:51 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/13 06:14:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:14:51 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2022/01/13 06:14:51 DEBUG : Waiting for deletions to finish 2022/01/13 06:14:52 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/13 06:14:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:14:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:14:53 DEBUG : empty space: md5 = 2a119e729e52ac28038e16e4025ba113 OK 2022/01/13 06:14:53 INFO : empty space: Copied (replaced existing) 2022/01/13 06:14:53 DEBUG : Waiting for deletions to finish --- PASS: TestSyncAfterChangingModtimeOnly (5.12s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" sync_test.go:577: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.58s) === RUN TestSyncDoesntUpdateModtime run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:14:57 DEBUG : foo: md5 = 595ca3a8fa49332d32560619d3cd18d8 OK 2022/01/13 06:14: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/13 06:14:57 DEBUG : pacer: Rate limited, increasing sleep to 1.707832444s 2022/01/13 06:14:57 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/13 06:14:57 DEBUG : pacer: Rate limited, increasing sleep to 2.662912017s 2022/01/13 06:14:59 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:15:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:15:01 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/13 06:15:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:15:03 DEBUG : foo: md5 = 3a74d6e3f78f6a23974339d056ce1140 OK 2022/01/13 06:15:03 INFO : foo: Copied (replaced existing) 2022/01/13 06:15:03 DEBUG : Waiting for deletions to finish --- PASS: TestSyncDoesntUpdateModtime (8.83s) === RUN TestSyncAfterAddingAFile run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:15:06 DEBUG : empty space: md5 = 43cadc9cc88d9843a026fbe1f38b2b3b OK 2022/01/13 06:15:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:15:06 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:15:06 DEBUG : empty space: Unchanged skipping 2022/01/13 06:15:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:15:07 DEBUG : potato: md5 = 438631d2e23447ad80fad50d98629c06 OK 2022/01/13 06:15:07 INFO : potato: Copied (new) 2022/01/13 06:15:07 DEBUG : Waiting for deletions to finish --- PASS: TestSyncAfterAddingAFile (5.64s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:15:11 DEBUG : potato: md5 = dfa329d0746bf73b1bd44d070b010ce4 OK 2022/01/13 06:15:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:15:12 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2022/01/13 06:15:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:15:13 DEBUG : potato: md5 = 55e868c1d14608ea75dbcbf0ece68ae1 OK 2022/01/13 06:15:13 INFO : potato: Copied (replaced existing) 2022/01/13 06:15:13 DEBUG : Waiting for deletions to finish --- PASS: TestSyncAfterChangingFilesSizeOnly (4.58s) === RUN TestSyncAfterChangingContentsOnly run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:15:16 DEBUG : potato: md5 = 0923eaa033a506581313ca6bff9aaa6c OK 2022/01/13 06:15: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/13 06:15:16 DEBUG : pacer: Rate limited, increasing sleep to 1.262046247s 2022/01/13 06:15:16 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/13 06:15:16 DEBUG : pacer: Rate limited, increasing sleep to 2.473658504s 2022/01/13 06:15:17 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/13 06:15:17 DEBUG : pacer: Rate limited, increasing sleep to 4.567101825s 2022/01/13 06:15:20 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:15:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:15:24 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/13 06:15:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:15:25 DEBUG : potato: md5 = ecb0b1e7516d4ed64f6add9b891a825c OK 2022/01/13 06:15:25 INFO : potato: Copied (replaced existing) 2022/01/13 06:15:25 DEBUG : Waiting for deletions to finish --- PASS: TestSyncAfterChangingContentsOnly (12.71s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:15:29 DEBUG : potato: md5 = 71817b4d8acd3e7a964f732732af0bbe OK 2022/01/13 06:15:30 DEBUG : empty space: md5 = 7799c5b392225dfcf1da3ed66cc51103 OK 2022/01/13 06:15:30 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2022/01/13 06:15:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:15:30 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:15:30 DEBUG : empty space: Unchanged skipping 2022/01/13 06:15:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:15:30 DEBUG : Waiting for deletions to finish 2022/01/13 06:15:30 NOTICE: potato: Skipped delete as --dry-run is set (size 21) 2022/01/13 06:15: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/13 06:15:32 DEBUG : pacer: Rate limited, increasing sleep to 1.039990558s 2022/01/13 06:15:32 DEBUG : pacer: Reducing sleep to 0s --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.95s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:15:34 DEBUG : potato: md5 = e5a6a698fa7fce111de4cbabdafc1a46 OK 2022/01/13 06:15:36 DEBUG : empty space: md5 = 33b9fc3bd8c01eb8887ee7782ae58b9e OK 2022/01/13 06:15:36 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:15:36 DEBUG : empty space: Unchanged skipping 2022/01/13 06:15:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:15:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:15:38 DEBUG : potato2: md5 = 68f026a9d67357cf76a725e104411936 OK 2022/01/13 06:15:38 INFO : potato2: Copied (new) 2022/01/13 06:15:38 DEBUG : Waiting for deletions to finish 2022/01/13 06:15:38 INFO : potato: Deleted --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.41s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:15:43 DEBUG : b/potato: md5 = 890a4c8e9c0beb70ac6c30cb6b15bcbc OK 2022/01/13 06:15:45 DEBUG : c/non empty space: md5 = 2f13b8e50b307837d498a5c6daa1486d OK 2022/01/13 06:15:45 DEBUG : d: Making directory 2022/01/13 06:15:46 DEBUG : d/e: Making directory 2022/01/13 06:15: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/13 06:15:47 DEBUG : pacer: Rate limited, increasing sleep to 1.816723398s 2022/01/13 06:15: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/13 06:15:47 DEBUG : pacer: Rate limited, increasing sleep to 2.905190504s 2022/01/13 06:15:47 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:15:47 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/13 06:15:47 DEBUG : pacer: Rate limited, increasing sleep to 1.050629156s 2022/01/13 06:15:49 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:15:51 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:15:51 DEBUG : c/non empty space: Unchanged skipping 2022/01/13 06:15:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:15:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:15:53 DEBUG : a/potato2: md5 = cccb383fffd16932ec64377d6b308da8 OK 2022/01/13 06:15:53 INFO : a/potato2: Copied (new) 2022/01/13 06:15:53 DEBUG : Waiting for deletions to finish 2022/01/13 06:15:54 INFO : b/potato: Deleted 2022/01/13 06:15:54 INFO : d/e: Removing directory 2022/01/13 06:15:54 INFO : d: Removing directory 2022/01/13 06:15:55 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2022/01/13 06:15:55 INFO : b: Removing directory 2022/01/13 06:15: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/13 06:15:55 DEBUG : pacer: Rate limited, increasing sleep to 1.601750649s 2022/01/13 06:15: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/13 06:15:56 DEBUG : pacer: Rate limited, increasing sleep to 2.092832429s 2022/01/13 06:15:57 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:15:57 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2022/01/13 06:16:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': deleted 3 directories 2022/01/13 06:16:02 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2022/01/13 06:16:03 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (23.55s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:16:06 DEBUG : b/potato: md5 = 433a69ce65d1483e8cad806cd779366d OK 2022/01/13 06:16: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/13 06:16:07 DEBUG : pacer: Rate limited, increasing sleep to 1.17599445s run.go:283: Retry Put of "c/non empty space" to Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': 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/13 06:16:10 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:16:12 DEBUG : c/non empty space: md5 = 148de590abe3b06c72742f765e174d47 OK 2022/01/13 06:16:12 DEBUG : d: Making directory 2022/01/13 06:16:14 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/13 06:16:14 DEBUG : pacer: Rate limited, increasing sleep to 1.029645161s 2022/01/13 06:16:14 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/13 06:16:14 DEBUG : pacer: Rate limited, increasing sleep to 2.560984831s 2022/01/13 06:16:14 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/13 06:16:14 DEBUG : pacer: Rate limited, increasing sleep to 4.395204209s 2022/01/13 06:16:14 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:16:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:16:15 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:16:15 DEBUG : c/non empty space: Unchanged skipping 2022/01/13 06:16:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:16:17 DEBUG : a/potato2: md5 = 9ff9ff12c6120662111b49f112b4465c OK 2022/01/13 06:16:17 INFO : a/potato2: Copied (new) 2022/01/13 06:16:17 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': not deleting files as there were IO errors 2022/01/13 06:16:17 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': not deleting directories as there were IO errors 2022/01/13 06:16:21 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2022/01/13 06:16:22 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2022/01/13 06:16:23 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (19.56s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:16:25 DEBUG : potato: md5 = a12a84581992456e0f75e24c61b4617c OK 2022/01/13 06:16:26 DEBUG : empty space: md5 = 88b55ba5237fcee981a0da2b0193babc OK 2022/01/13 06:16:27 DEBUG : Waiting for deletions to finish 2022/01/13 06:16:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:16:27 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:16:27 DEBUG : empty space: Unchanged skipping 2022/01/13 06:16:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:16: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/13 06:16:27 DEBUG : pacer: Rate limited, increasing sleep to 1.790316401s 2022/01/13 06:16:27 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/13 06:16:27 DEBUG : pacer: Rate limited, increasing sleep to 2.761839232s 2022/01/13 06:16:28 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:16:28 INFO : potato: Deleted 2022/01/13 06:16:30 DEBUG : potato2: md5 = 9603fcb2169619f2a5203498620dc5e7 OK 2022/01/13 06:16:30 INFO : potato2: Copied (new) --- PASS: TestSyncDeleteDuring (8.98s) === RUN TestSyncDeleteBefore run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:16:34 DEBUG : potato: md5 = 7db5d736a2929b89041c809b81dd4d42 OK 2022/01/13 06:16:35 DEBUG : empty space: md5 = e0e7012acd763d9b9c2f90af8b5b7726 OK 2022/01/13 06:16:36 DEBUG : Waiting for deletions to finish 2022/01/13 06:16:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:16:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:16:37 INFO : potato: Deleted 2022/01/13 06:16:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:16:37 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:16:37 DEBUG : empty space: Unchanged skipping 2022/01/13 06:16:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:16:38 DEBUG : potato2: md5 = 1f3815ea441ae19d5624c9731244ddc5 OK 2022/01/13 06:16:38 INFO : potato2: Copied (new) --- PASS: TestSyncDeleteBefore (7.75s) === RUN TestCopyDeleteBefore run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:16:41 DEBUG : potato: md5 = 11bbfa732314b0b224b1a227bf6d0503 OK 2022/01/13 06:16:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:16:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:16:43 DEBUG : potato2: md5 = e29359ab686447d57a5f18a036670cb2 OK 2022/01/13 06:16:43 INFO : potato2: Copied (new) --- PASS: TestCopyDeleteBefore (5.47s) === RUN TestSyncWithExclude run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:16:47 DEBUG : potato2: md5 = ff773c842b1191a671e58faa7de8d740 OK 2022/01/13 06:16: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/13 06:16:48 DEBUG : pacer: Rate limited, increasing sleep to 1.848983035s 2022/01/13 06:16: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/13 06:16:48 DEBUG : pacer: Rate limited, increasing sleep to 2.122835993s 2022/01/13 06:16:50 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:16:53 DEBUG : empty space: md5 = f53a5e9b80d09fafa43c1030fddb1470 OK 2022/01/13 06:16:53 DEBUG : enormous: Excluded 2022/01/13 06:16:53 DEBUG : potato2: Excluded 2022/01/13 06:16:53 DEBUG : potato2: Excluded 2022/01/13 06:16:53 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:16:53 DEBUG : empty space: Unchanged skipping 2022/01/13 06:16:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:16:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:16:53 DEBUG : Waiting for deletions to finish 2022/01/13 06:16:53 INFO : There was nothing to transfer 2022/01/13 06:16:54 DEBUG : enormous: Excluded 2022/01/13 06:16:54 DEBUG : potato2: Excluded 2022/01/13 06:16:54 DEBUG : potato2: Excluded 2022/01/13 06:16:54 DEBUG : Local file system at /tmp/rclone2772509430: Waiting for checks to finish 2022/01/13 06:16:54 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2022/01/13 06:16:54 DEBUG : empty space: Unchanged skipping 2022/01/13 06:16:54 DEBUG : Local file system at /tmp/rclone2772509430: Waiting for transfers to finish 2022/01/13 06:16:54 DEBUG : Waiting for deletions to finish 2022/01/13 06:16:54 INFO : There was nothing to transfer --- PASS: TestSyncWithExclude (10.08s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:16:57 DEBUG : potato2: md5 = b2b2f1cf2be90b416474f7575ca90f2c OK 2022/01/13 06:16:58 DEBUG : empty space: md5 = 8a209f674ba723a87ed4b792b284aaef OK 2022/01/13 06:17:00 DEBUG : enormous: md5 = 21626c0a63eb961bb79f890eda728136 OK 2022/01/13 06:17:00 DEBUG : enormous: Excluded 2022/01/13 06:17:00 DEBUG : potato2: Excluded 2022/01/13 06:17:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:17:00 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:17:00 DEBUG : empty space: Unchanged skipping 2022/01/13 06:17:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:17:00 DEBUG : Waiting for deletions to finish 2022/01/13 06:17:01 INFO : potato2: Deleted 2022/01/13 06:17:01 INFO : enormous: Deleted 2022/01/13 06:17:01 INFO : There was nothing to transfer 2022/01/13 06:17:02 DEBUG : Local file system at /tmp/rclone2772509430: Waiting for checks to finish 2022/01/13 06:17:02 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2022/01/13 06:17:02 DEBUG : empty space: Unchanged skipping 2022/01/13 06:17:02 DEBUG : Local file system at /tmp/rclone2772509430: Waiting for transfers to finish 2022/01/13 06:17:02 DEBUG : Waiting for deletions to finish 2022/01/13 06:17:02 INFO : enormous: Deleted 2022/01/13 06:17:02 INFO : potato2: Deleted 2022/01/13 06:17:02 INFO : There was nothing to transfer --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.09s) === RUN TestSyncWithUpdateOlder run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:17:04 DEBUG : one: md5 = b871e47f9c0d96f1983f248ed0bd9dbf OK 2022/01/13 06:17:06 DEBUG : two: md5 = 28ca63f22dfc375512c803e703d00d90 OK 2022/01/13 06:17:07 DEBUG : three: md5 = 02a1457a0134be2c69a43df76416de1c OK 2022/01/13 06:17:07 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/13 06:17:07 DEBUG : pacer: Rate limited, increasing sleep to 1.616829808s 2022/01/13 06:17: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/13 06:17:08 DEBUG : pacer: Rate limited, increasing sleep to 2.48873817s 2022/01/13 06:17:09 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:17:13 DEBUG : four: md5 = e19e7fe32d48e35aa36d40a6ce6e7755 OK 2022/01/13 06:17:13 DEBUG : four: Sizes differ (src 4 vs dst 8) 2022/01/13 06:17:13 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2022/01/13 06:17:13 DEBUG : three: Sizes identical 2022/01/13 06:17:13 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2022/01/13 06:17:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:17:13 DEBUG : one: Destination is newer than source, skipping 2022/01/13 06:17:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:17:14 DEBUG : four: md5 = eb99c34bc562849619f2c1f1c22939bb OK 2022/01/13 06:17:14 INFO : four: Copied (replaced existing) 2022/01/13 06:17:14 DEBUG : two: md5 = 76a2eeb84a329dac18512df92690ddcc OK 2022/01/13 06:17:14 INFO : two: Copied (replaced existing) 2022/01/13 06:17:15 DEBUG : five: md5 = 5349c19c5b24376df0a00632e92310fa OK 2022/01/13 06:17:15 INFO : five: Copied (new) 2022/01/13 06:17:15 DEBUG : Waiting for deletions to finish sync_test.go:992: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (15.08s) === 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-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" sync_test.go:1058: Can track renames: false 2022/01/13 06:17:18 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Ignoring --track-renames as the source and destination do not have a common hash 2022/01/13 06:17:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:17:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:17:18 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/13 06:17:18 DEBUG : pacer: Rate limited, increasing sleep to 1.306863514s 2022/01/13 06:17:18 DEBUG : yam: 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/13 06:17:19 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:17:19 DEBUG : potato: md5 = add7a2901cadace4fc94a47e6183ad6e OK 2022/01/13 06:17:19 INFO : potato: Copied (new) 2022/01/13 06:17:21 DEBUG : yam: md5 = 9958e6380b461b7992100ab52c9e34ec OK 2022/01/13 06:17:21 INFO : yam: Copied (new) 2022/01/13 06:17:21 DEBUG : Waiting for deletions to finish 2022/01/13 06:17:21 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Ignoring --track-renames as the source and destination do not have a common hash 2022/01/13 06:17:21 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:17:21 DEBUG : potato: Unchanged skipping 2022/01/13 06:17:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:17:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:17:23 DEBUG : yaml: md5 = f25757f82ea3ebaca4ad636bf79f3f16 OK 2022/01/13 06:17:23 INFO : yaml: Copied (new) 2022/01/13 06:17:23 DEBUG : Waiting for deletions to finish 2022/01/13 06:17:23 INFO : yam: Deleted --- PASS: TestSyncWithTrackRenames (7.22s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" sync_test.go:1127: Can track renames: true 2022/01/13 06:17:25 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Making map for --track-renames 2022/01/13 06:17:25 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Finished making map for --track-renames 2022/01/13 06:17:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:17:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for renames to finish 2022/01/13 06:17:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:17:27 DEBUG : potato: md5 = 4d3adef5e039516a88830caf91cb70c1 OK 2022/01/13 06:17:27 INFO : potato: Copied (new) 2022/01/13 06:17:27 DEBUG : yam: md5 = fc958342af9e189e1ec0bf0d7e06346b OK 2022/01/13 06:17:27 INFO : yam: Copied (new) 2022/01/13 06:17:27 DEBUG : Waiting for deletions to finish 2022/01/13 06:17:28 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:17:28 DEBUG : potato: Unchanged skipping 2022/01/13 06:17:28 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Making map for --track-renames 2022/01/13 06:17:28 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Finished making map for --track-renames 2022/01/13 06:17:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:17:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for renames to finish 2022/01/13 06:17: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/13 06:17:28 DEBUG : pacer: Rate limited, increasing sleep to 1.328682917s 2022/01/13 06:17: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/13 06:17:28 DEBUG : pacer: Rate limited, increasing sleep to 2.272586196s 2022/01/13 06:17:30 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:17:30 INFO : yam: Moved (server-side) to: yaml 2022/01/13 06:17:30 INFO : yaml: Renamed from "yam" 2022/01/13 06:17:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:17:30 DEBUG : Waiting for deletions to finish 2022/01/13 06:17:30 INFO : There was nothing to transfer --- PASS: TestSyncWithTrackRenamesStrategyModtime (8.49s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" sync_test.go:1163: Can track renames: true 2022/01/13 06:17:34 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Making map for --track-renames 2022/01/13 06:17:34 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Finished making map for --track-renames 2022/01/13 06:17:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:17:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for renames to finish 2022/01/13 06:17:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:17:36 DEBUG : potato: md5 = a8a2069cc444b6ebda79e5aae83847d4 OK 2022/01/13 06:17:36 INFO : potato: Copied (new) 2022/01/13 06:17:36 DEBUG : sub/yam: md5 = 39697f76d4e243c51a143eaf958a6dc9 OK 2022/01/13 06:17:36 INFO : sub/yam: Copied (new) 2022/01/13 06:17:36 DEBUG : Waiting for deletions to finish 2022/01/13 06:17:37 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:17:37 DEBUG : potato: Unchanged skipping 2022/01/13 06:17:37 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Making map for --track-renames 2022/01/13 06:17:37 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Finished making map for --track-renames 2022/01/13 06:17:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:17:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for renames to finish 2022/01/13 06:17:38 INFO : sub/yam: Moved (server-side) to: yam 2022/01/13 06:17:38 INFO : yam: Renamed from "sub/yam" 2022/01/13 06:17:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:17:38 DEBUG : Waiting for deletions to finish 2022/01/13 06:17:38 INFO : There was nothing to transfer 2022/01/13 06:17:38 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/13 06:17:38 DEBUG : pacer: Rate limited, increasing sleep to 1.276319544s 2022/01/13 06:17: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/13 06:17:39 DEBUG : pacer: Rate limited, increasing sleep to 2.880830628s 2022/01/13 06:17:40 DEBUG : pacer: Reducing sleep to 0s --- PASS: TestSyncWithTrackRenamesStrategyLeaf (11.57s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:17:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:17:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:17: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/13 06:17:45 DEBUG : pacer: Rate limited, increasing sleep to 1.763110605s 2022/01/13 06:17:46 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:17: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/13 06:17:47 DEBUG : pacer: Rate limited, increasing sleep to 1.715435619s 2022/01/13 06:17:47 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/13 06:17:47 DEBUG : pacer: Rate limited, increasing sleep to 2.669679176s 2022/01/13 06:17:49 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:17:53 DEBUG : sub dir/hello world: md5 = d66dee8ee2bfc3b9c4bd2cebe5f83615 OK 2022/01/13 06:17:53 INFO : sub dir/hello world: Copied (new) 2022/01/13 06:17:53 INFO : sub dir/hello world: Deleted 2022/01/13 06:17:55 DEBUG : nested/sub dir/file: md5 = 76f5526c7d81ceac898a205d2524767d OK 2022/01/13 06:17:55 INFO : nested/sub dir/file: Copied (new) 2022/01/13 06:17:55 INFO : nested/sub dir/file: Deleted 2022/01/13 06:17:55 INFO : sub dir: Removing directory 2022/01/13 06:17:55 INFO : nested/sub dir: Removing directory 2022/01/13 06:17:55 INFO : nested: Removing directory 2022/01/13 06:17:55 DEBUG : Local file system at /tmp/rclone2772509430: deleted 3 directories 2022/01/13 06:17: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/13 06:17:57 DEBUG : pacer: Rate limited, increasing sleep to 1.676888378s 2022/01/13 06:17:57 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/13 06:17:57 DEBUG : pacer: Rate limited, increasing sleep to 2.757875111s 2022/01/13 06:17:59 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:18:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2022/01/13 06:18:03 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2022/01/13 06:18:04 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (19.40s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:18:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:18:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:18:07 DEBUG : sub dir/hello world: md5 = a08faa82d843d871010c93e790b21287 OK 2022/01/13 06:18:07 INFO : sub dir/hello world: Copied (new) 2022/01/13 06:18:07 INFO : sub dir/hello world: Deleted 2022/01/13 06:18:09 DEBUG : nested/sub dir/file: md5 = 3776a3e8e2eadac7e3cc0bd14753db37 OK 2022/01/13 06:18:09 INFO : nested/sub dir/file: Copied (new) 2022/01/13 06:18:09 INFO : nested/sub dir/file: Deleted 2022/01/13 06:18: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/13 06:18:10 DEBUG : pacer: Rate limited, increasing sleep to 1.246900194s 2022/01/13 06:18:11 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/13 06:18:11 DEBUG : pacer: Rate limited, increasing sleep to 2.220715895s 2022/01/13 06:18:12 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:18:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2022/01/13 06:18:16 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2022/01/13 06:18:17 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" 2022/01/13 06:18: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/13 06:18:18 DEBUG : pacer: Rate limited, increasing sleep to 1.33984498s 2022/01/13 06:18:18 DEBUG : pacer: Reducing sleep to 0s --- PASS: TestMoveWithoutDeleteEmptySrcDirs (13.39s) === RUN TestMoveWithIgnoreExisting run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:18:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:18:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:18:20 DEBUG : existing-b: md5 = 0f567de8e8fc2f433553e8d1200fc519 OK 2022/01/13 06:18:20 INFO : existing-b: Copied (new) 2022/01/13 06:18:20 INFO : existing-b: Deleted 2022/01/13 06:18:21 DEBUG : existing: md5 = 0f5670dd53b0e80563c063c1f3ebde30 OK 2022/01/13 06:18:21 INFO : existing: Copied (new) 2022/01/13 06:18:21 INFO : existing: Deleted 2022/01/13 06:18:21 DEBUG : existing: Destination exists, skipping 2022/01/13 06:18:21 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2022/01/13 06:18:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:18:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:18:21 INFO : There was nothing to transfer 2022/01/13 06:18:22 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/13 06:18:22 DEBUG : pacer: Rate limited, increasing sleep to 1.283755203s 2022/01/13 06:18:22 DEBUG : pacer: Reducing sleep to 0s --- PASS: TestMoveWithIgnoreExisting (6.56s) === RUN TestServerSideMove run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:18:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fecadaf5guyohef3larasuy5" 2022/01/13 06:18:24 DEBUG : Config file has changed externaly - reloading 2022/01/13 06:18:24 DEBUG : Creating backend with remote "TestDrive:crypt/46pj013od3q6i2iv29b8bhli8eooqfi3qe2b0or6ctnquc87tj8k9ut0518hvusfpodqsjlhgia78" 2022/01/13 06:18:27 DEBUG : potato2: md5 = 451621821c76073de0c37783d3eaef2f OK 2022/01/13 06:18:28 DEBUG : empty space: md5 = ab154c1080c78e0a40fbae0cbef699e7 OK 2022/01/13 06:18:29 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/13 06:18:29 DEBUG : pacer: Rate limited, increasing sleep to 1.005164883s 2022/01/13 06:18:29 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:18:31 DEBUG : potato3: md5 = 2dd23809c6cef9441a5d5b03c62ffdd5 OK sync_test.go:1215: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5' -> Encrypted drive 'TestCryptDrive:rclone-test-fecadaf5guyohef3larasuy5' 2022/01/13 06:18:33 DEBUG : empty space: md5 = 1ff115d49674f79e1ace7b5f0645c95c OK 2022/01/13 06:18:35 DEBUG : potato3: md5 = 2167f734772946b9ddb321022cb53b10 OK 2022/01/13 06:18:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fecadaf5guyohef3larasuy5': Using server-side directory move 2022/01/13 06:18:35 INFO : Encrypted drive 'TestCryptDrive:rclone-test-fecadaf5guyohef3larasuy5': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2022/01/13 06:18:35 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2022/01/13 06:18:35 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2022/01/13 06:18:35 DEBUG : empty space: Unchanged skipping 2022/01/13 06:18:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fecadaf5guyohef3larasuy5': Waiting for checks to finish 2022/01/13 06:18: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/13 06:18:35 DEBUG : pacer: Rate limited, increasing sleep to 1.54991389s 2022/01/13 06:18: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/13 06:18:35 DEBUG : pacer: Rate limited, increasing sleep to 1.138056421s 2022/01/13 06:18: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/13 06:18:35 DEBUG : pacer: Rate limited, increasing sleep to 2.705029657s 2022/01/13 06:18: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/13 06:18:35 DEBUG : pacer: Rate limited, increasing sleep to 4.082283768s 2022/01/13 06:18: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/13 06:18:35 DEBUG : pacer: Rate limited, increasing sleep to 2.491515726s 2022/01/13 06:18:37 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:18:37 INFO : empty space: Deleted 2022/01/13 06:18:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fecadaf5guyohef3larasuy5': Waiting for transfers to finish 2022/01/13 06:18:37 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:18:37 INFO : potato3: Deleted 2022/01/13 06:18:41 INFO : potato2: Moved (server-side) 2022/01/13 06:18:42 INFO : potato3: Moved (server-side) 2022/01/13 06:18:42 INFO : There was nothing to transfer 2022/01/13 06:18:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xusejac6fixojod9beqagan3" 2022/01/13 06:18:42 DEBUG : Creating backend with remote "TestDrive:crypt/k8ttgo5qgiijhcngc751smm9hha7d73icnchlhgii22hhi28rq48or06gicd591io6v8oc0516ode" 2022/01/13 06:18: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/13 06:18:43 DEBUG : pacer: Rate limited, increasing sleep to 1.850743434s 2022/01/13 06:18: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/13 06:18:43 DEBUG : pacer: Rate limited, increasing sleep to 2.753957319s 2022/01/13 06:18:45 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:18:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xusejac6fixojod9beqagan3': Using server-side directory move 2022/01/13 06:18:49 INFO : Encrypted drive 'TestCryptDrive:rclone-test-xusejac6fixojod9beqagan3': Server side directory move succeeded 2022/01/13 06:18:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xusejac6fixojod9beqagan3': Purge remote 2022/01/13 06:18:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fecadaf5guyohef3larasuy5': Purge remote 2022/01/13 06:18:50 purge failed: directory not found --- PASS: TestServerSideMove (26.40s) === RUN TestServerSideMoveWithFilter run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:18:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-safelik6pulaxeg2yuluxeh9" 2022/01/13 06:18:51 DEBUG : Creating backend with remote "TestDrive:crypt/9q6i46mihjvsd5bhuojgcsqla1s012474ihji4g32b8sntijchhoj38f2q10a2q30ruarhoakjveg" 2022/01/13 06:18: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/13 06:18:52 DEBUG : pacer: Rate limited, increasing sleep to 1.142587562s 2022/01/13 06:18:52 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:18:54 DEBUG : potato2: md5 = 838a27c7c1c7a90d3559f845313d5094 OK 2022/01/13 06:18:56 DEBUG : empty space: md5 = ae20b6900e85352a236fbbf9396fc2e2 OK 2022/01/13 06:18:57 DEBUG : potato3: md5 = 85c3e26b856368015224ee5f1b35f1c3 OK sync_test.go:1215: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5' -> Encrypted drive 'TestCryptDrive:rclone-test-safelik6pulaxeg2yuluxeh9' 2022/01/13 06:19:00 DEBUG : empty space: md5 = 7cf3d4bb4ae07faa419583a195127c9c OK 2022/01/13 06:19:01 DEBUG : potato3: md5 = 5a9d361d060f89110c354f95742e99db OK 2022/01/13 06:19:02 DEBUG : empty space: Excluded 2022/01/13 06:19:02 DEBUG : empty space: Excluded 2022/01/13 06:19:02 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2022/01/13 06:19:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-safelik6pulaxeg2yuluxeh9': Waiting for checks to finish 2022/01/13 06:19:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-safelik6pulaxeg2yuluxeh9': Waiting for transfers to finish 2022/01/13 06:19:02 INFO : potato3: Deleted 2022/01/13 06:19:02 INFO : potato2: Moved (server-side) 2022/01/13 06:19:03 INFO : potato3: Moved (server-side) 2022/01/13 06:19:03 INFO : There was nothing to transfer 2022/01/13 06:19:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bunatuh7keqiwuz9topunen6" 2022/01/13 06:19:04 DEBUG : Creating backend with remote "TestDrive:crypt/a0jhrvk818b5l3cb4l9dgm7795kgup0ntv9m5i6jpt772mpbhd6oqaca4kbh77b7a2ef15b0oes9k" 2022/01/13 06:19:05 DEBUG : empty space: Excluded 2022/01/13 06:19:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bunatuh7keqiwuz9topunen6': Waiting for checks to finish 2022/01/13 06:19:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bunatuh7keqiwuz9topunen6': Waiting for transfers to finish 2022/01/13 06:19: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/13 06:19:05 DEBUG : pacer: Rate limited, increasing sleep to 1.43049027s 2022/01/13 06:19:06 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/13 06:19:06 DEBUG : pacer: Rate limited, increasing sleep to 2.432680658s 2022/01/13 06:19:07 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:19:10 INFO : potato2: Moved (server-side) 2022/01/13 06:19:10 INFO : potato3: Moved (server-side) 2022/01/13 06:19:10 INFO : There was nothing to transfer 2022/01/13 06:19:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bunatuh7keqiwuz9topunen6': Purge remote 2022/01/13 06:19:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-safelik6pulaxeg2yuluxeh9': Purge remote 2022/01/13 06:19:12 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/13 06:19:12 DEBUG : pacer: Rate limited, increasing sleep to 1.037312914s 2022/01/13 06:19:12 DEBUG : pacer: Reducing sleep to 0s --- PASS: TestServerSideMoveWithFilter (22.19s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:19:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tokewox3dajuqob7yekidix3" 2022/01/13 06:19:13 DEBUG : Creating backend with remote "TestDrive:crypt/a5v6gght83u17ukl3o638v2j7n681pu45hba041tmkeur2sa6q2g65j1mpbfivhlg92ds65jstjb2" 2022/01/13 06:19:15 DEBUG : potato2: md5 = 9aef2825ff16c7250510ce2f2a9cbdd9 OK 2022/01/13 06:19:17 DEBUG : empty space: md5 = f0483599529470f8d5124275d619c421 OK 2022/01/13 06:19:18 DEBUG : potato3: md5 = b3a025a3fc049b473a7936b5dab92dc2 OK 2022/01/13 06:19:18 DEBUG : tomatoDir: Making directory sync_test.go:1215: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5' -> Encrypted drive 'TestCryptDrive:rclone-test-tokewox3dajuqob7yekidix3' 2022/01/13 06:19:22 DEBUG : empty space: md5 = 74db7832172c86b47b9b30ae461abf21 OK 2022/01/13 06:19:23 DEBUG : potato3: md5 = 85661c511e4660865d541a1a1e601eb4 OK 2022/01/13 06:19:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tokewox3dajuqob7yekidix3': Using server-side directory move 2022/01/13 06:19:24 INFO : Encrypted drive 'TestCryptDrive:rclone-test-tokewox3dajuqob7yekidix3': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2022/01/13 06:19:24 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2022/01/13 06:19:24 DEBUG : empty space: Unchanged skipping 2022/01/13 06:19:24 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2022/01/13 06:19:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tokewox3dajuqob7yekidix3': Waiting for checks to finish 2022/01/13 06:19:24 INFO : potato3: Deleted 2022/01/13 06:19:25 INFO : empty space: Deleted 2022/01/13 06:19:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tokewox3dajuqob7yekidix3': Waiting for transfers to finish 2022/01/13 06:19:25 INFO : potato2: Moved (server-side) 2022/01/13 06:19:25 INFO : potato3: Moved (server-side) 2022/01/13 06:19:25 INFO : tomatoDir: Removing directory 2022/01/13 06:19:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': deleted 1 directories 2022/01/13 06:19:26 INFO : There was nothing to transfer 2022/01/13 06:19:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gawupoz8xujudes8xarelux9" 2022/01/13 06:19:27 DEBUG : Creating backend with remote "TestDrive:crypt/cie7hq6s8l6u1jq8de1lb1pmfvv7kb7mfq1irfhcuo4c4il4r68l5g9tgas712d6vn9leeg606s3q" 2022/01/13 06:19:28 DEBUG : tomatoDir: Making directory 2022/01/13 06:19:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gawupoz8xujudes8xarelux9': Using server-side directory move 2022/01/13 06:19:29 INFO : Encrypted drive 'TestCryptDrive:rclone-test-gawupoz8xujudes8xarelux9': Server side directory move succeeded 2022/01/13 06:19:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gawupoz8xujudes8xarelux9': Purge remote 2022/01/13 06:19:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tokewox3dajuqob7yekidix3': Purge remote 2022/01/13 06:19:31 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/13 06:19:31 DEBUG : pacer: Rate limited, increasing sleep to 1.29375232s 2022/01/13 06:19:32 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/13 06:19:32 DEBUG : pacer: Rate limited, increasing sleep to 2.08099769s 2022/01/13 06:19:33 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:19:33 purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (20.38s) === RUN TestServerSideMoveOverlap run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" sync_test.go:1399: Skipping test as remote supports DirMove 2022/01/13 06:19:34 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/13 06:19:34 DEBUG : pacer: Rate limited, increasing sleep to 1.136654127s 2022/01/13 06:19:34 DEBUG : pacer: Reducing sleep to 0s --- SKIP: TestServerSideMoveOverlap (1.54s) === RUN TestSyncOverlap run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:19:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/rclone-sync-test" 2022/01/13 06:19:35 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" --- PASS: TestSyncOverlap (2.17s) === RUN TestSyncCompareDest run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:19:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst" 2022/01/13 06:19:37 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o/31u3jie661vd5p8j7rtc3hgbh0" 2022/01/13 06:19: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/13 06:19:39 DEBUG : pacer: Rate limited, increasing sleep to 1.773279805s 2022/01/13 06:19:39 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:19:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/CompareDest" 2022/01/13 06:19:39 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o/gveqi14airsml4bgu7krj116o8" 2022/01/13 06:19:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:19:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:19:42 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/13 06:19:42 DEBUG : pacer: Rate limited, increasing sleep to 1.591984553s 2022/01/13 06:19:42 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:19:44 DEBUG : one: md5 = 7074df1bd0ff685709a0437e71161bf3 OK 2022/01/13 06:19:44 INFO : one: Copied (new) 2022/01/13 06:19:44 DEBUG : Waiting for deletions to finish 2022/01/13 06:19: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/13 06:19:46 DEBUG : pacer: Rate limited, increasing sleep to 1.865948504s 2022/01/13 06:19:46 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:19:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:19:46 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/01/13 06:19:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:19:48 DEBUG : one: md5 = 24b3e61113ee369e5037d6c16654e3a9 OK 2022/01/13 06:19:48 INFO : one: Copied (replaced existing) 2022/01/13 06:19:48 DEBUG : Waiting for deletions to finish 2022/01/13 06:19:50 DEBUG : dst/one: md5 = 210683392ef5b605c959e9a074820259 OK 2022/01/13 06:19:53 DEBUG : CompareDest/one: md5 = c12889e12a4ccb4abf6d272e8bfb1368 OK 2022/01/13 06:19:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:19:54 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:19:54 DEBUG : one: Destination found in --compare-dest, skipping 2022/01/13 06:19:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:19:54 DEBUG : Waiting for deletions to finish 2022/01/13 06:19:54 INFO : There was nothing to transfer 2022/01/13 06:19: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/13 06:19:54 DEBUG : pacer: Rate limited, increasing sleep to 1.552309913s 2022/01/13 06:19: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/13 06:19:54 DEBUG : pacer: Rate limited, increasing sleep to 2.023431414s 2022/01/13 06:19:55 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/13 06:19:55 DEBUG : pacer: Rate limited, increasing sleep to 4.7915245s 2022/01/13 06:19:56 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:20:02 DEBUG : CompareDest/two: md5 = fe6ddbd854de9c330280a45fdc31636d OK 2022/01/13 06:20:04 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:20:04 DEBUG : two: Destination found in --compare-dest, skipping 2022/01/13 06:20:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:20:04 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:20:04 DEBUG : one: Destination found in --compare-dest, skipping 2022/01/13 06:20:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:20:04 DEBUG : Waiting for deletions to finish 2022/01/13 06:20:04 INFO : There was nothing to transfer 2022/01/13 06:20:05 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:20:05 DEBUG : two: Destination found in --compare-dest, skipping 2022/01/13 06:20:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:20:05 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:20:05 DEBUG : one: Destination found in --compare-dest, skipping 2022/01/13 06:20:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:20:05 DEBUG : Waiting for deletions to finish 2022/01/13 06:20:05 INFO : There was nothing to transfer sync_test.go:1543: No hash on uploaded file so skipping compare timestamp test 2022/01/13 06:20:06 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/13 06:20:06 DEBUG : pacer: Rate limited, increasing sleep to 1.028284753s 2022/01/13 06:20:07 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:20:07 DEBUG : two: Sizes differ (src 5 vs dst 3) 2022/01/13 06:20:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:20:07 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:20:07 DEBUG : one: Destination found in --compare-dest, skipping 2022/01/13 06:20:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:20:09 DEBUG : two: md5 = 6d60bc661e3431a39c797deff15d5eb2 OK 2022/01/13 06:20:09 INFO : two: Copied (new) 2022/01/13 06:20:09 DEBUG : Waiting for deletions to finish 2022/01/13 06:20:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/13 06:20:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/13 06:20:13 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/13 06:20:13 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCompareDest (36.74s) === RUN TestSyncMultipleCompareDest run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:20:16 DEBUG : pre-dest1/1: md5 = 9fed7f82117a9b7a181f7156d6f9e528 OK 2022/01/13 06:20:18 DEBUG : pre-dest2/2: md5 = 91f12ee73229a845627f22ad1e46d167 OK 2022/01/13 06:20:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dest" 2022/01/13 06:20:19 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o/rg03c1jvnehrrc617i0lnqjddc" 2022/01/13 06:20:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/pre-dest1" 2022/01/13 06:20:20 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o/bbnblvh6k061ssopqrp18kd7gc" 2022/01/13 06:20:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/pre-dest2" 2022/01/13 06:20:21 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o/dgicm1h6b5ejvlltm8eeif0bnk" 2022/01/13 06:20:23 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:20:23 DEBUG : 1: Destination found in --compare-dest, skipping 2022/01/13 06:20:23 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:20:23 DEBUG : 2: Destination found in --compare-dest, skipping 2022/01/13 06:20:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dest': Waiting for checks to finish 2022/01/13 06:20:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dest': Waiting for transfers to finish 2022/01/13 06:20:26 DEBUG : 3: md5 = 2e384c8dd0f9ca2990ec3a651c608cfb OK 2022/01/13 06:20:26 INFO : 3: Copied (new) 2022/01/13 06:20:26 DEBUG : Waiting for deletions to finish 2022/01/13 06:20:29 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2022/01/13 06:20:30 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2022/01/13 06:20:30 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (17.41s) === RUN TestSyncCopyDest run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:20:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst" 2022/01/13 06:20:31 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o/31u3jie661vd5p8j7rtc3hgbh0" 2022/01/13 06:20: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/13 06:20:32 DEBUG : pacer: Rate limited, increasing sleep to 1.087458335s 2022/01/13 06:20:32 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:20:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/CopyDest" 2022/01/13 06:20:34 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o/d09o6po3f7bm6ce32vdgs8h9ls" 2022/01/13 06:20:34 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/13 06:20:34 DEBUG : pacer: Rate limited, increasing sleep to 1.951291989s 2022/01/13 06:20:34 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/13 06:20:34 DEBUG : pacer: Rate limited, increasing sleep to 2.416087092s 2022/01/13 06:20:37 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:20: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/13 06:20:40 DEBUG : pacer: Rate limited, increasing sleep to 1.146899455s 2022/01/13 06:20:40 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:20:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:20:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:20:43 DEBUG : one: md5 = 55f6d5cd30739241afea36db10b30ac7 OK 2022/01/13 06:20:43 INFO : one: Copied (new) 2022/01/13 06:20:43 DEBUG : Waiting for deletions to finish 2022/01/13 06:20: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/13 06:20:44 DEBUG : pacer: Rate limited, increasing sleep to 1.331231211s 2022/01/13 06:20:44 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:20:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:20:46 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/01/13 06:20:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:20:47 DEBUG : one: md5 = 60cd1af15b5f6b7bf92771071dc3e2ee OK 2022/01/13 06:20:47 INFO : one: Copied (replaced existing) 2022/01/13 06:20:47 DEBUG : Waiting for deletions to finish 2022/01/13 06:20:49 DEBUG : dst/one: md5 = 3b0087f7e7f6b61eda5ea6d5049ece6b OK 2022/01/13 06:20:51 DEBUG : CopyDest/one: md5 = 113e17148f7ad7280961351f6018f522 OK 2022/01/13 06:20:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/BackupDir" 2022/01/13 06:20:52 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o/s6dbk3lfi7c9kfvo6j7bla9m0g" 2022/01/13 06:20:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:20:54 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:20:54 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/01/13 06:20:56 INFO : one: Moved (server-side) 2022/01/13 06:20:57 INFO : one: Copied (server-side copy) 2022/01/13 06:20:57 DEBUG : one: Destination found in --copy-dest, using server-side copy 2022/01/13 06:20:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:20:57 DEBUG : Waiting for deletions to finish 2022/01/13 06:20:59 DEBUG : CopyDest/two: md5 = 88eab47ac6a164d8ac3b508058676fb1 OK 2022/01/13 06:20:59 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/13 06:20:59 DEBUG : pacer: Rate limited, increasing sleep to 1.513463646s 2022/01/13 06:21:00 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:21:00 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:21:02 INFO : two: Copied (server-side copy) 2022/01/13 06:21:02 DEBUG : two: Destination found in --copy-dest, using server-side copy 2022/01/13 06:21:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:21:02 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:21:02 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:21:02 DEBUG : one: Unchanged skipping 2022/01/13 06:21:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:21:02 DEBUG : Waiting for deletions to finish 2022/01/13 06:21:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:21: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/13 06:21:03 DEBUG : pacer: Rate limited, increasing sleep to 1.289939345s 2022/01/13 06:21:03 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:21:03 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:21:03 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:21:03 DEBUG : one: Unchanged skipping 2022/01/13 06:21:04 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:21:04 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:21:04 DEBUG : two: Unchanged skipping 2022/01/13 06:21:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:21:04 DEBUG : Waiting for deletions to finish 2022/01/13 06:21:04 INFO : There was nothing to transfer 2022/01/13 06:21: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/13 06:21:04 DEBUG : pacer: Rate limited, increasing sleep to 1.925970823s 2022/01/13 06:21:05 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:21:07 DEBUG : CopyDest/three: md5 = 3a765b907d3d4656be6ea9b2cb90485b OK 2022/01/13 06:21:09 DEBUG : three: Sizes differ (src 7 vs dst 5) 2022/01/13 06:21:09 DEBUG : three: Destination not found in --copy-dest 2022/01/13 06:21:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:21:09 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:21:09 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:21:09 DEBUG : two: Unchanged skipping 2022/01/13 06:21:09 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:21:09 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2022/01/13 06:21:09 DEBUG : one: Unchanged skipping 2022/01/13 06:21:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:21:10 DEBUG : three: md5 = e1c4d174a4e11f38205652f1a69c3c59 OK 2022/01/13 06:21:10 INFO : three: Copied (new) 2022/01/13 06:21:10 DEBUG : Waiting for deletions to finish 2022/01/13 06:21:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2022/01/13 06:21:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/13 06:21:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/13 06:21:16 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/13 06:21:16 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/13 06:21:16 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2022/01/13 06:21:17 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (46.26s) === RUN TestSyncBackupDir run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:21:20 DEBUG : dst/one: md5 = 2783370514b30e1afdfdd07464ed9b1c OK 2022/01/13 06:21:21 DEBUG : dst/two: md5 = 6911fa5537036dc6633e0cfc2bb17ea9 OK 2022/01/13 06:21:23 DEBUG : dst/three.txt: md5 = 6208e3f4846529d90ca36127e84e6a6e OK 2022/01/13 06:21:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst" 2022/01/13 06:21:23 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o/31u3jie661vd5p8j7rtc3hgbh0" 2022/01/13 06:21:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/backup" 2022/01/13 06:21:24 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o/1nrff024r7pq65ecp72fc28jb0" 2022/01/13 06:21:26 DEBUG : one: Sizes differ (src 4 vs dst 3) 2022/01/13 06:21:26 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:21:26 DEBUG : two: Unchanged skipping 2022/01/13 06:21:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:21:27 INFO : one: Moved (server-side) 2022/01/13 06:21:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:21:29 DEBUG : one: md5 = 3eb96f01414152982648f57e65f1d482 OK 2022/01/13 06:21:29 INFO : one: Copied (new) 2022/01/13 06:21:29 DEBUG : Waiting for deletions to finish 2022/01/13 06:21:30 INFO : three.txt: Moved (server-side) 2022/01/13 06:21:30 INFO : three.txt: Moved into backup dir 2022/01/13 06:21: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/13 06:21:30 DEBUG : pacer: Rate limited, increasing sleep to 1.141409739s 2022/01/13 06:21:31 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/13 06:21:31 DEBUG : pacer: Rate limited, increasing sleep to 2.454634355s 2022/01/13 06:21:32 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:21:35 DEBUG : dst/three.txt: md5 = 62708d2fbabfeffd67a4839495dca40d OK 2022/01/13 06:21:36 DEBUG : one: Sizes differ (src 5 vs dst 4) 2022/01/13 06:21:36 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:21:36 DEBUG : two: Unchanged skipping 2022/01/13 06:21:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:21:37 INFO : one: Deleted 2022/01/13 06:21:38 INFO : one: Moved (server-side) 2022/01/13 06:21:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:21:39 DEBUG : one: md5 = 56ed8a3aea3e9112731e5055af24832d OK 2022/01/13 06:21:39 INFO : one: Copied (new) 2022/01/13 06:21:39 DEBUG : Waiting for deletions to finish 2022/01/13 06:21:40 INFO : three.txt: Deleted 2022/01/13 06:21:40 INFO : three.txt: Moved (server-side) 2022/01/13 06:21:40 INFO : three.txt: Moved into backup dir 2022/01/13 06:21: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/13 06:21:41 DEBUG : pacer: Rate limited, increasing sleep to 1.834436939s 2022/01/13 06:21: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/13 06:21:41 DEBUG : pacer: Rate limited, increasing sleep to 2.145211799s 2022/01/13 06:21:41 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/13 06:21:41 DEBUG : pacer: Rate limited, increasing sleep to 4.349820331s 2022/01/13 06:21:43 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:21:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/13 06:21:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/13 06:21:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2022/01/13 06:21:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/13 06:21:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2022/01/13 06:21:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncBackupDir (34.38s) === RUN TestSyncBackupDirWithSuffix run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:21:54 DEBUG : dst/one: md5 = 96912ac922b8488636d6bcfce14e413d OK 2022/01/13 06:21:56 DEBUG : dst/two: md5 = 239c157642d675580e5f86a52fff63bf OK 2022/01/13 06:21:57 DEBUG : dst/three.txt: md5 = 1bed5d67884021d3af45554adee4371b OK 2022/01/13 06:21:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst" 2022/01/13 06:21:58 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o/31u3jie661vd5p8j7rtc3hgbh0" 2022/01/13 06:21:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/backup" 2022/01/13 06:21:59 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o/1nrff024r7pq65ecp72fc28jb0" 2022/01/13 06:21:59 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/13 06:21:59 DEBUG : pacer: Rate limited, increasing sleep to 1.944804292s 2022/01/13 06:22:00 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:22:03 DEBUG : one: Sizes differ (src 4 vs dst 3) 2022/01/13 06:22:03 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:22:03 DEBUG : two: Unchanged skipping 2022/01/13 06:22:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:22:04 INFO : one: Moved (server-side) to: one.bak 2022/01/13 06:22:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:22: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/13 06:22:05 DEBUG : pacer: Rate limited, increasing sleep to 1.049445525s 2022/01/13 06:22:05 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:22:07 DEBUG : one: md5 = a9b27b5097b838bad12eaa7debabff0e OK 2022/01/13 06:22:07 INFO : one: Copied (new) 2022/01/13 06:22:07 DEBUG : Waiting for deletions to finish 2022/01/13 06:22:08 INFO : three.txt: Moved (server-side) to: three.txt.bak 2022/01/13 06:22:08 INFO : three.txt: Moved into backup dir 2022/01/13 06:22:10 DEBUG : dst/three.txt: md5 = 765992728f16bb989fec3f97f6568867 OK 2022/01/13 06:22:10 DEBUG : one: Sizes differ (src 5 vs dst 4) 2022/01/13 06:22:10 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:22:10 DEBUG : two: Unchanged skipping 2022/01/13 06:22:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:22:11 INFO : one.bak: Deleted 2022/01/13 06:22:12 INFO : one: Moved (server-side) to: one.bak 2022/01/13 06:22:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:22:13 DEBUG : one: md5 = 3500cd68ee91a1736fe257b29d00e431 OK 2022/01/13 06:22:13 INFO : one: Copied (new) 2022/01/13 06:22:13 DEBUG : Waiting for deletions to finish 2022/01/13 06:22:14 INFO : three.txt.bak: Deleted 2022/01/13 06:22:15 INFO : three.txt: Moved (server-side) to: three.txt.bak 2022/01/13 06:22:15 INFO : three.txt: Moved into backup dir 2022/01/13 06:22: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/13 06:22:16 DEBUG : pacer: Rate limited, increasing sleep to 1.967931285s 2022/01/13 06:22:17 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/13 06:22:17 DEBUG : pacer: Rate limited, increasing sleep to 2.270620519s 2022/01/13 06:22:19 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:22:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/13 06:22:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/13 06:22:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2022/01/13 06:22:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2022/01/13 06:22:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2022/01/13 06:22:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirWithSuffix (31.88s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:22:26 DEBUG : dst/one: md5 = 124bab56182c273c5ff9a6052dd22739 OK 2022/01/13 06:22:27 DEBUG : dst/two: md5 = e793d53c8e8e73e17875ccbfe28caa4f OK 2022/01/13 06:22:29 DEBUG : dst/three.txt: md5 = f674c91ff7dc0301a2a2cfbc8081ef63 OK 2022/01/13 06:22:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst" 2022/01/13 06:22:29 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o/31u3jie661vd5p8j7rtc3hgbh0" 2022/01/13 06:22:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/backup" 2022/01/13 06:22:30 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o/1nrff024r7pq65ecp72fc28jb0" 2022/01/13 06:22:31 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/13 06:22:31 DEBUG : pacer: Rate limited, increasing sleep to 1.192925506s 2022/01/13 06:22:32 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/13 06:22:32 DEBUG : pacer: Rate limited, increasing sleep to 2.163291355s 2022/01/13 06:22:33 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:22:35 DEBUG : one: Sizes differ (src 4 vs dst 3) 2022/01/13 06:22:35 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:22:35 DEBUG : two: Unchanged skipping 2022/01/13 06:22:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:22:37 INFO : one: Moved (server-side) to: one-2019-01-01 2022/01/13 06:22:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:22:38 DEBUG : one: md5 = 7391764b1619ee0e930c2f37f7a46953 OK 2022/01/13 06:22:38 INFO : one: Copied (new) 2022/01/13 06:22:38 DEBUG : Waiting for deletions to finish 2022/01/13 06:22:38 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/13 06:22:38 DEBUG : pacer: Rate limited, increasing sleep to 1.884617149s 2022/01/13 06:22:39 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:22:41 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2022/01/13 06:22:41 INFO : three.txt: Moved into backup dir 2022/01/13 06:22: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/13 06:22:41 DEBUG : pacer: Rate limited, increasing sleep to 1.543712735s 2022/01/13 06:22: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/13 06:22:41 DEBUG : pacer: Rate limited, increasing sleep to 2.902422095s 2022/01/13 06:22:42 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/13 06:22:42 DEBUG : pacer: Rate limited, increasing sleep to 4.111010397s 2022/01/13 06:22:43 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:22: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/13 06:22:47 DEBUG : pacer: Rate limited, increasing sleep to 1.425635884s 2022/01/13 06:22:48 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:22:50 DEBUG : dst/three.txt: md5 = 1740a0874a2763c3c6aba7377e5c0c58 OK 2022/01/13 06:22:51 DEBUG : one: Sizes differ (src 5 vs dst 4) 2022/01/13 06:22:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:22:51 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:22:51 DEBUG : two: Unchanged skipping 2022/01/13 06:22:52 INFO : one-2019-01-01: Deleted 2022/01/13 06:22:52 INFO : one: Moved (server-side) to: one-2019-01-01 2022/01/13 06:22:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:22:54 DEBUG : one: md5 = 56fa3b1409d65e19776a7bb4d5041e85 OK 2022/01/13 06:22:54 INFO : one: Copied (new) 2022/01/13 06:22:54 DEBUG : Waiting for deletions to finish 2022/01/13 06:22:55 INFO : three-2019-01-01.txt: Deleted 2022/01/13 06:22:55 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2022/01/13 06:22:55 INFO : three.txt: Moved into backup dir 2022/01/13 06:22: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/13 06:22:56 DEBUG : pacer: Rate limited, increasing sleep to 1.580558506s 2022/01/13 06:22: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/13 06:22:56 DEBUG : pacer: Rate limited, increasing sleep to 2.155574905s 2022/01/13 06:22: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/13 06:22:56 DEBUG : pacer: Rate limited, increasing sleep to 4.006474283s 2022/01/13 06:22:58 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:23:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/13 06:23:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/13 06:23: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/13 06:23:05 DEBUG : pacer: Rate limited, increasing sleep to 1.946185964s 2022/01/13 06:23:06 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:23:06 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2022/01/13 06:23:06 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2022/01/13 06:23:06 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2022/01/13 06:23:06 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (44.37s) === RUN TestSyncBackupDirSuffixOnly run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:23:10 DEBUG : dst/one: md5 = 40cc631d8197af59550a426827e4bf72 OK 2022/01/13 06:23:12 DEBUG : dst/two: md5 = ab27be7b7e3a33f83cae9e23e167398d OK 2022/01/13 06:23:13 DEBUG : dst/three.txt: md5 = 1bfed9342b88a4bcb9780e60e7416942 OK 2022/01/13 06:23:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst" 2022/01/13 06:23:14 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o/31u3jie661vd5p8j7rtc3hgbh0" 2022/01/13 06:23:15 DEBUG : one: Sizes differ (src 4 vs dst 3) 2022/01/13 06:23:15 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:23:15 DEBUG : two: Unchanged skipping 2022/01/13 06:23:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:23: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/13 06:23:15 DEBUG : pacer: Rate limited, increasing sleep to 1.184996917s 2022/01/13 06:23: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/13 06:23:15 DEBUG : pacer: Rate limited, increasing sleep to 2.744009804s 2022/01/13 06:23:17 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:23:17 INFO : one: Moved (server-side) to: one.bak 2022/01/13 06:23:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:23:21 DEBUG : one: md5 = 93f50adb7d59e806145d9f308fa08c22 OK 2022/01/13 06:23:21 INFO : one: Copied (new) 2022/01/13 06:23:21 DEBUG : Waiting for deletions to finish 2022/01/13 06:23:22 INFO : three.txt: Moved (server-side) to: three.txt.bak 2022/01/13 06:23:22 INFO : three.txt: Moved into backup dir 2022/01/13 06:23:23 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/13 06:23:23 DEBUG : pacer: Rate limited, increasing sleep to 1.850915582s run.go:283: Retry Put of "dst/three.txt" to Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': 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/13 06:23:25 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:23:27 DEBUG : dst/three.txt: md5 = ecd20ca1deda2ef89391f691b5ebf808 OK 2022/01/13 06:23:28 DEBUG : three.txt.bak: Excluded 2022/01/13 06:23:28 DEBUG : one.bak: Excluded 2022/01/13 06:23:28 DEBUG : one: Sizes differ (src 5 vs dst 4) 2022/01/13 06:23:28 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:23:28 DEBUG : two: Unchanged skipping 2022/01/13 06:23:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for checks to finish 2022/01/13 06:23:29 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/13 06:23:29 DEBUG : pacer: Rate limited, increasing sleep to 1.14097102s 2022/01/13 06:23:29 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:23:30 INFO : one.bak: Deleted 2022/01/13 06:23:31 INFO : one: Moved (server-side) to: one.bak 2022/01/13 06:23:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst': Waiting for transfers to finish 2022/01/13 06:23:32 DEBUG : one: md5 = 6af58bdd4889c87da79ced8f7ee3f26a OK 2022/01/13 06:23:32 INFO : one: Copied (new) 2022/01/13 06:23:32 DEBUG : Waiting for deletions to finish 2022/01/13 06:23:33 INFO : three.txt.bak: Deleted 2022/01/13 06:23:33 INFO : three.txt: Moved (server-side) to: three.txt.bak 2022/01/13 06:23:33 INFO : three.txt: Moved into backup dir 2022/01/13 06:23:34 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/13 06:23:34 DEBUG : pacer: Rate limited, increasing sleep to 1.993364438s 2022/01/13 06:23:35 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:23:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/13 06:23:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2022/01/13 06:23:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2022/01/13 06:23:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2022/01/13 06:23:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/13 06:23:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirSuffixOnly (31.67s) === RUN TestSyncSuffix run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:23: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/13 06:23:40 DEBUG : pacer: Rate limited, increasing sleep to 1.813049896s 2022/01/13 06:23:41 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:23:43 DEBUG : dst/one: md5 = e98332520b2607a3177694012dd4dbe6 OK 2022/01/13 06:23:45 DEBUG : dst/two: md5 = fd942bd3dc47de6e60d32c9b9cf15a22 OK 2022/01/13 06:23:46 DEBUG : dst/three.txt: md5 = 297cec66c27709b59a0ebd916d09a1e0 OK 2022/01/13 06:23:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst" 2022/01/13 06:23:47 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o/31u3jie661vd5p8j7rtc3hgbh0" 2022/01/13 06:23:48 DEBUG : one: Sizes differ (src 4 vs dst 3) 2022/01/13 06:23:49 INFO : one: Moved (server-side) to: one.bak 2022/01/13 06:23:50 DEBUG : one: md5 = 5303db9497b9aef18214e12f0dbe818c OK 2022/01/13 06:23:50 INFO : one: Copied (new) 2022/01/13 06:23:50 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:23:50 DEBUG : two: Unchanged skipping 2022/01/13 06:23:51 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2022/01/13 06:23:51 INFO : three.txt: Moved (server-side) to: three.txt.bak 2022/01/13 06:23:53 DEBUG : three.txt: md5 = 7d3baf50dd26b87e5f9c9f5439041690 OK 2022/01/13 06:23:53 INFO : three.txt: Copied (new) 2022/01/13 06:23:54 DEBUG : one: Sizes differ (src 5 vs dst 4) 2022/01/13 06:23:55 INFO : one.bak: Deleted 2022/01/13 06:23:56 INFO : one: Moved (server-side) to: one.bak 2022/01/13 06:23:57 DEBUG : one: md5 = 710043d12bf1f3fceb5c17334550d79a OK 2022/01/13 06:23:57 INFO : one: Copied (new) 2022/01/13 06:23:57 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:23:57 DEBUG : two: Unchanged skipping 2022/01/13 06:23:57 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2022/01/13 06:23:58 INFO : three.txt.bak: Deleted 2022/01/13 06:23:59 INFO : three.txt: Moved (server-side) to: three.txt.bak 2022/01/13 06:24:00 DEBUG : three.txt: md5 = bc6f00272d17ed7275f796a49ab829fa OK 2022/01/13 06:24:00 INFO : three.txt: Copied (new) 2022/01/13 06:24:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2022/01/13 06:24:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/13 06:24:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2022/01/13 06:24:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2022/01/13 06:24:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/13 06:24:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2022/01/13 06:24:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncSuffix (24.98s) === RUN TestSyncSuffixKeepExtension run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:24:07 DEBUG : dst/one: md5 = ec0b0654f98a964dcf38e08913de1ce4 OK 2022/01/13 06:24:08 DEBUG : dst/two: md5 = 1e05989fb80b1fc586abaa003d4a52be OK 2022/01/13 06:24:10 DEBUG : dst/three.txt: md5 = 410f01f76724b9df6b7d730b90c0824e OK 2022/01/13 06:24:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5/dst" 2022/01/13 06:24:10 DEBUG : Creating backend with remote "TestDrive:crypt/ieo52fcl6r9op34kuk3p9ad5a352e9s1uf5aldi1p01137uaf7pvcnjf2qdkjhkjfats61841nh6o/31u3jie661vd5p8j7rtc3hgbh0" 2022/01/13 06:24:11 DEBUG : one: Sizes differ (src 4 vs dst 3) 2022/01/13 06:24:12 INFO : one: Moved (server-side) to: one-2019-01-01 2022/01/13 06:24:14 DEBUG : one: md5 = 02b4e743fb1065156bf31c13e5b1e2ae OK 2022/01/13 06:24:14 INFO : one: Copied (new) 2022/01/13 06:24:14 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:24:14 DEBUG : two: Unchanged skipping 2022/01/13 06:24:14 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2022/01/13 06:24:15 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2022/01/13 06:24:16 DEBUG : three.txt: md5 = 6cef9d0df8e6d09c8325a1d2c596ec57 OK 2022/01/13 06:24:16 INFO : three.txt: Copied (new) 2022/01/13 06:24:18 DEBUG : one: Sizes differ (src 5 vs dst 4) 2022/01/13 06:24:18 INFO : one-2019-01-01: Deleted 2022/01/13 06:24:19 INFO : one: Moved (server-side) to: one-2019-01-01 2022/01/13 06:24:20 DEBUG : one: md5 = 41f9d0aca4184210d821ddd3ce951678 OK 2022/01/13 06:24:20 INFO : one: Copied (new) 2022/01/13 06:24:21 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:24:21 DEBUG : two: Unchanged skipping 2022/01/13 06:24:21 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2022/01/13 06:24:22 INFO : three-2019-01-01.txt: Deleted 2022/01/13 06:24:22 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2022/01/13 06:24:23 DEBUG : three.txt: md5 = 455026ca4c67089e31e25b12616bcff2 OK 2022/01/13 06:24:23 INFO : three.txt: Copied (new) 2022/01/13 06:24:27 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2022/01/13 06:24:27 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2022/01/13 06:24:27 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2022/01/13 06:24:27 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2022/01/13 06:24:27 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2022/01/13 06:24:27 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2022/01/13 06:24:27 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (23.31s) === RUN TestSyncUTFNorm run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:24:30 DEBUG : Testêé: md5 = 42884146cc9d62381a3099b581bbb28f OK 2022/01/13 06:24:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:24:30 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2022/01/13 06:24:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:24:31 DEBUG : Testêé: md5 = ce1aa646b4ddb4d1eabaf64d4802ff2b OK 2022/01/13 06:24:31 INFO : Testêé: Copied (replaced existing) 2022/01/13 06:24:31 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.56s) === RUN TestSyncImmutable run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:24:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:24:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:24:34 DEBUG : existing: md5 = 9d7138628f1a77eed883abdd385d1ee0 OK 2022/01/13 06:24:34 INFO : existing: Copied (new) 2022/01/13 06:24:34 DEBUG : Waiting for deletions to finish 2022/01/13 06:24:35 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2022/01/13 06:24:35 ERROR : existing: Source and destination exist but do not match: immutable file modified 2022/01/13 06:24:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:24:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:24:35 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': not deleting files as there were IO errors 2022/01/13 06:24:35 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': not deleting directories as there were IO errors --- PASS: TestSyncImmutable (3.96s) === RUN TestSyncIgnoreCase run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:24:38 DEBUG : EXISTING: md5 = a9aa32853f7053f16442245e738d8d72 OK 2022/01/13 06:24:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:24:39 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:24:39 DEBUG : existing: Unchanged skipping 2022/01/13 06:24:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:24:39 DEBUG : Waiting for deletions to finish 2022/01/13 06:24:39 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.34s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", 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-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", 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-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" sync_test.go:1989: This test only runs on local --- PASS: TestMaxTransfer (1.50s) --- SKIP: TestMaxTransfer/Hard (0.48s) --- SKIP: TestMaxTransfer/Soft (0.55s) --- SKIP: TestMaxTransfer/Cautious (0.47s) === RUN TestSyncConcurrentDelete run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:24:43 DEBUG : both0: md5 = 10b52089b818b55e05f5b8d17838bad1 OK 2022/01/13 06:24:44 DEBUG : only0: md5 = c34c7de7a8455381f136487aeca3275e OK 2022/01/13 06:24:46 DEBUG : both1: md5 = 3595180eacfa37390c62ab563c7b81ec OK 2022/01/13 06:24:47 DEBUG : only1: md5 = 6aa896b0396e5ce68a9c948b8f6142b1 OK 2022/01/13 06:24:48 DEBUG : both2: md5 = f486694b4ff92132a9b4eea2bf878c16 OK 2022/01/13 06:24:50 DEBUG : only2: md5 = 80908aa4ee793a0dbc29742de154edd1 OK 2022/01/13 06:24:51 DEBUG : both3: md5 = 335e24f94d0511926337c38802fc8592 OK 2022/01/13 06:24:52 DEBUG : only3: md5 = f4396fca3ef2589f4af6595b9ac6849d OK 2022/01/13 06:24:54 DEBUG : both4: md5 = e2d7d07fdee691bc1bc48278d64c8415 OK 2022/01/13 06:24:55 DEBUG : only4: md5 = a5b957712ce4c686413bf783f9398b06 OK 2022/01/13 06:24:57 DEBUG : both5: md5 = 88410bb528bc8a4667b5bf8781ce24f0 OK 2022/01/13 06:24:58 DEBUG : only5: md5 = cb92b743256af5ecb34d530dbaed740a OK 2022/01/13 06:25:00 DEBUG : both6: md5 = 737bdca55192f4f3100c80f3809300c5 OK 2022/01/13 06:25:01 DEBUG : only6: md5 = ef44128539d4f0cde1cf66c39df5ef4c OK 2022/01/13 06:25:02 DEBUG : both7: md5 = 535d2950929b5014dbde18beffa4dab6 OK 2022/01/13 06:25:04 DEBUG : only7: md5 = e496a0a7aaf6855440c8a69c140f4854 OK 2022/01/13 06:25:05 DEBUG : both8: md5 = 9f577490506c6453696390d559cbd2d2 OK 2022/01/13 06:25:06 DEBUG : only8: md5 = 7dc21d3af944a8cf8f983e5c87af4fd7 OK 2022/01/13 06:25:08 DEBUG : both9: md5 = 7858c0aa89d91eda369b57a88f8fc840 OK 2022/01/13 06:25:09 DEBUG : only9: md5 = 2518c80c5290b3b4530a209ca77f3207 OK 2022/01/13 06:25:11 DEBUG : both10: md5 = 282ed34e449285bb47160cef56fd2957 OK 2022/01/13 06:25:12 DEBUG : only10: md5 = 41ce3a529a8e7e7cf800bb792ea99cb9 OK 2022/01/13 06:25:13 DEBUG : both11: md5 = 1ca29fad54f1d4dfafddac767da8b24c OK 2022/01/13 06:25:15 DEBUG : only11: md5 = 26d3f81eb58916a98fdbbcc05ffbe0c7 OK 2022/01/13 06:25:16 DEBUG : both12: md5 = d80b56111f5c82d270f6bf03216bbf67 OK 2022/01/13 06:25:18 DEBUG : only12: md5 = 194548b9be7239536e8adc1bb6d84a3d OK 2022/01/13 06:25:19 DEBUG : both13: md5 = 61234556fcb74bd855d19bf685ef19c2 OK 2022/01/13 06:25:20 DEBUG : only13: md5 = 2dc36faf46c8e9e7f613ad1de70804a5 OK 2022/01/13 06:25:22 DEBUG : both14: md5 = b31d0127d9b1e375113e9b0ac2c1e9d2 OK 2022/01/13 06:25:23 DEBUG : only14: md5 = b7645446aa67ba676db99a177f7bc5d3 OK 2022/01/13 06:25:25 DEBUG : both15: md5 = 293660095f150869d66e5751f978ef80 OK 2022/01/13 06:25:26 DEBUG : only15: md5 = 3d5974347502c53be1f3af979ce61248 OK 2022/01/13 06:25:27 DEBUG : both16: md5 = b61e2dba551cbd791100a8d747ba5761 OK 2022/01/13 06:25:29 DEBUG : only16: md5 = bc22d22c41f2692c23951f6f10cf6fa0 OK 2022/01/13 06:25:30 DEBUG : both17: md5 = 4ea6b990ddf003d495c033a9a90f811d OK 2022/01/13 06:25:30 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/13 06:25:30 DEBUG : pacer: Rate limited, increasing sleep to 1.147280403s run.go:283: Retry Put of "only17" to Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': 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/13 06:25:33 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:25:35 DEBUG : only17: md5 = 19c7bf8c72a52ae629fc314777eb6771 OK 2022/01/13 06:25:36 DEBUG : both18: md5 = 563fdc6a8895da849b7189faca994e90 OK 2022/01/13 06:25:37 DEBUG : only18: md5 = 5f4c4f9c5fa00dcdd14c745c897042aa OK 2022/01/13 06:25:39 DEBUG : both19: md5 = c14556b2347f1457b2c21a1ca4657d99 OK 2022/01/13 06:25:40 DEBUG : only19: md5 = cdcd250497e1e7b54f5af5d6055a0e5e OK 2022/01/13 06:25:41 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both0: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:25:41 DEBUG : both11: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both13: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both14: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both15: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both16: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both17: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both18: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both19: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both2: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both3: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both4: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both5: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both12: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both6: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both7: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both9: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both10: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both8: Unchanged skipping 2022/01/13 06:25:41 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:25:41 DEBUG : both1: Unchanged skipping 2022/01/13 06:25:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:25:41 DEBUG : Waiting for deletions to finish 2022/01/13 06:25:41 INFO : only4: Deleted 2022/01/13 06:25:41 INFO : only19: Deleted 2022/01/13 06:25:41 INFO : only6: Deleted 2022/01/13 06:25:41 INFO : only0: Deleted 2022/01/13 06:25: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/13 06:25:41 DEBUG : pacer: Rate limited, increasing sleep to 1.624068605s 2022/01/13 06:25:42 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:25:42 INFO : only5: Deleted 2022/01/13 06:25:42 INFO : only9: Deleted 2022/01/13 06:25:42 INFO : only12: Deleted 2022/01/13 06:25:42 INFO : only13: Deleted 2022/01/13 06:25:44 INFO : only15: Deleted 2022/01/13 06:25:44 INFO : only14: Deleted 2022/01/13 06:25:44 INFO : only10: Deleted 2022/01/13 06:25:44 INFO : only1: Deleted 2022/01/13 06:25:44 INFO : only17: Deleted 2022/01/13 06:25:44 INFO : only11: Deleted 2022/01/13 06:25: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/13 06:25:44 DEBUG : pacer: Rate limited, increasing sleep to 1.246847503s 2022/01/13 06:25:44 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:25:44 INFO : only8: Deleted 2022/01/13 06:25: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/13 06:25:44 DEBUG : pacer: Rate limited, increasing sleep to 1.425389853s 2022/01/13 06:25:44 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:25:44 INFO : only16: Deleted 2022/01/13 06:25:44 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/13 06:25:44 DEBUG : pacer: Rate limited, increasing sleep to 1.066868748s 2022/01/13 06:25:46 DEBUG : pacer: Reducing sleep to 0s 2022/01/13 06:25:46 INFO : only3: Deleted 2022/01/13 06:25:47 INFO : only18: Deleted 2022/01/13 06:25:47 INFO : only2: Deleted 2022/01/13 06:25:47 INFO : only7: Deleted 2022/01/13 06:25:47 INFO : There was nothing to transfer --- PASS: TestSyncConcurrentDelete (77.10s) === RUN TestSyncConcurrentTruncate run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5'", Local "Local file system at /tmp/rclone2772509430", Modify Window "1ms" 2022/01/13 06:26:00 DEBUG : both0: md5 = 4e8999169965f80a1b8570d2dab45d80 OK 2022/01/13 06:26:01 DEBUG : only0: md5 = a313ccece36948d36b77651842589e44 OK 2022/01/13 06:26:03 DEBUG : both1: md5 = 42e6f9fb9a1d98a8a8abc1a3b69aea9d OK 2022/01/13 06:26:04 DEBUG : only1: md5 = 4d188c8cf8e6fabfe599d5c6a48436ea OK 2022/01/13 06:26:06 DEBUG : both2: md5 = e9a287116c1e8c250a990efab29a4186 OK 2022/01/13 06:26:07 DEBUG : only2: md5 = cfc91bdc441c1be89cc569e833eb319c OK 2022/01/13 06:26:08 DEBUG : both3: md5 = dbbb646f57ab67b8a7bfb48c9fa2dafc OK 2022/01/13 06:26:10 DEBUG : only3: md5 = 1732a71b67807fd989221d7f94950dc7 OK 2022/01/13 06:26:11 DEBUG : both4: md5 = 2af0ea006fd9008fbb992d7e70af90c7 OK 2022/01/13 06:26:13 DEBUG : only4: md5 = 92254bf2fa700bd5a9244cc452e203fa OK 2022/01/13 06:26:14 DEBUG : both5: md5 = d98a290d761ccf7e3236e0b87c07fb6e OK 2022/01/13 06:26:15 DEBUG : only5: md5 = db2d4959da215fda95dfebc0d554afd4 OK 2022/01/13 06:26:17 DEBUG : both6: md5 = 9e292787c96113292ef233bd2eb6bc87 OK 2022/01/13 06:26:18 DEBUG : only6: md5 = d73178f3ca0bf62046017f2fa21d969b OK 2022/01/13 06:26:20 DEBUG : both7: md5 = 826cdec63ee1b44d04b487c4c7c0ad38 OK 2022/01/13 06:26:22 DEBUG : only7: md5 = e98008023e1e25ca3b73dc729a588ac7 OK 2022/01/13 06:26:24 DEBUG : both8: md5 = 4f15eb83c16effe1c84efecf9cab9175 OK 2022/01/13 06:26:25 DEBUG : only8: md5 = efce135b5e514693bfec401c06fb487d OK 2022/01/13 06:26:27 DEBUG : both9: md5 = 864e5a064f6b37f0b41985008739f0cd OK 2022/01/13 06:26:28 DEBUG : only9: md5 = c8de56968a1edad9da9d3efc7960f458 OK 2022/01/13 06:26:29 DEBUG : both10: md5 = de9430f1e99a00f028c1a26ba09279d6 OK 2022/01/13 06:26:31 DEBUG : only10: md5 = 72acd9389367de800a21f540080c9a56 OK 2022/01/13 06:26:32 DEBUG : both11: md5 = 2efd55342eff1034efaeafcfffe9a3ea OK 2022/01/13 06:26:34 DEBUG : only11: md5 = 1f70c4f1d849cdbbaf5b7a5890849b46 OK 2022/01/13 06:26:35 DEBUG : both12: md5 = 0ee7ccb3ebc83580d49565f97df60338 OK 2022/01/13 06:26:36 DEBUG : only12: md5 = 4a53a3592ad36810eeed42e208740f88 OK 2022/01/13 06:26:38 DEBUG : both13: md5 = 20df4f36b0e1c272562b844dda3692c4 OK 2022/01/13 06:26:39 DEBUG : only13: md5 = 555dce8ea258af17c8e2212600aca057 OK 2022/01/13 06:26:41 DEBUG : both14: md5 = a9546cebf84c5b00d7239cd1fa099a8d OK 2022/01/13 06:26:42 DEBUG : only14: md5 = 141d849ea3cc1d28cdd4b09a3d8f0278 OK 2022/01/13 06:26:44 DEBUG : both15: md5 = 4e12972f223c3183af54eec8dda78132 OK 2022/01/13 06:26:45 DEBUG : only15: md5 = 5a27fbb566f3300e77b0e090e7093246 OK 2022/01/13 06:26:46 DEBUG : both16: md5 = 98a93ddf4fbc0331eb66efbfb629c79d OK 2022/01/13 06:26:48 DEBUG : only16: md5 = 82ac4a7154a5ceeafe24becc30dd5210 OK 2022/01/13 06:26:49 DEBUG : both17: md5 = 8cf364e95d242bf2dbdf2168dd98a617 OK 2022/01/13 06:26:51 DEBUG : only17: md5 = 3b1386e75fc63f8b0f5afbdc82decde6 OK 2022/01/13 06:26:52 DEBUG : both18: md5 = e94c35bc10bd47fb48bd7ecdf772c86b OK 2022/01/13 06:26:53 DEBUG : only18: md5 = 8a1238aecaf0c71123e0ba676fb304a2 OK 2022/01/13 06:26:55 DEBUG : both19: md5 = ba1789710e61e53e8cc27aa946f5f681 OK 2022/01/13 06:26:56 DEBUG : only19: md5 = 743f7b88e4b606922419ed0896ab33a1 OK 2022/01/13 06:26:57 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both1: Unchanged skipping 2022/01/13 06:26:57 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both10: Unchanged skipping 2022/01/13 06:26:57 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both12: Unchanged skipping 2022/01/13 06:26:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for checks to finish 2022/01/13 06:26:57 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both13: Unchanged skipping 2022/01/13 06:26:57 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both15: Unchanged skipping 2022/01/13 06:26:57 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both0: Unchanged skipping 2022/01/13 06:26:57 DEBUG : both14: Unchanged skipping 2022/01/13 06:26:57 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both17: Unchanged skipping 2022/01/13 06:26:57 DEBUG : both16: Unchanged skipping 2022/01/13 06:26:57 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both19: Unchanged skipping 2022/01/13 06:26:57 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both2: Unchanged skipping 2022/01/13 06:26:57 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both11: Unchanged skipping 2022/01/13 06:26:57 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both4: Unchanged skipping 2022/01/13 06:26:57 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both3: Unchanged skipping 2022/01/13 06:26:57 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both6: Unchanged skipping 2022/01/13 06:26:57 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both7: Unchanged skipping 2022/01/13 06:26:57 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both8: Unchanged skipping 2022/01/13 06:26:57 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : both9: Unchanged skipping 2022/01/13 06:26:57 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2022/01/13 06:26:57 DEBUG : both18: Unchanged skipping 2022/01/13 06:26:57 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : both5: Unchanged skipping 2022/01/13 06:26:57 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2022/01/13 06:26:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Waiting for transfers to finish 2022/01/13 06:26:58 DEBUG : only11: md5 = c79214fbd08ed873535a12f1fbc6652b OK 2022/01/13 06:26:58 INFO : only11: Copied (replaced existing) 2022/01/13 06:26:58 DEBUG : only10: md5 = 5e3d02373a940a9844b0d316b56cc647 OK 2022/01/13 06:26:58 INFO : only10: Copied (replaced existing) 2022/01/13 06:26:58 DEBUG : only0: md5 = 057fe92aa1e3f338068cd978188acbe7 OK 2022/01/13 06:26:58 INFO : only0: Copied (replaced existing) 2022/01/13 06:26:58 DEBUG : only1: md5 = 45e97cbd8b978b9a4a126e69d7fb99ce OK 2022/01/13 06:26:58 INFO : only1: Copied (replaced existing) 2022/01/13 06:26:59 DEBUG : only12: md5 = 24bf5f271e8a5359fef8cbad9211167a OK 2022/01/13 06:26:59 INFO : only12: Copied (replaced existing) 2022/01/13 06:26:59 DEBUG : only14: md5 = 7a5816a88b0d4e6999992c056fe985c1 OK 2022/01/13 06:26:59 INFO : only14: Copied (replaced existing) 2022/01/13 06:27:00 DEBUG : only13: md5 = b49f1cbb1a323ed294b41021dc311279 OK 2022/01/13 06:27:00 INFO : only13: Copied (replaced existing) 2022/01/13 06:27:00 DEBUG : only15: md5 = dc4789eaa420d5c111c7a6a22ba966eb OK 2022/01/13 06:27:00 INFO : only15: Copied (replaced existing) 2022/01/13 06:27:00 DEBUG : only16: md5 = 07d15011490472f5a5ac7014b43c3247 OK 2022/01/13 06:27:00 INFO : only16: Copied (replaced existing) 2022/01/13 06:27:01 DEBUG : only18: md5 = 3b0076a1535ed4fa43bab303fbf0bf63 OK 2022/01/13 06:27:01 INFO : only18: Copied (replaced existing) 2022/01/13 06:27:01 DEBUG : only17: md5 = de5c6171160a0398e9878a024e2e2933 OK 2022/01/13 06:27:01 INFO : only17: Copied (replaced existing) 2022/01/13 06:27:01 DEBUG : only19: md5 = c4015dce1660defa74c7435086bee35d OK 2022/01/13 06:27:01 INFO : only19: Copied (replaced existing) 2022/01/13 06:27:02 DEBUG : only2: md5 = 06580ec9b78f740963bc6c8e7775bf54 OK 2022/01/13 06:27:02 INFO : only2: Copied (replaced existing) 2022/01/13 06:27:02 DEBUG : only5: md5 = 55dfa34a1ddfd60813c9fdb1087fa4f7 OK 2022/01/13 06:27:02 INFO : only5: Copied (replaced existing) 2022/01/13 06:27:02 DEBUG : only7: md5 = 8ea2f95ceb1ad1b5939b30f63b297154 OK 2022/01/13 06:27:02 INFO : only7: Copied (replaced existing) 2022/01/13 06:27:02 DEBUG : only6: md5 = 3e2d89c4b6a947658c9a9d7590c44745 OK 2022/01/13 06:27:02 INFO : only6: Copied (replaced existing) 2022/01/13 06:27:03 DEBUG : only8: md5 = d5a2dc12b61c4a505d40b6cb6621f7de OK 2022/01/13 06:27:03 INFO : only8: Copied (replaced existing) 2022/01/13 06:27:03 DEBUG : only9: md5 = 26d032d42f2f8cd7394fb752c2fbf1b8 OK 2022/01/13 06:27:03 INFO : only9: Copied (replaced existing) 2022/01/13 06:27:03 DEBUG : only3: md5 = 5c90bea194f96c37893e5c5313732bef OK 2022/01/13 06:27:03 INFO : only3: Copied (replaced existing) 2022/01/13 06:27:03 DEBUG : only4: md5 = a2e5d88dfc7c13e936c7af134a757234 OK 2022/01/13 06:27:03 INFO : only4: Copied (replaced existing) 2022/01/13 06:27:03 DEBUG : Waiting for deletions to finish --- PASS: TestSyncConcurrentTruncate (86.90s) PASS 2022/01/13 06:27:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoduziz2yilihud0gefomel5': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 15m0.103583787s (try 1/5)