django-oauth-toolkit icon indicating copy to clipboard operation
django-oauth-toolkit copied to clipboard

Refresh token grant causes integrity error

Open Amertz08 opened this issue 3 years ago • 18 comments

Describe the bug

When duplicate simultaneous requests are sent to the POST /oauth2/token via a refresh grant on the same refresh token we get an IntegrityError

To Reproduce

  • Get a valid refresh token
  • Send duplicate simultaneous requests to POST /oauth2/token
  • Observe integrity error thrown

Expected behavior

I guess I'd expect at least one request to throw a 400 back to the client.

Version

1.4.1

  • [ ] I have tested with the latest published release and it's still a problem.
  • [ ] I have tested with the master branch and it's still a problem.

Additional context

Amertz08 avatar Apr 08 '21 22:04 Amertz08

@Amertz08 Thank you for the bug report! would you be able to provide the detailed error message here? It should save some time in actually fixing the problem. Having spent 10 seconds thinking about this I'm guessing this is some kind of uniqueness constraint failure, but would love a confirmation.

Based on the changelogs for 1.5.0 I don't think it's likely that the latest release fixes things, but if you are able to consistently reproduce it, please give it a shot real quick. But yeah the detailed exception message could be a huge time saver.

rtpg avatar Apr 12 '21 13:04 rtpg

@rtpg Here is the errors in our logs.

2021-03-29T10:58:30.851-05:00 | psycopg2.errors.UniqueViolation: duplicate key value violates unique constraint "access_token_source_refresh_token_id_key"
2021-03-29T10:58:30.851-05:00 | DETAIL: Key (source_refresh_token_id)=(7636288) already exists.
2021-03-29T10:58:30.851-05:00 | The above exception was the direct cause of the following exception:
...
2021-03-29T10:58:30.851-05:00 | django.db.utils.IntegrityError: duplicate key value violates unique constraint "access_token_source_refresh_token_id_key"

We were able to consistently reproduce the bug by doing parallel curl requests via iTerm2.

Amertz08 avatar Apr 12 '21 14:04 Amertz08

Thanks for the confirmation!

To anyone who tries to fix this bug, a good way would likely be to use a get_or_create call instead of a create (after confirming that an idempotent response would make sense of course)

rtpg avatar Apr 12 '21 15:04 rtpg

Hi @Amertz08, I was trying to reproduce your issue but I couldn't.

Steps which I followed:

  • Get a valid refresh_token
  • Sent 2, 4, and 10 concurrent post requests
  • All of them returned with a 200 response status

It will be helpful to provide us with all the POST request options.

panosangelopoulos avatar Apr 17 '21 18:04 panosangelopoulos

I was able to recreate this bug 95% of the time with the following procedure (I'm on a Mac, so you may need to find comparable software to allow the same approach in other OSes):

  • Open iTerm
  • Split the window into two panes
  • Enable Shell -> Broadcast Input -> Broadcast Input to All Panes in Current Tab (this ensures identical token refresh requests are issued at more or less exactly the same time)
  • Issue an oAuth token refresh request using cURL.

Here is the cURL request I made with the sensitive bits redacted:

curl \
    -X POST \
    https://api.mycompany.com/oauth2/token \
    -F grant_type=refresh_token \
    -F client_id={client_id} \
    -F refresh_token={refresh_token}

szicari-farmobile avatar Apr 20 '21 16:04 szicari-farmobile

Thanks for your message @szicari-farmobile but still I cannot reproduce it even with 6 different panes plus using the Broadcast Input to All Panes in Current Tab approach.

curl --request POST \
  --url https://api.mycompany.com/oauth2/token/ \
  --header 'Content-Type: application/x-www-form-urlencoded' \
  --data refresh_token=REFRESH_TOKEN \
  --data grant_type=refresh_token \
  --data client_id=CLIENT_ID \
  --data client_secret=CLIENT_SECRET

panosangelopoulos avatar Apr 20 '21 18:04 panosangelopoulos

@panosangelopoulos Did you mean 6 different panes, because having multiple tabs open but only issuing the request from a single pane would only be a single request, even when broadcasting to all panes.

szicari-farmobile avatar Apr 20 '21 18:04 szicari-farmobile

Yes, @szicari-farmobile I mean panes, sorry for mention tabs. Even with 6 different panes, I cannot reproduce it.

I realized that somehow there is a queue with the requests and I am not getting the result simultaneously from every single pane but in order.

panosangelopoulos avatar Apr 20 '21 18:04 panosangelopoulos

Ah, interesting. So in your case, the only request that doesn't return an HTTP 400 is the first request to have been processed, I would image.

In our case, we've got n number of µWSGI workers, and therefore it is possible for truly simultaneous requests to cause this issue. Is there a way you can test with a similar configuration? Even just running Django w/ a two-worker µWSGI configuration should be sufficient to reproduce.

szicari-farmobile avatar Apr 20 '21 18:04 szicari-farmobile

Not really, all of them are returned correctly with a 200 status code.

Even after running Django with a two-worker configuration as you suggested the issue is not showing up.

panosangelopoulos avatar Apr 21 '21 19:04 panosangelopoulos

Something tells me we're not running the same tests. Only the first request should return HTTP 200 and subsequent requests should return HTTP 400 because the token was invalidated by the first request.

I am issuing simultaneous requests with the same refresh token. Are you trying simultaneous requests with different refresh tokens?

szicari-farmobile avatar Apr 21 '21 20:04 szicari-farmobile

Maybe it would be possible here to write a bash script to set up the conditions here? Somethign where the main loop is

for i in {1..20} do
    curl insert-stuff-here &  # & here to allow for us to fire a bunch of these at once
done

so that everyone is on the same page and has a good way of reproducing this?

rtpg avatar Apr 22 '21 02:04 rtpg

@szicari-farmobile regarding your concern you are right since I had configured the REFRESH_TOKEN_EXPIRE_SECONDS and REFRESH_TOKEN_GRACE_PERIOD_SECONDS to 60, thus you can reuse the same refresh token. After comment out this configuration problem solved and only the first request returns with 200.

@rtpg I was trying to run your suggestion but still doesn't raise any IntegrityError, the first request returns 200 and the upcoming 400 with {"error": "invalid_grant"} as an error message.

panosangelopoulos avatar Apr 23 '21 10:04 panosangelopoulos

The plot thickens, at least for me. I tried the bash loop and got both successful responses back. I also get the exact same new oAuth token back for both requests. Why would this be the case?

for i in {1..2}; do
    curl \
        -X POST \
        https://api.mycompany.com/oauth2/token \
        -F refresh_token=TOKEN \
        -F grant_type=refresh_token \
        -F client_id=CLIENT_ID \
        -F client_secret=CLIENT_SECRET & done

HTTP/2 200
date: Fri, 23 Apr 2021 14:49:13 GMT
content-type: application/json
content-length: 169
server: nginx
cache-control: no-store
pragma: no-cache
vary: Origin
x-frame-options: DENY
x-content-type-options: nosniff
referrer-policy: same-origin
x-content-type-options: nosniff
x-xss-protection: 1; mode=block
strict-transport-security: max-age=31536000; includeSubDomains

{
    "access_token": "ACCESS_TOKEN",
    "expires_in": 36000,
    "token_type": "Bearer",
    "scope": "read write",
    "refresh_token": "REFRESH_TOKEN"
}
HTTP/2 200
date: Fri, 23 Apr 2021 14:49:13 GMT
content-type: application/json
content-length: 169
server: nginx
cache-control: no-store
pragma: no-cache
vary: Origin
x-frame-options: DENY
x-content-type-options: nosniff
referrer-policy: same-origin
x-content-type-options: nosniff
x-xss-protection: 1; mode=block
strict-transport-security: max-age=31536000; includeSubDomains

{
    "access_token": "ACCESS_TOKEN",
    "expires_in": 36000,
    "token_type": "Bearer",
    "scope": "read write",
    "refresh_token": "REFRESH_TOKEN"
}

szicari-farmobile avatar Apr 23 '21 14:04 szicari-farmobile

@szicari-farmobile Did you set REFRESH_TOKEN_GRACE_PERIOD_SECONDS and/or REFRESH_TOKEN_EXPIRE_SECONDS in the above requests ?

panosangelopoulos avatar Apr 23 '21 15:04 panosangelopoulos

Our oAuth configuration is as follows:

OAUTH2_PROVIDER = {
    "SCOPES": {"read": "Read scope", "write": "Write scope"},
    # 86400 is the number of seconds in a day
    # 183 is the rounded up number of days in 6 months
    # (round up on 365/2 .... which would account for leap years too)
    "REFRESH_TOKEN_EXPIRE_SECONDS": 86400 * 183,
}

szicari-farmobile avatar Apr 23 '21 15:04 szicari-farmobile

Then I'm not expecting two responses with 200 status.

Anyone else who can reproduce the bug by using the method which @rtpg mentioned?

panosangelopoulos avatar Apr 27 '21 15:04 panosangelopoulos

I did my research and came back to this topic, the reason that we are getting two valid requests (cc @szicari-farmobile ) when we are sending simultaneous requests is this line https://github.com/jazzband/django-oauth-toolkit/blob/master/oauth2_provider/oauth2_validators.py#L698

The server is authorized to send valid tokens for 0 seconds (if we don't modify the REFRESH_TOKEN_GRACE_PERIOD_SECONDS setting from 0 which is the default) because the requests are coming with some milliseconds time difference both are valid.

I tried to send two requests with the same refresh token with a time diff of a second and only the first was valid.

Is this a bug or a feature? I cannot give an enlightening answer to this question, for this reason, my suggestion is to gather more opinions.

panosangelopoulos avatar Jun 14 '21 08:06 panosangelopoulos