Exchange SSO refresh token for access token API call results in an HTTP 500 Error

[tomzorz]

Exchange SSO refresh token for access token API call results in an HTTP 500 Error

Description

I'm trying to call the "exchange refresh token for access token" API, and I'm getting an HTTP 500 error. This API has worked in the past. I know if I provide it a random string for refresh token, it will complain it wasn't a proper token - so the code does run partially. But otherwise I get no information back besides '{"fieldErrors":{},"generalErrors":[{"code":"[Exception]","message":"FusionAuth encountered an unexpected error. Please review the troubleshooting guide found in the documentation for assistance and the available support channels."}]}'. I don't even see the error in the logs of our instance.

Affects versions

1.46.0, 1.48.3.

Steps to reproduce

• enable refresh tokens on the login api (also works with oauth2 grants, but this is simpler)
• when you login to any application (including the admin ui) check 'keep me signed in'
• retrieve the token values using the api. Select the token with no application id.
• present that to the oauth2 token endpoint
• see this error

{"fieldErrors":{},"generalErrors":[{"code":"[Exception]","message":"FusionAuth encountered an unexpected error. Please review the troubleshooting guide found in the documentation for assistance and the available support channels."}]}%   

• look in the system log and see

fusionauth-1  | 2024-01-23 04:54:34.335 PM ERROR io.fusionauth.app.primeframework.error.ExceptionExceptionHandler - An unhandled exception was thrown
fusionauth-1  | java.lang.NullPointerException: Cannot invoke "java.util.UUID.equals(Object)" because "<parameter1>.refreshToken.applicationId" is null
fusionauth-1  | 	at io.fusionauth.api.service.oauth2.DefaultOAuthService.validateTokenEndpointRefreshTokenGrant(DefaultOAuthService.java:2185)
fusionauth-1  | 	at io.fusionauth.api.service.oauth2.DefaultOAuthService.validateTokenRequest(DefaultOAuthService.java:1270)
fusionauth-1  | 	at io.fusionauth.app.action.oauth2.TokenAction.post(TokenAction.java:125)
fusionauth-1  | 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
fusionauth-1  | 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)

Original steps to reproduce

Invoke the API with a valid refresh token.

Expected behavior

We get an access token.

Screenshots

Nothing useful.

Platform

• Device: Desktop/any
• OS: Windows, any
• Browser + version: Vivaldi latest, but any
• Database: you are hosting

Community guidelines

Release notes

Improved validation and error messaging when calling the /oauth2/token endpoint with an incorrect refresh token.

[robotdan]

Can you please provide recreate steps? Be as specific as possible, if you can recreate with a curl command or something like that, this would be helpful.

[tomzorz]

Sorry @robotdan I totally missed your original response here. Here's the curl command:

curl -v -XPOST -H 'User-Agent: python-requests/2.28.1' -H 'Accept: */*' -H 'Connection: keep-alive' -H 'Content-Type: application/x-www-form-urlencoded' -d 'refresh_token=REDACTED&client_id=REDACTED&client_secret=REDACTED&grant_type=refresh_token' 'https://REDACTED/oauth2/token' --output -

I am happy to provide you with the secret details somewhere privately.

Response from cURL {"fieldErrors":{},"generalErrors":[{"code":"[Exception]","message":"FusionAuth encountered an unexpected error. Please review the troubleshooting guide found in the documentation for assistance and the available support channels."}]}(

[tomzorz]

I realize this is not much more info than I provided, but I also don't want to leak our secret keys or my refresh key. As I mentioned, if I put in a garbage string for refresh key, it will say The refresh_token is invalid, so the logic clearly grabs the token, just fails somewhere afterwards.

[mooreds]

@tomzorz Hmmm. sorry to hear this.

I have tried to replicate this on the sandbox.fusionauth.io environment, which is running 1.48.3, and was unable to. I did the following:

• enabled the refresh token from the login api for a given application
• logged the user in using this curl script:

curl -H 'content-type: application/json' -H 'Authorization: 90d8fb62-6f13-47d4-8ef6-1c3e687883c6' https://sandbox.fusionauth.io/api/login -d '{"loginId":"sandbox@fusionauth.io", "password": "4xDU4RTwB6Wp", "applicationId":"85a03867-dccf-4882-adde-1a79aeec50df"}'

• took the refresh token and your curl script and ran it

Additional questions that will help us troubleshoot:

• does this happen repeatedly or intermittently
• does making a second request resolve the error
• does this occur only in your prod environment or locally
• does this occur on the latest version of FusionAuth (1.48.3)
• how are you acquiring the refresh token (login api, oauth authorization code grant)
• are there any errors in the event log (System -> Event Log in the admin UI) or system log (System -> Logs) when this occurs
• are there any patterns (occurring at a certain time, for a certain user, for a certain application, when you make a large number of api calls)
• what are your refresh token settings (Tenants -> your tenant -> JWT -> refresh token settings in the admin UI)
• can you replicate this issue on sandbox.fusionauth.io (that environment is public and reset nightly, so sharing details about that in a GH issue is okay)

Again, sorry this is an issue. We'll need some help from you to troubleshoot this further.

[tomzorz]

does this happen repeatedly or intermittently

Every single time with every request.

does making a second request resolve the error

No.

does this occur only in your prod environment or locally

We're using a deployment managed by FA, I guess it's a "prod" environment in that way.

does this occur on the latest version of FusionAuth (1.48.3)

Our deployed version is at 1.46.0, I haven't seen any related issues in the changelog since (although admittedly we should probably update)

how are you acquiring the refresh token (login api, oauth authorization code grant)

OAuth code grant.

are there any errors in the event log (System -> Event Log in the admin UI) or system log (System -> Logs) when this occurs

We see errors when other errors occur, there are no log events for this error though. I finally noticed this in the "raw" system logs (stacktrace shortened for brevity):

2024-01-18 06:29:40.743 AM ERROR io.fusionauth.app.primeframework.error.ExceptionExceptionHandler - An unhandled exception was thrown
java.lang.NullPointerException: Cannot invoke "java.util.UUID.equals(Object)" because "<parameter1>.refreshToken.applicationId" is null
	at io.fusionauth.api.service.oauth2.DefaultOAuthService.validateTokenEndpointRefreshTokenGrant(DefaultOAuthService.java:2167)
	at io.fusionauth.api.service.oauth2.DefaultOAuthService.validateTokenRequest(DefaultOAuthService.java:1252)
	at io.fusionauth.app.action.oauth2.TokenAction.post(TokenAction.java:125)
	at jdk.internal.reflect.GeneratedMethodAccessor91.invoke(Unknown Source)

are there any patterns (occurring at a certain time, for a certain user, for a certain application, when you make a large number of api calls)

It occurs every time, for every user as far as I can tell.

what are your refresh token settings (Tenants -> your tenant -> JWT -> refresh token settings in the admin UI)

Fixed expiration policy, 2 weeks (20160 minutes), one-time use, revocation on action preventing login & password change.

can you replicate this issue on sandbox.fusionauth.io (that environment is public and reset nightly, so sharing details about that in a GH issue is okay)

I can't. I also created a PoC replica of the calls with your python library we're using for the sandbox env, couldn't replicate it there either.

I made sure to match the sandbox environment as close as I could get it to ours. I am also using the exact same python calls.

[mooreds]

Hmmm.

I stood up a 1.46.0 local server and tried to replicate this. I was unable to do so.

I also created a PoC replica of the calls

Was this PoC using 1.46.0?

• did any configuration or related code change when this error started showing up?
• FYI, if this is a bug, we only fix forward (so wouldn't backport the fix). If you can, it would be helpful to upgrade your system to 1.48.3 and see if that fixes it.

[tomzorz]

The PoC script used our logic to target our 1.46 env, and then I switched it out to the sandbox 1.48.3 one - essentially to test and make sure the issue isn't somewhere in the python library or something. But yeah, couldn't replicate in the sandbox, only in ours.

I guess I'll try updating to 1.48.3 and see if that helps. As far as I know, we didn't make any configuration or code changes... but also we haven't been reliably using the exchange refresh token feature in recent time so I am not sure when it might've broke. I remember initially when we implemented it, it worked. And then at some point in the past ~8 months it broke.

[mooreds]

Okay. Please let us know what happens with the 1.48.3 update and we can discuss next steps.

[tomzorz]

@mooreds I have upgraded to 1.48.3 and the issue still persists the same way. Stacktrace looks similar:

2024-01-23 05:50:12.852 AM ERROR io.fusionauth.app.primeframework.error.ExceptionExceptionHandler - An unhandled exception was thrown
java.lang.NullPointerException: Cannot invoke "java.util.UUID.equals(Object)" because "<parameter1>.refreshToken.applicationId" is null
	at io.fusionauth.api.service.oauth2.DefaultOAuthService.validateTokenEndpointRefreshTokenGrant(DefaultOAuthService.java:2185)
	at io.fusionauth.api.service.oauth2.DefaultOAuthService.validateTokenRequest(DefaultOAuthService.java:1270)
	at io.fusionauth.app.action.oauth2.TokenAction.post(TokenAction.java:125)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

I have also expanded my test script a little to verify that we do properly save and restore the refresh token from the client - the retrieve refresh tokens endpoint gives me back the same one from the session:

I also tried out the other "exchange refresh token for jwt" call, that just returns a completely empty 404 and there isn't even anything in the regular log or the event log.

[mooreds]

Okay, I have replicated the issue.

We need to fix this, but for now I'd recommend filtering any refresh tokens you get and removing any that don't have an application Id. Refresh tokens that don't have an application Id are for internal use only (they represent our SSO session) and shouldn't be presented to the /oauth2/token endpoint.

I updated the documentation ( FusionAuth/fusionauth-site#2836 ).

Please try that and let me know if you still see the issue.

[tomzorz]

Hmm, okay I'll try and see what tokens do we have / get.

[robotdan]

The root issue appears to be that you are using an SSO token - which is a special kind of refresh token. The correct behavior of the API should be to fail with a validation error indicate the token was not found.

[robotdan]

Internal:

• https://github.com/FusionAuth/fusionauth-app/pull/368

[tomzorz]

Okay so looks like our logic right now takes first token from the "get refresh tokens" API and uses that after we succeed with the "exchange oauth code for access token with pkce" call. I imagine this is where we mess up currently.

Is there a reason btw why these "internal" refresh tokens are included in the "get refresh tokens" call? If I/we can't use these for anything?

[mooreds]

Is there a reason btw why these "internal" refresh tokens are included in the "get refresh tokens" call? If I/we can't use these for anything?

You might want to revoke them or otherwise examine them. See FusionAuth/fusionauth-site#2836 (comment) from @robotdan .

[tomzorz]

Ok so one more question, is there some setting we might not have turned on to get these "proper" refresh tokens? I just did a query in our logs and in the last 90 days we barely have any results where we do actually have one:

I just did multiple logins on my own account, always had "keep me logged in" turned on - and yet no applicable refresh tokens in our logs today. (To note, this API is called every time when someone logs in.)

[mooreds]

"keep me logged in" is for SSO refresh tokens (the ones you should avoid)

the other one requires you request the offline_access scope. More here: https://fusionauth.io/docs/lifecycle/authenticate-users/oauth/endpoints#authorization-code-grant-request

[tomzorz]

Ohhhh, okay. TIL :) I think I just made the connection in my head, what the difference is exactly and why it is the way it is. Although I will say, as an end-user I would imagine that checkbox do what I thought we were doing :)

[mooreds]

I hear you! We need more 201 level content. Sorry for the confusion!

[tomzorz]

All good, I have def needed to learn more too. Also side-question: is there a way then for us to add a "keep me logged in" option that does what we thought the current one does? Or do we have to set the scopes early, and even before redirecting to the flow have the option set for the user whether they want it or not?

[robotdan]

Will be fixed in 1.49.0.

[robotdan]

Also side-question: is there a way then for us to add a "keep me logged in" option that does what we thought the current one does? Or do we have to set the scopes early, and even before redirecting to the flow have the option set for the user whether they want it or not?

If I understand the question... you are asking how to maintain state in your app - outside of the FusionAuth SSO?

Checking the box "keep me logged in" will just cause us to create an SSO session. This has a configured TTL.

If you want to use tokens in your own app to maintain user state, and you want to use a refresh token for that purpose - then you'd ask for the offline_access scope when you build the request to FusionAuth. Then you could store that refresh token on your end and refresh it until it expires to maintain the user state.

[mooreds]

@tomzorz and to add what @robotdan said, this seems like it is veering away from "reporting a bug" toward "asking for support" :) .

The best way for you to get support is to either:

• post on the forum: https://fusionauth.io/community/forum/
• open a support ticket (if you have an account with engineering support): https://account.fusionauth.io/account/support/

More on technical support here: https://fusionauth.io/docs/operate/troubleshooting/technical-support