2021/11/01 09:50:18 INFO :
2021/11/01 09:50:20 ERROR : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': error reading destination root directory: couldn't list directory: googleapi: Error 401: Invalid Credentials, authError
2021/11/01 09:50:20 DEBUG : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': Waiting for checks to finish
2021/11/01 09:50:20 DEBUG : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': Waiting for transfers to finish
2021/11/01 09:50:20 ERROR : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': not deleting files as there were IO errors
2021/11/01 09:50:20 ERROR : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': not deleting directories as there were IO errors
2021/11/01 09:50:20 ERROR : Attempt 1/3 failed with 1 errors and: couldn't list directory: googleapi: Error 401: Invalid Credentials, authError
2021/11/01 09:50:20 DEBUG : Creating backend with remote "gdrive-crypt-sa:/archive/2021/2021-11-01_08:33:13"
2021/11/01 09:50:20 DEBUG : fs cache: switching user supplied name "gdrive-sa:/erqd5fvau35q91v162n2gp3sfs/2qrfke4mj0m76u8spiovqifvog/bghvnrknidhe0jcddd4idcfbk8243q6fb19h4ja5ibkgflko2pu0" for canonical name "gdrive-sa{OgfZc}:erqd5fvau35q91v162n2gp3sfs/2qrfke4mj0m76u8spiovqifvog/bghvnrknidhe0jcddd4idcfbk8243q6fb19h4ja5ibkgflko2pu0"
2021/11/01 09:50:20 DEBUG : fs cache: switching user supplied name "gdrive-sa:/erqd5fvau35q91v162n2gp3sfs/2qrfke4mj0m76u8spiovqifvog/bghvnrknidhe0jcddd4idcfbk8243q6fb19h4ja5ibkgflko2pu0" for canonical name "gdrive-sa{OgfZc}:erqd5fvau35q91v162n2gp3sfs/2qrfke4mj0m76u8spiovqifvog/bghvnrknidhe0jcddd4idcfbk8243q6fb19h4ja5ibkgflko2pu0"
2021/11/01 09:50:21 DEBUG : <removed>: Excluded
2021/11/01 09:50:29 DEBUG : <removed>/.DS_Store: Excluded from sync (and deletion)
2021/11/01 09:50:34 DEBUG : <removed>/.DS_Store: Excluded from sync (and deletion)
2021/11/01 09:50:34 DEBUG : <removed>/.DS_Store: Excluded from sync (and deletion)
2021/11/01 09:50:34 DEBUG : <removed>/.DS_Store: Excluded from sync (and deletion)
^^ Same repeats until it eventually fails.
What I've tried:
I have tried with a non service account, same error.
Listing manually rclone ls gdrive-crypt-sa -vv. Works fine.
Everything looks good as far as I can see in the cloud console.
Not sure what's going on.
The whole thing happened after I tweaked the tps-limit due to Dropbox giving error the last few weeks (could also be because of upgrading to latest rclone). But that should not really be relevant. The command have been running every day for months without issue.
Dropbox has nothing to do with Google Drive, except the command is syncing from dropbox to google drive. And the issue happened after I've tweaked Dropbox settings.
Hence why I also wrote: But that should not really be relevant
Anyhow. I did reconnect with the main account (tested first with regular account ie. non service account), then I tried again after rclone config reconnect. Same error.
Service accounts looks fine in the google cloud. AND I can execute commands no problem with the sa account.
rclone -vv mkdir gdrive-crypt-sa:/test
2021/11/01 13:23:54 DEBUG : rclone: Version "v1.56.2" starting with parameters ["rclone" "-vv" "mkdir" "gdrive-crypt-sa:/test"]
2021/11/01 13:23:54 DEBUG : Creating backend with remote "gdrive-crypt-sa:/test"
2021/11/01 13:23:54 DEBUG : Using config file from "/home/<removed>/.config/rclone/rclone.conf"
2021/11/01 13:23:54 DEBUG : Creating backend with remote "gdrive-sa:/bio0l83stlol81sgujc8lhn2ig"
2021/11/01 13:23:54 DEBUG : gdrive-sa: detected overridden config - adding "{4fGU6}" suffix to name
2021/11/01 13:23:54 DEBUG : fs cache: renaming cache item "gdrive-sa:/bio0l83stlol81sgujc8lhn2ig" to be canonical "gdrive-sa{4fGU6}:bio0l83stlol81sgujc8lhn2ig"
2021/11/01 13:23:54 DEBUG : fs cache: switching user supplied name "gdrive-sa:/bio0l83stlol81sgujc8lhn2ig" for canonical name "gdrive-sa{4fGU6}:bio0l83stlol81sgujc8lhn2ig"
2021/11/01 13:23:54 DEBUG : Encrypted drive 'gdrive-crypt-sa:/test': Making directory
2021/11/01 13:23:56 DEBUG : 6 go routines active
Don't think that would give any more info, but here it is an excerpt with more info:
2021/10/31 18:38:54 INFO : Starting transaction limiter: max 1 transactions/s with burst 1
2021/10/31 18:38:54 DEBUG : rclone: Version "v1.56.2" starting with parameters ["rclone" "sync" "dropbox:/" "gdrive-crypt-sa:/last_snapshot" "--backup-dir=gdrive-crypt-sa:/archive/2021/2021-10-31_18:38:53" "--log-file=/home/<removed>/rclone/log/rclone_jobber.log" "--rc" "--rc-no-auth" "--config" "/home/<removed>/rclone/rclone.conf" "--filter-from" "/home/<removed>/rclone/filter_rules" "--fast-list" "--transfers" "24" "--checkers" "24" "--dropbox-chunk-size" "128M" "--dropbox-batch-mode" "sync" "--tpslimit" "1" "--tpslimit-burst" "1" "--drive-chunk-size" "128M" "--create-empty-src-dirs" "--user-agent" "<removed>" "--log-level" "DEBUG"]
2021/10/31 18:38:54 NOTICE: Serving remote control on http://localhost:5572/
2021/10/31 18:38:54 DEBUG : Creating backend with remote "dropbox:/"
2021/10/31 18:38:54 DEBUG : Using config file from "/home/<removed>/rclone/rclone.conf"
2021/10/31 18:38:54 DEBUG : dropbox: detected overridden config - adding "{GLfj_}" suffix to name
2021/10/31 18:38:55 DEBUG : Dropbox root '': Using root namespace "8294458816"
2021/10/31 18:38:55 DEBUG : fs cache: renaming cache item "dropbox:/" to be canonical "dropbox{GLfj_}:"
2021/10/31 18:38:55 DEBUG : Creating backend with remote "gdrive-crypt-sa:/last_snapshot"
2021/10/31 18:38:56 DEBUG : Creating backend with remote "gdrive-sa:/d4g7fbatdhi2k49f7b59alv9t8"
2021/10/31 18:38:56 DEBUG : gdrive-sa: detected overridden config - adding "{OgfZc}" suffix to name
2021/10/31 18:38:58 DEBUG : fs cache: renaming cache item "gdrive-sa:/d4g7fbatdhi2k49f7b59alv9t8" to be canonical "gdrive-sa{OgfZc}:d4g7fbatdhi2k49f7b59alv9t8"
2021/10/31 18:38:58 DEBUG : fs cache: switching user supplied name "gdrive-sa:/d4g7fbatdhi2k49f7b59alv9t8" for canonical name "gdrive-sa{OgfZc}:d4g7fbatdhi2k49f7b59alv9t8"
2021/10/31 18:38:58 DEBUG : Creating backend with remote "gdrive-crypt-sa:/archive/2021/2021-10-31_18:38:53"
2021/10/31 18:38:59 DEBUG : Creating backend with remote "gdrive-sa:/erqd5fvau35q91v162n2gp3sfs/2qrfke4mj0m76u8spiovqifvog/biugauv03f201p7rldbfmjgnlpukcaji1o33cql8mnlncoisquag"
2021/10/31 18:38:59 DEBUG : gdrive-sa: detected overridden config - adding "{OgfZc}" suffix to name
2021/10/31 18:39:06 DEBUG : fs cache: renaming cache item "gdrive-sa:/erqd5fvau35q91v162n2gp3sfs/2qrfke4mj0m76u8spiovqifvog/biugauv03f201p7rldbfmjgnlpukcaji1o33cql8mnlncoisquag" to be canonical "gdrive-sa{OgfZc}:erqd5fvau35q91v162n2gp3sfs/2qrfke4mj0m76u8spiovqifvog/biugauv03f201p7rldbfmjgnlpukcaji1o33cql8mnlncoisquag"
2021/10/31 18:39:06 DEBUG : fs cache: switching user supplied name "gdrive-sa:/erqd5fvau35q91v162n2gp3sfs/2qrfke4mj0m76u8spiovqifvog/biugauv03f201p7rldbfmjgnlpukcaji1o33cql8mnlncoisquag" for canonical name "gdrive-sa{OgfZc}:erqd5fvau35q91v162n2gp3sfs/2qrfke4mj0m76u8spiovqifvog/biugauv03f201p7rldbfmjgnlpukcaji1o33cql8mnlncoisquag"
(…)
2021/10/31 19:12:39 DEBUG : Google drive root 'd4g7fbatdhi2k49f7b59alv9t8': Disabling ListR to work around bug in drive as multi listing (50) returned no entries
2021/10/31 19:12:39 DEBUG : Google drive root 'd4g7fbatdhi2k49f7b59alv9t8': Recycled 50 entries
2021/10/31 19:12:58 INFO :
Transferred: 0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time: 34m4.1s
(…)
2021/10/31 19:45:58 INFO :
Transferred: 0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time: 1h7m4.1s
2021/10/31 19:46:29 ERROR : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': error reading destination root directory: couldn't list directory: googleapi: Error 401: Invalid Credentials, authError
2021/10/31 19:46:29 DEBUG : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': Waiting for checks to finish
2021/10/31 19:46:29 DEBUG : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': Waiting for transfers to finish
2021/10/31 19:46:29 ERROR : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': not deleting files as there were IO errors
2021/10/31 19:46:29 ERROR : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': not deleting directories as there were IO errors
2021/10/31 19:46:29 ERROR : Attempt 1/3 failed with 1 errors and: couldn't list directory: googleapi: Error 401: Invalid Credentials, authError
2021/10/31 19:46:29 DEBUG : Creating backend with remote "gdrive-crypt-sa:/archive/2021/2021-10-31_18:38:53"
2021/10/31 19:46:30 DEBUG : fs cache: switching user supplied name "gdrive-sa:/erqd5fvau35q91v162n2gp3sfs/2qrfke4mj0m76u8spiovqifvog/biugauv03f201p7rldbfmjgnlpukcaji1o33cql8mnlncoisquag" for canonical name "gdrive-sa{OgfZc}:erqd5fvau35q91v162n2gp3sfs/2qrfke4mj0m76u8spiovqifvog/biugauv03f201p7rldbfmjgnlpukcaji1o33cql8mnlncoisquag"
2021/10/31 19:46:30 DEBUG : fs cache: switching user supplied name "gdrive-sa:/erqd5fvau35q91v162n2gp3sfs/2qrfke4mj0m76u8spiovqifvog/biugauv03f201p7rldbfmjgnlpukcaji1o33cql8mnlncoisquag" for canonical name "gdrive-sa{OgfZc}:erqd5fvau35q91v162n2gp3sfs/2qrfke4mj0m76u8spiovqifvog/biugauv03f201p7rldbfmjgnlpukcaji1o33cql8mnlncoisquag")
(…)
2021/10/31 20:54:58 INFO :
Transferred: 0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time: 2h16m4.1s
2021/10/31 20:55:57 ERROR : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': error reading destination root directory: couldn't list directory: googleapi: Error 401: Invalid Credentials, authError
2021/10/31 20:55:57 DEBUG : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': Waiting for checks to finish
2021/10/31 20:55:57 DEBUG : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': Waiting for transfers to finish
2021/10/31 20:55:57 ERROR : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': not deleting files as there were IO errors
2021/10/31 20:55:57 ERROR : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': not deleting directories as there were IO errors
2021/10/31 20:55:57 ERROR : Attempt 2/3 failed with 1 errors and: couldn't list directory: googleapi: Error 401: Invalid Credentials, authError
2021/10/31 20:55:57 DEBUG : Creating backend with remote "gdrive-crypt-sa:/archive/2021/2021-10-31_18:38:53"
2021/10/31 20:55:57 DEBUG : fs cache: switching user supplied name "gdrive-sa:/erqd5fvau35q91v162n2gp3sfs/2qrfke4mj0m76u8spiovqifvog/biugauv03f201p7rldbfmjgnlpukcaji1o33cql8mnlncoisquag" for canonical name "gdrive-sa{OgfZc}:erqd5fvau35q91v162n2gp3sfs/2qrfke4mj0m76u8spiovqifvog/biugauv03f201p7rldbfmjgnlpukcaji1o33cql8mnlncoisquag"
2021/10/31 20:55:57 DEBUG : fs cache: switching user supplied name "gdrive-sa:/erqd5fvau35q91v162n2gp3sfs/2qrfke4mj0m76u8spiovqifvog/biugauv03f201p7rldbfmjgnlpukcaji1o33cql8mnlncoisquag" for canonical name "gdrive-sa{OgfZc}:erqd5fvau35q91v162n2gp3sfs/2qrfke4mj0m76u8spiovqifvog/biugauv03f201p7rldbfmjgnlpukcaji1o33cql8mnlncoisquag"
2021/10/31 20:55:58 INFO :
Transferred: 0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time: 2h17m4.1s
(…)
2021/10/31 21:53:58 INFO :
Transferred: 0 / 0 Byte, -, 0 Byte/s, ETA -
Elapsed time: 3h15m4.1s
2021/10/31 21:54:12 ERROR : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': error reading destination root directory: couldn't list directory: googleapi: Error 401: Invalid Credentials, authError
2021/10/31 21:54:12 DEBUG : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': Waiting for checks to finish
2021/10/31 21:54:12 DEBUG : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': Waiting for transfers to finish
2021/10/31 21:54:12 ERROR : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': not deleting files as there were IO errors
2021/10/31 21:54:12 ERROR : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': not deleting directories as there were IO errors
2021/10/31 21:54:12 ERROR : Attempt 3/3 failed with 1 errors and: couldn't list directory: googleapi: Error 401: Invalid Credentials, authError
2021/10/31 21:54:12 INFO :
Transferred: 0 / 0 Byte, -, 0 Byte/s, ETA -
Errors: 1 (retrying may help)
Elapsed time: 3h15m18.2s
2021/10/31 21:54:12 DEBUG : 12 go routines active
2021/10/31 21:54:12 Failed to sync: couldn't list directory: googleapi: Error 401: Invalid Credentials, authError
2021/10/31 21:54:12 INFO : Dropbox root '': Commiting uploads - please wait...
2021-10-31_21:54:13 ERROR: rcj-blox.sh failed. rclone exit_code=1
It makes no sense to me that I'm getting 2021/10/31 21:54:12 ERROR : Encrypted drive 'gdrive-crypt-sa:/last_snapshot': error reading destination root directory: couldn't list directory: googleapi: Error 401: Invalid Credentials, authError
While running: rclone --fast-list ls -vv gdrive-crypt-sa:/last_snapshot
and rclone -vv mkdir gdrive-crypt-sa:/test
rclone -vv copy rclonecmd.log gdrive-crypt-sa:/test
2021/11/01 14:35:20 DEBUG : rclone: Version "v1.56.2" starting with parameters ["rclone" "-vv" "copy" "rclonecmd.log" "gdrive-crypt-sa:/test"]
2021/11/01 14:35:20 DEBUG : Creating backend with remote "rclonecmd.log"
2021/11/01 14:35:20 DEBUG : Using config file from "/home/<removed>/.config/rclone/rclone.conf"
2021/11/01 14:35:20 DEBUG : fs cache: adding new entry for parent of "rclonecmd.log", "/home/blaa/rclone/log"
2021/11/01 14:35:20 DEBUG : Creating backend with remote "gdrive-crypt-sa:/test"
2021/11/01 14:35:20 DEBUG : Creating backend with remote "gdrive-sa:/bio0l83stlol81sgujc8lhn2ig"
2021/11/01 14:35:21 DEBUG : fs cache: renaming cache item "gdrive-sa:/bio0l83stlol81sgujc8lhn2ig" to be canonical "gdrive-sa:bio0l83stlol81sgujc8lhn2ig"
2021/11/01 14:35:21 DEBUG : fs cache: switching user supplied name "gdrive-sa:/bio0l83stlol81sgujc8lhn2ig" for canonical name "gdrive-sa:bio0l83stlol81sgujc8lhn2ig"
2021/11/01 14:35:21 DEBUG : rclonecmd.log: Need to transfer - File not found at Destination
2021/11/01 14:35:22 DEBUG : rclonecmd.log: md5 = da33cf793d58cf40f249592d36e6140c OK
2021/11/01 14:35:22 INFO : rclonecmd.log: Copied (new)
2021/11/01 14:35:22 INFO :
Transferred: 658 / 658 Byte, 100%, 657 Byte/s, ETA 0s
Transferred: 1 / 1, 100%
Elapsed time: 2.3s
2021/11/01 14:35:22 DEBUG : 7 go routines active
Don't think it should be a quota issue. Not seeing anything in the cloud console, and using different users should remedy that (since I tested with both service accounts and regular user)
You can't see any quota issues in the console really as your quota isn't tracked anywhere unfortunately.
The way it works is if are you close to quota, you can usually copy small files as you edge closer to the limit but if you have large files, they would fail so a small file test isn't useful unfortunately.
I see some logs are a team drive, but in your post you say it's a personal drive. Which is it? Does it work without a SA account and using a regular user?
I can try to copy a large file, but it's not been very much data generated lately, so shouldn't be an issue.
This is uploaded to a Google Workspace account – not a team drive (due to the file number limitation). So the account is locked to a directory inside my users workspace drive.
Actually it seems like the data gets copied on ever run, and the issue happens when rclone tries to move the files from the last_snapshot directory to the backup archive.
No, not really. What I meant is using root_folder_id in the config – to lock it to a directory.
Also using impersonate = user@domain.tld to make the files belong to the main account (makes it easier if I need to move/delete files, etc.)
The directory is shared with a group (that consists of 3 service accounts – mostly only one is used) with "editor" rights.
Been running this setup for over a year, without issues. Until recently Dropbox started giving errors and now Google.
For testing, what happens if you remove the root ID and let it do it's own thing since it doesn't seem to be a quota issue. I've never tested or used changing the root ID to not be the actual root ID.
Don't think that would be relevant, and it would make it hard to reproduce I think. I've tested to create files, delete files, list files manually. So all should be good.
I did test to go back to 1.56.0, and now 1.57.0, but I still get the same error.
I do have logs of it with dumped headers, but I can't really tell what wrong. They are not sanitized, so I will not put them up here.
Maybe @ncw has any aditional input (or would like to see the log)?
I see your point, but I do not agree it's very unique. I've been doing that for years without issue. It's just jails that rclone remote to that specific directory.
Out of the thousands of posts I've read, commented on and helped folks, it is the first time I've seen it in use so that feels pretty unique from my perspective. Good luck.
