exchangelib: Expired OAuth token refreshing endless loop

OAuth token refresh is not working properly. It keeps looping with 100% CPU load and creates million lines of debug output in a short time. It seems to get new session number but access_token itself stays as same and therefore keeps trying to refresh it again and again.

To reproduce you need to have an session which takes longer than OAuth expire time lasts (1 hour, e.g. big mailbox export).

MS documentation of the token refresh: https://docs.microsoft.com/en-us/azure/active-directory/develop/v2-oauth2-auth-code-flow#refresh-the-access-token

DEBUG LOG:

<..returning from the job when token was not expired yet..>
INFO:exchangelib.fields:Found naive datetime 2021-01-25 10:53:31 on field last_modified_time. Assuming timezone Europe/Helsinki
DEBUG:exchangelib.services.common:Processing chunk 146 containing 30 items
DEBUG:exchangelib.services.common:Calling service GetItem
DEBUG:exchangelib.services.common:Trying API version Exchange2016
DEBUG:exchangelib.protocol:Server outlook.office365.com: Got session immediately
DEBUG:exchangelib.protocol:Server outlook.office365.com: Got session 87246
DEBUG:exchangelib.util:Session 87246 thread 139712341780288: retry 0 timeout 120 POST'ing to https://outlook.office365.com/EWS/Exchange.asmx after 10s wait
DEBUG:requests_oauthlib.oauth2_session:Invoking 0 protected resource request hooks.
DEBUG:requests_oauthlib.oauth2_session:Adding token {'token_type': 'Bearer', 'expires_in': 3599, 'ext_expires_in': 3599, 'access_token': 'eyJ0e <REMOVED> N9uGA', 'expires_at': 1653914631
.8988214} to request.
DEBUG:exchangelib.util:Session 87246 thread 139712341780288: OAuth token expired; refreshing
DEBUG:exchangelib.util:Retry: 0
Waited: 10
Timeout: 120
Session: 87246
Thread: 139712341780288
Auth type: <requests_oauthlib.oauth2_auth.OAuth2 object at 0x7f114de7d670>
URL: https://outlook.office365.com/EWS/Exchange.asmx
HTTP adapter: <requests.adapters.HTTPAdapter object at 0x7f114de7d580>
Allow redirects: False
Streaming: False
Response time: 0.0001604610006324947
Status code: 401
Request headers: {'X-AnchorMailbox': 'email@example.<REMOVED>'}
Response headers: {'TokenExpiredError': TokenExpiredError('(token_expired) ')}
DEBUG:exchangelib.util.xml:Request XML: b'<?xml version=\'1.0\' encoding=\'utf-8\'?>\n<s:Envelope <REMOVED> </s:Envelope>'
Response XML: b''
DEBUG:exchangelib.protocol:Server outlook.office365.com: Renewing session 87246
DEBUG:exchangelib.protocol:Server outlook.office365.com: Created session 17831
DEBUG:exchangelib.util:Session 17831 thread 139712341780288: retry 0 timeout 120 POST'ing to https://outlook.office365.com/EWS/Exchange.asmx after 10s wait
DEBUG:requests_oauthlib.oauth2_session:Invoking 0 protected resource request hooks.
DEBUG:requests_oauthlib.oauth2_session:Adding token {'token_type': 'Bearer', 'expires_in': 3599, 'ext_expires_in': 3599, 'access_token': 'eyJ0e <REMOVED> N9uGA', 'expires_at': 1653914631
.8988214} to request.
DEBUG:exchangelib.util:Session 17831 thread 139712341780288: OAuth token expired; refreshing
DEBUG:exchangelib.util:Retry: 0
Waited: 10
Timeout: 120
Session: 17831
Thread: 139712341780288
Auth type: <requests_oauthlib.oauth2_auth.OAuth2 object at 0x7f114de7d670>
URL: https://outlook.office365.com/EWS/Exchange.asmx
HTTP adapter: <requests.adapters.HTTPAdapter object at 0x7f114de7d580>
Allow redirects: False
Streaming: False
Response time: 0.0004302969991840655
Status code: 401
Request headers: {'X-AnchorMailbox': 'email@example.<REMOVED>'}
Response headers: {'TokenExpiredError': TokenExpiredError('(token_expired) ')}
DEBUG:exchangelib.util.xml:Request XML: b'<?xml version=\'1.0\' encoding=\'utf-8\'?>\n<s:Envelope <REMOVED></s:Envelope>'
Response XML: b''
DEBUG:exchangelib.protocol:Server outlook.office365.com: Renewing session 17831
DEBUG:exchangelib.protocol:Server outlook.office365.com: Created session 43264
DEBUG:exchangelib.util:Session 43264 thread 139712341780288: retry 0 timeout 120 POST'ing to https://outlook.office365.com/EWS/Exchange.asmx after 10s wait
DEBUG:requests_oauthlib.oauth2_session:Invoking 0 protected resource request hooks.
DEBUG:requests_oauthlib.oauth2_session:Adding token {'token_type': 'Bearer', 'expires_in': 3599, 'ext_expires_in': 3599, 'access_token': 'eyJ0 <REMOVED> N9uGA', 'expires_at': 1653914631
.8988214} to request.
DEBUG:exchangelib.util:Session 43264 thread 139712341780288: OAuth token expired; refreshing
DEBUG:exchangelib.util:Retry: 0
Waited: 10
Timeout: 120
Session: 43264
Thread: 139712341780288
Auth type: <requests_oauthlib.oauth2_auth.OAuth2 object at 0x7f114de7d670>
URL: https://outlook.office365.com/EWS/Exchange.asmx
HTTP adapter: <requests.adapters.HTTPAdapter object at 0x7f114de7d580>
Allow redirects: False
Streaming: False

VERSIONS: Python 3.9.10 exchangelib 4.7.3

About this issue

  • Original URL
  • State: closed
  • Created 2 years ago
  • Reactions: 1
  • Comments: 18 (7 by maintainers)

Commits related to this issue

Most upvoted comments

It turns out you need to actually build the new package before uploading to PyPI. Otherwise you’re just re-uploading 4.7.5 😃 It’s there now.

It’s out now.

@cmin764 and @Tepe

It seems the upstream issue is not getting any attention. I came up with a slightly different patch in https://github.com/ecederstrand/exchangelib/pull/1104/files. I’m unable to properly test because I don’t have access to a setup that uses OAuth2AuthorizationCodeCredentials. Can you give it a spin before I merge the PR?

Sure, I’ll test it with that patched util.py and report back how it goes.

@cmin764 and @Tepe

It seems the upstream issue is not getting any attention. I came up with a slightly different patch in https://github.com/ecederstrand/exchangelib/pull/1104. I’m unable to properly test because I don’t have access to a setup that uses OAuth2AuthorizationCodeCredentials. Can you give it a spin before I merge the PR?

Thanks for the detailed write-up! Let’s wait to see if the requests-oauthlib issue gets any responses. Otherwise, we can have a look at patches to exchangelib.