From 1efd7a3230795285c641de3d5675c906dbf3623d Mon Sep 17 00:00:00 2001 From: Robert Knight Date: Mon, 3 Jun 2024 10:20:24 +0100 Subject: [PATCH] Add logging to detect concurrent token refreshes for most OAuth APIs As a step towards preventing concurrent refreshes for all OAuth APIs, try to acquire the advisory lock on all OAuth token refreshes performed by `OAuthHTTPService`, but only prevent concurrent refreshes when the caller opts-in, which currently means only Canvas Studio. Otherwise we just write a log entry so we can count how often concurrent refreshes occur. --- lms/services/oauth_http.py | 21 ++++++++++++-------- tests/unit/lms/services/oauth_http_test.py | 23 +++++++++++++++++----- 2 files changed, 31 insertions(+), 13 deletions(-) diff --git a/lms/services/oauth_http.py b/lms/services/oauth_http.py index 6825252ceb..b62544949b 100644 --- a/lms/services/oauth_http.py +++ b/lms/services/oauth_http.py @@ -1,3 +1,4 @@ +import logging from datetime import datetime, timedelta from marshmallow import fields @@ -13,6 +14,8 @@ from lms.validation import RequestsResponseSchema from lms.validation.authentication import OAuthTokenResponseSchema +LOG = logging.getLogger(__name__) + class _OAuthAccessTokenErrorResponseSchema(RequestsResponseSchema): """Schema for parsing OAuth 2 access token error response bodies.""" @@ -117,14 +120,16 @@ def refresh_access_token( ): return old_token.access_token - if prevent_concurrent_refreshes: - # Prevent concurrent refresh attempts. If acquiring the lock fails, - # the client should wait briefly and try again, at which point it - # should find the refreshed token already available and skip the - # refresh. - try: - self._oauth2_token_service.try_lock_for_refresh(self.service) - except CouldNotAcquireLock as exc: + # Check for concurrent refresh attempts. + try: + self._oauth2_token_service.try_lock_for_refresh(self.service) + except CouldNotAcquireLock as exc: + LOG.debug('Concurrent OAuth token refresh with token URL "%s"', token_url) + if prevent_concurrent_refreshes: + # Prevent concurrent refresh attempts. If acquiring the lock + # fails, the client should wait briefly and try again, at which + # point it should find the refreshed token already available and + # skip the refresh. raise ConcurrentTokenRefreshError() from exc try: diff --git a/tests/unit/lms/services/oauth_http_test.py b/tests/unit/lms/services/oauth_http_test.py index d32aa01192..b2c6ce241f 100644 --- a/tests/unit/lms/services/oauth_http_test.py +++ b/tests/unit/lms/services/oauth_http_test.py @@ -241,12 +241,25 @@ def test_refresh_access_token_acquires_refresh_lock( sentinel.auth, prevent_concurrent_refreshes=prevent_concurrent_refreshes, ) - if prevent_concurrent_refreshes: - oauth2_token_service.try_lock_for_refresh.assert_called_once() - else: - oauth2_token_service.try_lock_for_refresh.assert_not_called() - def test_refresh_access_token_raises_ConcurrentTokenRefreshError_on_concurrent_refresh( + # We acquire the lock whether or not concurrent refreshes are allowed, + # but only raise if not allowed. + oauth2_token_service.try_lock_for_refresh.assert_called_once() + + def test_refresh_access_does_not_raise_if_concurrent_refreshes_allowed( + self, + svc, + oauth2_token_service, + ): + oauth2_token_service.try_lock_for_refresh.side_effect = CouldNotAcquireLock() + svc.refresh_access_token( + sentinel.token_url, + sentinel.redirect_uri, + sentinel.auth, + prevent_concurrent_refreshes=False, + ) + + def test_refresh_access_token_raises_if_concurrent_refreshes_prevented( self, svc, oauth2_token_service,