Expired tokens not refreshed
glyn opened this issue · 6 comments
According to the docs:
The [InstalledFlowAuthenticator] takes care of caching tokens to disk and refreshing tokens once
they've expired.
The first part of this works nicely: tokens are cached on disk. However, when these tokens expire, the first attempt to call the remote API results in:
Error: MissingToken(AuthError(AuthError { error: InvalidGrant, error_description: Some("Bad Request"), error_uri: None }))
which seems to imply that the tokens have expired and have not been refreshed. This is in a relatively short running application, so the installed flow authenticator has just been built using the disk cache (i.e., I'm not talking about a long running application in which the failing flow occurs a long time after the authenticator has been built).
Turning on debug logging yields a further log:
[2021-11-11T16:52:12Z DEBUG yup_oauth2::refresh] Received response; head: Parts { status: 400, version: HTTP/2.0, headers: {"pragma": "no-cache", "cache-control": "no-cache, no-store, max-age=0, must-revalidate", "expires": "Mon, 01 Jan 1990 00:00:00 GMT", "date": "Thu, 11 Nov 2021 16:52:12 GMT", "content-type": "application/json; charset=utf-8", "vary": "X-Origin", "vary": "Referer", "vary": "Origin,Accept-Encoding", "server": "scaffolding on HTTPServer2", "x-xss-protection": "0", "x-frame-options": "SAMEORIGIN", "x-content-type-options": "nosniff", "alt-svc": "h3=\":443\"; ma=2592000,h3-29=\":443\"; ma=2592000,h3-Q050=\":443\"; ma=2592000,h3-Q046=\":443\"; ma=2592000,h3-Q043=\":443\"; ma=2592000,quic=\":443\"; ma=2592000; v=\"46,43\"", "accept-ranges": "none"} }, body: b"{\n \"error\": \"invalid_grant\",\n \"error_description\": \"Bad Request\"\n}"
Error: MissingToken(AuthError(AuthError { error: InvalidGrant, error_description: Some("Bad Request"), error_uri: None }))
For more context, see this area of my code.
Is this the case for more than one API? 'Bad request' could either mean that the library is issuing a wrong request (maybe something on the server side changed), or that the API is special for some reason.
The request being issued is valid because if I delete the token cache the application works fine.
@dermesser Re-reading your response, I have only used yup-oauth2 with the YouTube API. However, YouTube appears to use Google's general authorisation server (https://accounts.google.com/o/oauth2/v2/auth), which makes me think it's rather unlikely that this issue is specific to YouTube and may apply to other Google services.
If you have any suggestions for how to debug this issue, I'm happy to assist. Not being an expert in oauth2, it's hard to dive in.
Re-running the failure with log trace configured, gives this log output which includes:
[2021-12-15T05:09:02Z DEBUG yup_oauth2::authenticator] access token requested for scopes: [https://www.googleapis.com/auth/youtube.readonly]
[2021-12-15T05:09:02Z DEBUG yup_oauth2::refresh] refreshing access token with refresh token: 1//036vPnah6LqJJCgYIARAAGAMSNwF-L9Irv6svpgLbNl3tzMU85Ao5qSPld0NSNle2nVsXDZBT-ZuOpSr79UqrYuToMB4ZxtF4FTA
[2021-12-15T05:09:02Z DEBUG yup_oauth2::refresh] Sending request: Request { method: POST, uri: https://oauth2.googleapis.com/token, version: HTTP/1.1, headers: {"content-type": "application/x-www-form-urlencoded"}, body: Body(Full(b"client_id=663812898511-gkjnnh493ar17niq2e7qv13pk9vgiqvv.apps.googleusercontent.com&client_secret=WkBzMjRAYGQ01gikreObiVLb&refresh_token=1%2F%2F036vPnah6LqJJCgYIARAAGAMSNwF-L9Irv6svpgLbNl3tzMU85Ao5qSPld0NSNle2nVsXDZBT-ZuOpSr79UqrYuToMB4ZxtF4FTA&grant_type=refresh_token")) }
so a refresh token is being used to obtain an access token.
Please note the above behaviour is being observed with yup-oauth2 = "5.1.0" as this version is required by the google-youtube3 crate. However, I have no reason to believe the behaviour is any better with a later version of yup-auth2.