I've got a cron job running a master rsync script once a week to back up 50+ individual volumes. In the auto generated reports, I've noticed I consistently have 7 remotes that fail to sync due to a failure to connect to their corresponding google drive. When I recreate the remote with its Client ID and Secret, it fixes that remote but breaks another. Only one unique API OAuth 2.0 Client ID is assigned to all remotes. The script has been cut down for simplicity, and only one -vv remote error log is included.
v1.52.0
Mac OS 10.14.5
Google Drive
The command you were trying to run (eg rclone copy /tmp remote:tmp)
#!/bin/bash
# This script is set to run regularly with crontab to keep terrablock volumes up to date (use command "crontab -l" to find in terminal)
# Newly created volumes must be manually added to this script in order to be regularly synced
# This is only a secondary backup, any new data of high value should have a primary backup on site
# Establishes a time variable used to calculate total script run time
SECONDS=0
duration=$SECONDS
# Tell crontab where the rclone config file is
RCLONE_CONFIG=/Users/nahb/.config/rclone/rclone.conf
# Detailed information on progress is written to a new file here on each run
LOGFILE="/Users/nahb/Desktop/Rclone/Reports/Master_Sync_$(date +%Y-%m-%d_%H-%M).log"
# Sync controls
FLAGS="-P --bwlimit=8.65M --exclude-from /Users/nahb/Desktop/Rclone/rclone_exclude_files.txt --skip-links --max-delete=0 -v --log-file=$LOGFILE"
# Put new volumes in here
cmd1="/usr/local/bin/rclone sync /volumes/VoiceOvers VoiceOvers:"
cmd2="/usr/local/bin/rclone sync /volumes/07_MEDIA 07_MEDIA:"
cmd3="/usr/local/bin/rclone sync /volumes/08_MEDIA 08_MEDIA:"
# Run syncs and make note in the log file
echo $(date +%Y-%m-%d_%H:%M) $cmd1 STARTED | tee -a $LOGFILE
$cmd1 $FLAGS
echo $(date +%Y-%m-%d_%H:%M) $cmd2 STARTED | tee -a $LOGFILE
$cmd2 $FLAGS
echo $(date +%Y-%m-%d_%H:%M) $cmd3 STARTED | tee -a $LOGFILE
$cmd3 $FLAGS
echo "$(date +%Y-%m-%d_%H:%M) RCLONE SYNC FINISHED IN $(($duration / 3600)) HOURS AND $(($duration / 60)) MINUTES" | tee -a $LOGFILE
exit
The rclone config contents with secrets removed.
type= drive
scope=drive
team drive = "yes"
A log from the command with the -vv flag
2020/11/03 14:14:53 DEBUG : rclone: Version "v1.52.0" starting with parameters ["rclone" "sync" "/volumes/1153_Warburton" "1153_Warburton:" "-P" "--bwlimit=8.65M" "--exclude-from" "/Users/nahb/Desktop/Rclone/rclone_exclude_files.txt" "--skip-links" "--max-delete=0" "-vv"]
2020/11/03 14:14:53 DEBUG : Using config file from "/Users/nahb/.config/rclone/rclone.conf"
2020/11/03 14:14:53 INFO : Starting bandwidth limiter at 8.650MBytes/s
2020-11-03 14:14:53 DEBUG : 1153_Warburton: Loaded invalid token from config file - ignoring
2020-11-03 14:14:53 DEBUG : .DS_Store: Excluded
2020-11-03 14:14:53 DEBUG : .TemporaryItems: Excluded
2020-11-03 14:14:53 DEBUG : 1153_Warburton: Token refresh failed try 1/5: oauth2: cannot fetch token: 400 Bad Request
Response: {
"error": "invalid_grant",
"error_description": "Bad Request"
}
2020-11-03 14:14:54 DEBUG : 1153_Warburton: Loaded invalid token from config file - ignoring
2020-11-03 14:14:54 DEBUG : 1153_Warburton: Token refresh failed try 2/5: oauth2: cannot fetch token: 400 Bad Request
Response: {
"error": "invalid_grant",
"error_description": "Bad Request"
}
2020-11-03 14:14:55 DEBUG : 1153_Warburton: Loaded invalid token from config file - ignoring
2020-11-03 14:14:55 DEBUG : 1153_Warburton: Token refresh failed try 3/5: oauth2: cannot fetch token: 400 Bad Request
Response: {
"error": "invalid_grant",
"error_description": "Bad Request"
}
2020-11-03 14:14:56 DEBUG : 1153_Warburton: Loaded invalid token from config file - ignoring
2020-11-03 14:14:56 DEBUG : 1153_Warburton: Token refresh failed try 4/5: oauth2: cannot fetch token: 400 Bad Request
Response: {
"error": "invalid_grant",
"error_description": "Bad Request"
}
2020-11-03 14:14:57 DEBUG : 1153_Warburton: Loaded invalid token from config file - ignoring
2020-11-03 14:14:57 DEBUG : 1153_Warburton: Token refresh failed try 5/5: oauth2: cannot fetch token: 400 Bad Request
Response: {
"error": "invalid_grant",
"error_description": "Bad Request"
}
2020-11-03 14:14:58 ERROR : : error reading destination directory: couldn't list directory: Get "https://www.googleapis.com/drive/v3/files?alt=json&corpora=drive&driveId=0AI_kbOLUQS5GUk9PVA&fields=files%28id%2Cname%2Csize%2Cmd5Checksum%2Ctrashed%2CmodifiedTime%2CcreatedTime%2CmimeType%2Cparents%2CwebViewLink%2CshortcutDetails%29%2CnextPageToken%2CincompleteSearch&includeItemsFromAllDrives=true&pageSize=1000&prettyPrint=false&q=trashed%3Dfalse+and+%28%270AI_kbOLUQS5GUk9PVA%27+in+parents%29&supportsAllDrives=true": couldn't fetch token - maybe it has expired? - refresh with "rclone config reconnect 1153_Warburton:": oauth2: cannot fetch token: 400 Bad Request
Response: {
"error": "invalid_grant",
"error_description": "Bad Request"
}
2020-11-03 14:14:58 DEBUG : Google drive root '': Waiting for checks to finish
2020-11-03 14:14:58 DEBUG : Google drive root '': Waiting for transfers to finish
2020-11-03 14:14:58 ERROR : Google drive root '': not deleting files as there were IO errors
2020-11-03 14:14:58 ERROR : Google drive root '': not deleting directories as there were IO errors
2020-11-03 14:14:58 INFO : There was nothing to transfer
2020-11-03 14:14:58 ERROR : Attempt 1/3 failed with 1 errors and: couldn't list directory: Get "https://www.googleapis.com/drive/v3/files?alt=json&corpora=drive&driveId=0AI_kbOLUQS5GUk9PVA&fields=files%28id%2Cname%2Csize%2Cmd5Checksum%2Ctrashed%2CmodifiedTime%2CcreatedTime%2CmimeType%2Cparents%2CwebViewLink%2CshortcutDetails%29%2CnextPageToken%2CincompleteSearch&includeItemsFromAllDrives=true&pageSize=1000&prettyPrint=false&q=trashed%3Dfalse+and+%28%270AI_kbOLUQS5GUk9PVA%27+in+parents%29&supportsAllDrives=true": couldn't fetch token - maybe it has expired? - refresh with "rclone config reconnect 1153_Warburton:": oauth2: cannot fetch token: 400 Bad Request
Response: {
"error": "invalid_grant",
"error_description": "Bad Request"
Do these backups run simultaneously off the same config file? It doesn't look like it from your script... Or are there other rclone's running at the same time off the same config file?
Is each of your 07_MEDIA:08_MEDIA: remotes a separate google remote? I guess each one is a separate google shared drive (team drive) is that correct?
I think this means the refresh token has expired.
When you run rclone config reconnect for these do you run them individually? Or do you cut and paste the token between the remotes in the config file?
It might be worth trying with the latest rclone v1.53.2 - I can't think of a specific fix but it would be worth a try.
Everything I see suggests each backup runs one at a time, but no, I don't have other instances of rclone running. They all reference the same config file (or at least, I can see every remote on the single config file). You are correct, each volume listed in the code is an individual remote pointing to an individual google team drive.
Per your rclone config reconnect comment, I'm not sure I understand. I don't think I've ever run the rclone config reconnect command. Can you define "token" for me? I assume this is not related to the oauth ID and secret.
Ill check out the lastest rclone version and report back. Thanks for the help!
Rclone uses the client_id and client_secret to get a token and this token is what is actually used by the API. When the token expires, rclone needs to get a new one which it does with the refresh token. If that doesn't work then you need to reconnect the remote. You can do this by running through rclone config again, or you can run rclone config reconnect remote: as a shorthand to say - don't change anything, just get me a new token.
I like this config reconnect shortcut, and thanks for helping me wrap my brain around the "token". This "copy and pasting" the token between volumes as you mentioned above, is this synonymous with copying and pasting the ID and Secret between remotes?
Odd that I'm seeing this apparent token expiration issue. The master log file doesn't suggest that the token is being "used up" resulting in consecutive failures. Every time, 7 specific volumes fail to refresh the token, and fixing one breaks another. Does the token support a max number of remotes tied to a max number of google drive shared drives?
Also, If I download and install an updated version of rclone, will I lose my config file unless I make a copy?
I've attached my master log for reference. (there are a few other issues you might see, I've been working through them one at a time)
Can you see if any of the token lines are duplicated?
Can you see if any of the refresh_tokens are duplicated? What might be happening is that Google is detecting the multiple use of the refresh token and banning it somehow.
If that is the case then just using one remote but passing --drive-team-drive XXX to each call would work around it. That is a bit of a pain though...
If I have a total of 53 remotes and consistently see 7 token request failures I either have 4 duplicates or 4 expired tokens failing to refresh.
Possible workaround would be to introduce a second account with a new OAuth 2.0. In theory I could have double the remotes (and not have to worry which drives and backed up vs not) but its less clean...
Unfortunately I think I need to have individual remotes tied to the specific volumes I'm backing up. Better control over who can see/access what as opposed to having a single remote with folders per volume. I'll have to check out the service account too.
