Backup process doesn't work anymore, stuck a locking the repository

Zottelchen · May 15, 2019, 3:06pm

So I have a backup of ~700GB on Google Drive (using rclone). But since 2 days ago backup does not work anymore. It now stops at “lock repository” (it permanently retries until it aborts). rclone and restic are both up to date. How can I fix this?

$ restic -r rclone:zombie: --verbose --password-file H:/PW --cleanup-cache backup H:/
open repository
repository 1301036c opened successfully, password is correct
lock repository
Load(<lock/22301c1fd7>, 0, 0) returned error, retrying after 720.254544ms: <lock/22301c1fd7> does not exist
Load(<lock/a59805e476>, 0, 0) returned error, retrying after 582.280027ms: <lock/a59805e476> does not exist
Load(<lock/a59805e476>, 0, 0) returned error, retrying after 703.28564ms: <lock/a59805e476> does not exist
Load(<lock/ddcd54b6f3>, 0, 0) returned error, retrying after 462.318748ms: <lock/ddcd54b6f3> does not exist
Load(<lock/b2a805d1d2>, 0, 0) returned error, retrying after 593.411537ms: <lock/b2a805d1d2> does not exist
Load(<lock/2aa34aaedd>, 0, 0) returned error, retrying after 282.818509ms: <lock/2aa34aaedd> does not exist
Load(<lock/75f3f6a181>, 0, 0) returned error, retrying after 328.259627ms: <lock/75f3f6a181> does not exist
Load(<lock/e099facd6f>, 0, 0) returned error, retrying after 298.484759ms: <lock/e099facd6f> does not exist
Load(<lock/3f12f1bd4c>, 0, 0) returned error, retrying after 400.45593ms: <lock/3f12f1bd4c> does not exist
Load(<lock/69a447f9aa>, 0, 0) returned error, retrying after 507.606314ms: <lock/69a447f9aa> does not exist
Load(<lock/17a8b50faa>, 0, 0) returned error, retrying after 656.819981ms: <lock/17a8b50faa> does not exist
Load(<lock/e15ba20c75>, 0, 0) returned error, retrying after 357.131936ms: <lock/e15ba20c75> does not exist
Load(<lock/e15ba20c75>, 0, 0) returned error, retrying after 660.492892ms: <lock/e15ba20c75> does not exist
Load(<lock/1d6570e16f>, 0, 0) returned error, retrying after 409.029087ms: <lock/1d6570e16f> does not exist
Load(<lock/6f8a2f997c>, 0, 0) returned error, retrying after 484.444922ms: <lock/6f8a2f997c> does not exist
Load(<lock/56ea07ebcc>, 0, 0) returned error, retrying after 391.517075ms: <lock/56ea07ebcc> does not exist
Load(<lock/b3f2d7294e>, 0, 0) returned error, retrying after 396.550928ms: <lock/b3f2d7294e> does not exist
Load(<lock/b3f2d7294e>, 0, 0) returned error, retrying after 884.313507ms: <lock/b3f2d7294e> does not exist
Load(<lock/b3f2d7294e>, 0, 0) returned error, retrying after 808.372184ms: <lock/b3f2d7294e> does not exist
Load(<lock/b3f2d7294e>, 0, 0) returned error, retrying after 1.186627854s: <lock/b3f2d7294e> does not exist
Load(<lock/9ecd7b64e9>, 0, 0) returned error, retrying after 430.435708ms: <lock/9ecd7b64e9> does not exist
rclone: 2019/05/15 18:40:09 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request put error: googleapi: Error 429: Rate Limit Exceeded, rateLimitExceeded
rclone: 2019/05/15 18:40:09 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request rcat error: googleapi: Error 429: Rate Limit Exceeded, rateLimitExceeded
Save(<lock/d5ed40634d>) returned error, retrying after 535.336638ms: server response unexpected: 500 Internal Server Error (500)
rclone: 2019/05/15 18:40:19 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request put error: googleapi: Error 429: Rate Limit Exceeded, rateLimitExceeded
rclone: 2019/05/15 18:40:19 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request rcat error: googleapi: Error 429: Rate Limit Exceeded, rateLimitExceeded
Save(<lock/d5ed40634d>) returned error, retrying after 1.021868578s: server response unexpected: 500 Internal Server Error (500)
rclone: 2019/05/15 18:42:19 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request put error: googleapi: Error 429: Rate Limit Exceeded, rateLimitExceeded
rclone: 2019/05/15 18:42:19 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request rcat error: googleapi: Error 429: Rate Limit Exceeded, rateLimitExceeded
Save(<lock/d5ed40634d>) returned error, retrying after 892.253525ms: server response unexpected: 500 Internal Server Error (500)
rclone: 2019/05/15 18:42:41 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request put error: googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded
rclone: 2019/05/15 18:42:41 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request rcat error: googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded
Save(<lock/d5ed40634d>) returned error, retrying after 1.345076826s: server response unexpected: 500 Internal Server Error (500)
rclone: 2019/05/15 18:42:49 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request put error: googleapi: Error 429: Rate Limit Exceeded, rateLimitExceeded
rclone: 2019/05/15 18:42:49 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request rcat error: googleapi: Error 429: Rate Limit Exceeded, rateLimitExceeded
Save(<lock/d5ed40634d>) returned error, retrying after 3.170575496s: server response unexpected: 500 Internal Server Error (500)
rclone: 2019/05/15 18:43:43 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request put error: googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded
rclone: 2019/05/15 18:43:43 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request rcat error: googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded
Save(<lock/d5ed40634d>) returned error, retrying after 2.682806044s: server response unexpected: 500 Internal Server Error (500)
rclone: 2019/05/15 18:43:48 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request put error: googleapi: Error 429: Rate Limit Exceeded, rateLimitExceeded
rclone: 2019/05/15 18:43:48 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request rcat error: googleapi: Error 429: Rate Limit Exceeded, rateLimitExceeded
Save(<lock/d5ed40634d>) returned error, retrying after 7.776009567s: server response unexpected: 500 Internal Server Error (500)
rclone: 2019/05/15 18:48:13 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request put error: couldn't list directory: googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded
rclone: 2019/05/15 18:48:13 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request rcat error: couldn't list directory: googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded
Save(<lock/d5ed40634d>) returned error, retrying after 10.223534436s: server response unexpected: 500 Internal Server Error (500)
rclone: 2019/05/15 18:50:26 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request put error: couldn't list directory: googleapi: Error 429: Rate Limit Exceeded, rateLimitExceeded
rclone: 2019/05/15 18:50:26 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request rcat error: couldn't list directory: googleapi: Error 429: Rate Limit Exceeded, rateLimitExceeded
Save(<lock/d5ed40634d>) returned error, retrying after 13.11969732s: server response unexpected: 500 Internal Server Error (500)
rclone: 2019/05/15 18:51:19 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request put error: googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded
rclone: 2019/05/15 18:51:19 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request rcat error: googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded
Save(<lock/d5ed40634d>) returned error, retrying after 10.154872645s: server response unexpected: 500 Internal Server Error (500)
rclone: 2019/05/15 18:51:40 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request put error: googleapi: Error 429: Rate Limit Exceeded, rateLimitExceeded
rclone: 2019/05/15 18:51:40 ERROR : locks/d5ed40634d5070b948da8e4ec2f5029ed22df88457effece47d08d4bbb80a53e: Post request rcat error: googleapi: Error 429: Rate Limit Exceeded, rateLimitExceeded
Fatal: unable to create lock in backend: server response unexpected: 500 Internal Server Error (500)

Dj0k3 · May 15, 2019, 3:42pm

For me Google Drive always returns errors but it always finish. It takes a lot of time, but it is because of Google limitations. Have you tried to unlock the repository to see if that works? You could try restic -r rclone:zombie: unlock and then try again. Here are other posts related to Google Drive errors:

You could also search in this forum for “Google Drive” and see other results that may be helpful.

durval · May 15, 2019, 5:52pm

Hello @Zottelchen,

Is the GoogleDrive account you are using an EDU account, or a “normal” business account?

Coincidence or not, in the last 2 days I started seeing, on an EDU gsuite account with rclone, a lot of these same Limit Exceeded, rateLimitExceeded errors you are seeing with restic on top of rclone.

Perhaps Google messed up something, either intentionally or not, on their end?

On the other hand, on a business GSuite account I use restic a lot (again on top of rclone), I’m having other problems but I see no such errors.

Perhaps contact Google support and see what they say?

Please keep us posted.

Cheers,
– Durval

Zottelchen · May 15, 2019, 6:29pm

@durval Yeah, it is a EDU account. Really seems to be a problem right now (I’ve now seen threads on reddit / rclone), hopefully only temporary. Apparently you can change the user-agent to fix it, so maybe this isn’t an accident. Btw, in the reddit thread is also mentioned that there is now a download limit of 750gb per day.

@Dj0k3 Basically same thing happens

$ restic -r rclone:zombie: unlock
enter password for repository:
Load(<key/412d565d5e>, 0, 0) returned error, retrying after 720.254544ms: <key/412d565d5e> does not exist
repository 1301036c opened successfully, password is correct
Remove(<lock/7d7e59e5d4>) returned error, retrying after 582.280027ms: <lock/7d7e59e5d4> does not exist
Load(<lock/22301c1fd7>, 0, 0) returned error, retrying after 468.857094ms: <lock/22301c1fd7> does not exist
Load(<lock/13d094624c>, 0, 0) returned error, retrying after 462.318748ms: <lock/13d094624c> does not exist
rclone: 2019/05/15 19:50:59 ERROR : locks/13d094624c8305bb8e4e77cfa6ce448628d2d811d6fe47dec7c8ec26500617ed: Delete request remove error: googleapi: Error 429: Rate Limit Exceeded, rateLimitExceeded
Remove(<lock/13d094624c>) returned error, retrying after 593.411537ms: blob not removed, server response: 500 Internal Server Error (500)
Load(<lock/ada20feaed>, 0, 0) returned error, retrying after 282.818509ms: <lock/ada20feaed> does not exist
rclone: 2019/05/15 19:56:43 ERROR : locks/ada20feaedd4f2c92665e73ac2263b35f3fdc0f5397f81b3110292ccd93945ec: Delete request remove error: googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded
Remove(<lock/ada20feaed>) returned error, retrying after 328.259627ms: blob not removed, server response: 500 Internal Server Error (500)
Load(<lock/54727f51cd>, 0, 0) returned error, retrying after 298.484759ms: <lock/54727f51cd> does not exist
Remove(<lock/54727f51cd>) returned error, retrying after 400.45593ms: <lock/54727f51cd> does not exist
rclone: 2019/05/15 20:04:35 ERROR : locks/54727f51cdd2f2fcb9cefc7d03c578a7c1b20c5328da18829bed3a89351f6750: Delete request remove error: googleapi: Error 429: Rate Limit Exceeded, rateLimitExceeded
Remove(<lock/54727f51cd>) returned error, retrying after 761.409471ms: blob not removed, server response: 500 Internal Server Error (500)
Load(<lock/987e8a276b>, 0, 0) returned error, retrying after 656.819981ms: <lock/987e8a276b> does not exist
Load(<lock/987e8a276b>, 0, 0) returned error, retrying after 535.697904ms: <lock/987e8a276b> does not exist
Load(<lock/ab8708e676>, 0, 0) returned error, retrying after 440.328595ms: <lock/ab8708e676> does not exist

durval · May 15, 2019, 6:40pm

Oh crap. Thanks for the info, @Zottelchen. Let’s hope they ‘fix’ it (presuming it’s broken) – meanwhile, I’m just glad I kept a full copy (on duplicate disks) of everything I ever uploaded to Google Drive…

AndyIbanezK · May 15, 2019, 6:44pm

The limit is an upload limit. You can only upload 750GB per day. Download limit is much higher (I believe 10TB).

Dj0k3 · May 15, 2019, 6:53pm

I would try @alejandor solution posted here.

He tried --tpslimit=10 option and it worked. I use Google Drive too for a personal account and always have these errors 400 or something like that, including the lock one but the tasks always finish. I do have much less data than you, so… still take hours sometimes with prune. If I’m not mistaken, the issue is with rclone backend.

Zottelchen · May 15, 2019, 7:11pm

I posted that in reference to this reddit post. I knew of the 750 gb upload limit, but in that post the google support confirmed an 750gb download limit. Which could be of course human error of the support.

durval · May 15, 2019, 10:11pm

Howdy @Zottelchen,

Again thanks for the info. Here, I can confirm that setting rclone’s --user-agent to a random string avoided the issue.

Too bad that Google started resorting to these expedients… :-/

Cheers,
– Durval

Dj0k3 · May 15, 2019, 10:45pm

Nice. I don’t have an EDU account but tried it and it seems to reduce a lot the errors. I’m still getting errors but the process took a lot less time! Thanks for sharing the solution!

durval · May 15, 2019, 10:49pm

Interesting. So it’s not just EDU users that Google is throttling (if indeed throttling it is).

I was under the impression it was connected to the EDU because my EDU account was receiving errors while my business GSuite account wasn’t – but perhaps it has to do with countries of origin (Chile and Germany for the EDU account, and Brazil for the business account). On the reddit topic @Zottelchen posted above, people were mentioning Germany, so it is in accordance with what I was seeing.

Cheers,
– Durval.

cdhowie · May 16, 2019, 4:42pm

7 posts were split to a new topic: Should we discourage users from using Google Drive?

alejandor · May 16, 2019, 11:06am

Also, with my university email account we get unlimited for free, which is why I’m trying to take advantage even if it’s not the most convenient.

I must add that --tpslimit=10 ceased being faultless. Now I’m going at --tpslimit=2 and things go well again. Perhaps there are throttling thresholds (I’ve been hitting on them non-stop for a few days now).

durval · May 16, 2019, 2:39pm

Here, --user-agent=XXXXXX keeps working fine and is effectively working around the problem. Have you tried it?

alejandor · May 16, 2019, 5:30pm

It does seem to be making a difference, even with --tpslimit=10 again. Thanks!