Bubble up refresh exception when we cannot recover #434

rayluo · 2021-11-02T20:24:20Z

This will fix #431.

We won't have an easy way to test this. So, @jiasli please help the code review.

And, if the ConnectionError in Xing Zhuo's report is still observable, you can then pull in this feature branch and test it in rare real environment (by pip install git+https://github.com/AzureAD/microsoft-authentication-library-for-python.git@bubble-up-refresh-exception).

jiasli · 2021-11-03T07:08:13Z

msal/application.py

@@ -1207,7 +1207,9 @@ def _acquire_token_silent_from_cache_and_possibly_refresh_it(
            if (result and "error" not in result) or (not access_token_from_cache):
                return result
        except:  # The exact HTTP exception is transportation-layer dependent
-            logger.exception("Refresh token failed")  # Potential AAD outage?
+            # Typically network error. Potential AAD outage?
+            if not access_token_from_cache:  # It means there is no fall back option


It is possible for access_token_from_cache to be not-None here? It seems L1198 will prevent a not-None access_token_from_cache to reach here.

Line 1198 would be skipped by line 1196. So, this check here is still beneficial.

Ah, I see. Even if AT_AGING refresh fails, access_token_from_cache can serve as a fallback. Thanks for the explanation.

jiasli · 2021-11-03T07:57:22Z

Tested by manually changing expires_on in the token cache to make it expire, then disable the network adopter. I am able to get the expected error.

It fails at /54826b22-38d6-4fb2-bad9-b7b93a3e9c5a/oauth2/v2.0/token:

Full call stack

The command failed with an unexpected error. Here is the traceback:
HTTPSConnectionPool(host='login.microsoftonline.com', port=443): Max retries exceeded with url: /54826b22-38d6-4fb2-bad9-b7b93a3e9c5a/oauth2/v2.0/token (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x00000284219C0040>: Failed to establish a new connection: [Errno 11001] getaddrinfo failed'))
Traceback (most recent call last):
  File "D:\cli\py39\lib\site-packages\urllib3\connection.py", line 169, in _new_conn
    conn = connection.create_connection(
  File "D:\cli\py39\lib\site-packages\urllib3\util\connection.py", line 73, in create_connection
    for res in socket.getaddrinfo(host, port, family, socket.SOCK_STREAM):
  File "C:\Users\jiasli\AppData\Local\Programs\Python\Python39\lib\socket.py", line 953, in getaddrinfo
    for res in _socket.getaddrinfo(host, port, family, type, proto, flags):
socket.gaierror: [Errno 11001] getaddrinfo failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "D:\cli\py39\lib\site-packages\urllib3\connectionpool.py", line 699, in urlopen
    httplib_response = self._make_request(
  File "D:\cli\py39\lib\site-packages\urllib3\connectionpool.py", line 382, in _make_request
    self._validate_conn(conn)
  File "D:\cli\py39\lib\site-packages\urllib3\connectionpool.py", line 1010, in _validate_conn
    conn.connect()
  File "D:\cli\py39\lib\site-packages\urllib3\connection.py", line 353, in connect
    conn = self._new_conn()
  File "D:\cli\py39\lib\site-packages\urllib3\connection.py", line 181, in _new_conn
    raise NewConnectionError(
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPSConnection object at 0x00000284219C0040>: Failed to establish a new connection: [Errno 11001] getaddrinfo failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "D:\cli\py39\lib\site-packages\requests\adapters.py", line 439, in send
    resp = conn.urlopen(
  File "D:\cli\py39\lib\site-packages\urllib3\connectionpool.py", line 783, in urlopen
    return self.urlopen(
  File "D:\cli\py39\lib\site-packages\urllib3\connectionpool.py", line 755, in urlopen
    retries = retries.increment(
  File "D:\cli\py39\lib\site-packages\urllib3\util\retry.py", line 574, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='login.microsoftonline.com', port=443): Max retries exceeded with url: /54826b22-38d6-4fb2-bad9-b7b93a3e9c5a/oauth2/v2.0/token (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x00000284219C0040>: Failed to establish a new connection: [Errno 11001] getaddrinfo failed'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "D:\cli\py39\lib\site-packages\knack\cli.py", line 231, in invoke
    cmd_result = self.invocation.execute(args)
  File "d:\cli\azure-cli\src\azure-cli-core\azure\cli\core\commands\__init__.py", line 657, in execute
    raise ex
  File "d:\cli\azure-cli\src\azure-cli-core\azure\cli\core\commands\__init__.py", line 720, in _run_jobs_serially
    results.append(self._run_job(expanded_arg, cmd_copy))
  File "d:\cli\azure-cli\src\azure-cli-core\azure\cli\core\commands\__init__.py", line 691, in _run_job
    result = cmd_copy(params)
  File "d:\cli\azure-cli\src\azure-cli-core\azure\cli\core\commands\__init__.py", line 328, in __call__
    return self.handler(*args, **kwargs)
  File "d:\cli\azure-cli\src\azure-cli-core\azure\cli\core\commands\command_operation.py", line 121, in handler
    return op(**command_args)
  File "d:\cli\azure-cli\src\azure-cli\azure\cli\command_modules\resource\custom.py", line 1298, in list_resource_groups
    return list(groups)
  File "D:\cli\py39\lib\site-packages\azure\core\paging.py", line 129, in __next__
    return next(self._page_iterator)
  File "D:\cli\py39\lib\site-packages\azure\core\paging.py", line 76, in __next__
    self._response = self._get_next(self.continuation_token)
  File "D:\cli\py39\lib\site-packages\azure\mgmt\resource\resources\v2021_04_01\operations\_resource_groups_operations.py", line 599, in get_next
    pipeline_response = self._client._pipeline.run(request, stream=False, **kwargs)
  File "D:\cli\py39\lib\site-packages\azure\core\pipeline\_base.py", line 211, in run
    return first_node.send(pipeline_request)  # type: ignore
  File "D:\cli\py39\lib\site-packages\azure\core\pipeline\_base.py", line 71, in send
    response = self.next.send(request)
  File "D:\cli\py39\lib\site-packages\azure\core\pipeline\_base.py", line 71, in send
    response = self.next.send(request)
  File "D:\cli\py39\lib\site-packages\azure\core\pipeline\_base.py", line 71, in send
    response = self.next.send(request)
  [Previous line repeated 2 more times]
  File "D:\cli\py39\lib\site-packages\azure\mgmt\core\policies\_base.py", line 47, in send
    response = self.next.send(request)
  File "D:\cli\py39\lib\site-packages\azure\core\pipeline\policies\_redirect.py", line 158, in send
    response = self.next.send(request)
  File "D:\cli\py39\lib\site-packages\azure\core\pipeline\policies\_retry.py", line 445, in send
    response = self.next.send(request)
  File "D:\cli\py39\lib\site-packages\azure\core\pipeline\policies\_authentication.py", line 117, in send
    self.on_request(request)
  File "D:\cli\py39\lib\site-packages\azure\core\pipeline\policies\_authentication.py", line 94, in on_request
    self._token = self._credential.get_token(*self._scopes)
  File "d:\cli\azure-cli\src\azure-cli-core\azure\cli\core\auth\credential_adaptor.py", line 60, in get_token
    token, _ = self._get_token(scopes, **kwargs)
  File "d:\cli\azure-cli\src\azure-cli-core\azure\cli\core\auth\credential_adaptor.py", line 38, in _get_token
    token = self._credential.get_token(*scopes, **kwargs)
  File "d:\cli\azure-cli\src\azure-cli-core\azure\cli\core\auth\msal_authentication.py", line 57, in get_token
    result = self.acquire_token_silent_with_error(list(scopes), self._account, **kwargs)
  File "d:\cli\microsoft-authentication-library-for-python\msal\application.py", line 1118, in acquire_token_silent_with_error
    result = self._acquire_token_silent_from_cache_and_possibly_refresh_it(
  File "d:\cli\microsoft-authentication-library-for-python\msal\application.py", line 1203, in _acquire_token_silent_from_cache_and_possibly_refresh_it
    result = _clean_up(self._acquire_token_silent_by_finding_rt_belongs_to_me_or_my_family(
  File "d:\cli\microsoft-authentication-library-for-python\msal\application.py", line 1241, in _acquire_token_silent_by_finding_rt_belongs_to_me_or_my_family
    last_resp = at = self._acquire_token_silent_by_finding_specific_refresh_token(
  File "d:\cli\microsoft-authentication-library-for-python\msal\application.py", line 1288, in _acquire_token_silent_by_finding_specific_refresh_token
    response = client.obtain_token_by_refresh_token(
  File "d:\cli\microsoft-authentication-library-for-python\msal\oauth2cli\oauth2.py", line 831, in obtain_token_by_refresh_token
    resp = super(Client, self).obtain_token_by_refresh_token(
  File "d:\cli\microsoft-authentication-library-for-python\msal\oauth2cli\oauth2.py", line 263, in obtain_token_by_refresh_token
    return self._obtain_token("refresh_token", data=data, **kwargs)
  File "d:\cli\microsoft-authentication-library-for-python\msal\oauth2cli\oidc.py", line 115, in _obtain_token
    ret = super(Client, self)._obtain_token(grant_type, *args, **kwargs)
  File "d:\cli\microsoft-authentication-library-for-python\msal\oauth2cli\oauth2.py", line 772, in _obtain_token
    resp = super(Client, self)._obtain_token(
  File "d:\cli\microsoft-authentication-library-for-python\msal\oauth2cli\oauth2.py", line 235, in _obtain_token
    resp = (post or self._http_client.post)(
  File "d:\cli\microsoft-authentication-library-for-python\msal\individual_cache.py", line 269, in wrapper
    value = function(*args, **kwargs)
  File "d:\cli\microsoft-authentication-library-for-python\msal\individual_cache.py", line 269, in wrapper
    value = function(*args, **kwargs)
  File "D:\cli\py39\lib\site-packages\requests\sessions.py", line 590, in post
    return self.request('POST', url, data=data, json=json, **kwargs)
  File "D:\cli\py39\lib\site-packages\requests\sessions.py", line 542, in request
    resp = self.send(prep, **send_kwargs)
  File "D:\cli\py39\lib\site-packages\requests\sessions.py", line 655, in send
    r = adapter.send(request, **kwargs)
  File "D:\cli\py39\lib\site-packages\requests\adapters.py", line 516, in send
    raise ConnectionError(e, request=request)

requests.exceptions.ConnectionError: HTTPSConnectionPool(host='login.microsoftonline.com', port=443): Max retries exceeded with url: /54826b22-38d6-4fb2-bad9-b7b93a3e9c5a/oauth2/v2.0/token (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x00000284219C0040>: Failed to establish a new connection: [Errno 11001] getaddrinfo failed'))

Without the change it fails at /common/discovery/instance:

Full call stack

The command failed with an unexpected error. Here is the traceback:
HTTPSConnectionPool(host='login.microsoftonline.com', port=443): Max retries exceeded with url: /common/discovery/instance?api-version=1.1&authorization_endpoint=https://login.microsoftonline.com/common/oauth2/authorize (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x000002B89FCC0490>: Failed to establish a new connection: [Errno 11001] getaddrinfo failed'))
Traceback (most recent call last):
  File "D:\cli\py39\lib\site-packages\urllib3\connection.py", line 169, in _new_conn
    conn = connection.create_connection(
  File "D:\cli\py39\lib\site-packages\urllib3\util\connection.py", line 73, in create_connection
    for res in socket.getaddrinfo(host, port, family, socket.SOCK_STREAM):
  File "C:\Users\jiasli\AppData\Local\Programs\Python\Python39\lib\socket.py", line 953, in getaddrinfo
    for res in _socket.getaddrinfo(host, port, family, type, proto, flags):
socket.gaierror: [Errno 11001] getaddrinfo failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "D:\cli\py39\lib\site-packages\urllib3\connectionpool.py", line 699, in urlopen
    httplib_response = self._make_request(
  File "D:\cli\py39\lib\site-packages\urllib3\connectionpool.py", line 382, in _make_request
    self._validate_conn(conn)
  File "D:\cli\py39\lib\site-packages\urllib3\connectionpool.py", line 1010, in _validate_conn
    conn.connect()
  File "D:\cli\py39\lib\site-packages\urllib3\connection.py", line 353, in connect
    conn = self._new_conn()
  File "D:\cli\py39\lib\site-packages\urllib3\connection.py", line 181, in _new_conn
    raise NewConnectionError(
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPSConnection object at 0x000002B89FCC0490>: Failed to establish a new connection: [Errno 11001] getaddrinfo failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "D:\cli\py39\lib\site-packages\requests\adapters.py", line 439, in send
    resp = conn.urlopen(
  File "D:\cli\py39\lib\site-packages\urllib3\connectionpool.py", line 783, in urlopen
    return self.urlopen(
  File "D:\cli\py39\lib\site-packages\urllib3\connectionpool.py", line 755, in urlopen
    retries = retries.increment(
  File "D:\cli\py39\lib\site-packages\urllib3\util\retry.py", line 574, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='login.microsoftonline.com', port=443): Max retries exceeded with url: /common/discovery/instance?api-version=1.1&authorization_endpoint=https://login.microsoftonline.com/common/oauth2/authorize (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x000002B89FCC0490>: Failed to establish a new connection: [Errno 11001] getaddrinfo failed'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "D:\cli\py39\lib\site-packages\knack\cli.py", line 231, in invoke
    cmd_result = self.invocation.execute(args)
  File "d:\cli\azure-cli\src\azure-cli-core\azure\cli\core\commands\__init__.py", line 657, in execute
    raise ex
  File "d:\cli\azure-cli\src\azure-cli-core\azure\cli\core\commands\__init__.py", line 720, in _run_jobs_serially
    results.append(self._run_job(expanded_arg, cmd_copy))
  File "d:\cli\azure-cli\src\azure-cli-core\azure\cli\core\commands\__init__.py", line 691, in _run_job
    result = cmd_copy(params)
  File "d:\cli\azure-cli\src\azure-cli-core\azure\cli\core\commands\__init__.py", line 328, in __call__
    return self.handler(*args, **kwargs)
  File "d:\cli\azure-cli\src\azure-cli-core\azure\cli\core\commands\command_operation.py", line 121, in handler
    return op(**command_args)
  File "d:\cli\azure-cli\src\azure-cli\azure\cli\command_modules\resource\custom.py", line 1298, in list_resource_groups
    return list(groups)
  File "D:\cli\py39\lib\site-packages\azure\core\paging.py", line 129, in __next__
    return next(self._page_iterator)
  File "D:\cli\py39\lib\site-packages\azure\core\paging.py", line 76, in __next__
    self._response = self._get_next(self.continuation_token)
  File "D:\cli\py39\lib\site-packages\azure\mgmt\resource\resources\v2021_04_01\operations\_resource_groups_operations.py", line 599, in get_next
    pipeline_response = self._client._pipeline.run(request, stream=False, **kwargs)
  File "D:\cli\py39\lib\site-packages\azure\core\pipeline\_base.py", line 211, in run
    return first_node.send(pipeline_request)  # type: ignore
  File "D:\cli\py39\lib\site-packages\azure\core\pipeline\_base.py", line 71, in send
    response = self.next.send(request)
  File "D:\cli\py39\lib\site-packages\azure\core\pipeline\_base.py", line 71, in send
    response = self.next.send(request)
  File "D:\cli\py39\lib\site-packages\azure\core\pipeline\_base.py", line 71, in send
    response = self.next.send(request)
  [Previous line repeated 2 more times]
  File "D:\cli\py39\lib\site-packages\azure\mgmt\core\policies\_base.py", line 47, in send
    response = self.next.send(request)
  File "D:\cli\py39\lib\site-packages\azure\core\pipeline\policies\_redirect.py", line 158, in send
    response = self.next.send(request)
  File "D:\cli\py39\lib\site-packages\azure\core\pipeline\policies\_retry.py", line 445, in send
    response = self.next.send(request)
  File "D:\cli\py39\lib\site-packages\azure\core\pipeline\policies\_authentication.py", line 117, in send
    self.on_request(request)
  File "D:\cli\py39\lib\site-packages\azure\core\pipeline\policies\_authentication.py", line 94, in on_request
    self._token = self._credential.get_token(*self._scopes)
  File "d:\cli\azure-cli\src\azure-cli-core\azure\cli\core\auth\credential_adaptor.py", line 60, in get_token
    token, _ = self._get_token(scopes, **kwargs)
  File "d:\cli\azure-cli\src\azure-cli-core\azure\cli\core\auth\credential_adaptor.py", line 38, in _get_token
    token = self._credential.get_token(*scopes, **kwargs)
  File "d:\cli\azure-cli\src\azure-cli-core\azure\cli\core\auth\msal_authentication.py", line 57, in get_token
    result = self.acquire_token_silent_with_error(list(scopes), self._account, **kwargs)
  File "d:\cli\microsoft-authentication-library-for-python\msal\application.py", line 1126, in acquire_token_silent_with_error
    for alias in self._get_authority_aliases(self.authority.instance):
  File "d:\cli\microsoft-authentication-library-for-python\msal\application.py", line 978, in _get_authority_aliases
    resp = self.http_client.get(
  File "d:\cli\microsoft-authentication-library-for-python\msal\individual_cache.py", line 269, in wrapper
    value = function(*args, **kwargs)
  File "D:\cli\py39\lib\site-packages\requests\sessions.py", line 555, in get
    return self.request('GET', url, **kwargs)
  File "D:\cli\py39\lib\site-packages\requests\sessions.py", line 542, in request
    resp = self.send(prep, **send_kwargs)
  File "D:\cli\py39\lib\site-packages\requests\sessions.py", line 655, in send
    r = adapter.send(request, **kwargs)
  File "D:\cli\py39\lib\site-packages\requests\adapters.py", line 516, in send
    raise ConnectionError(e, request=request)

requests.exceptions.ConnectionError: HTTPSConnectionPool(host='login.microsoftonline.com', port=443): Max retries exceeded with url: /common/discovery/instance?api-version=1.1&authorization_endpoint=https://login.microsoftonline.com/common/oauth2/authorize (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x000002B89FCC0490>: Failed to establish a new connection: [Errno 11001] getaddrinfo failed'))

If the tenant discovery succeeds, it will fail in CLI code as shown in the issue description.

Bubble up refresh exception when we cannot recover

640d88a

jiasli reviewed Nov 3, 2021

View reviewed changes

jiasli approved these changes Nov 3, 2021

View reviewed changes

rayluo merged commit 429f121 into dev Nov 3, 2021

rayluo deleted the bubble-up-refresh-exception branch November 3, 2021 08:07

jiasli mentioned this pull request Dec 31, 2021

az keyvault key create fails: Session.request() got an unexpected keyword argument 'tenant_id' Azure/azure-cli#20856

Closed

rayluo mentioned this pull request Feb 8, 2022

MSAL Python 1.17.0 #457

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Bubble up refresh exception when we cannot recover #434

Bubble up refresh exception when we cannot recover #434

rayluo commented Nov 2, 2021 •

edited

Loading

jiasli Nov 3, 2021

rayluo Nov 3, 2021

jiasli Nov 3, 2021

jiasli commented Nov 3, 2021 •

edited

Loading

Bubble up refresh exception when we cannot recover #434

Bubble up refresh exception when we cannot recover #434

Conversation

rayluo commented Nov 2, 2021 • edited Loading

jiasli Nov 3, 2021

Choose a reason for hiding this comment

rayluo Nov 3, 2021

Choose a reason for hiding this comment

jiasli Nov 3, 2021

Choose a reason for hiding this comment

jiasli commented Nov 3, 2021 • edited Loading

rayluo commented Nov 2, 2021 •

edited

Loading

jiasli commented Nov 3, 2021 •

edited

Loading