Describe the bug
AzureCliCredential fails intermittently on devops pipelines with CredentialUnavailableError because of timed out after 10 seconds, and resulting in the build failures.
'['cmd', '/c', 'az account get-access-token --output json --resource https://management.azure.com']' timed out after 10 seconds
To Reproduce
Intermittent CredentialUnavailableError in DevOps pipelines.
Expected behavior
Some random Az CLI tasks should not fail with an intermittent CredentialUnavailableError
Environment summary
[command]C:\Windows\system32\cmd.exe /D /S /C ""C:\Program Files (x86)\Microsoft SDKs\Azure\CLI2\wbin\az.cmd" --version"
azure-cli 2.30.0
Please let us know how we are doing: https://aka.ms/azureclihats
and let us know if you're interested in trying out our newest features: https://aka.ms/CLIUXstudy
core 2.30.0
telemetry 1.0.6
Extensions:
azure-devops 0.22.0
Additional context
Logs from build agent:
2021-11-11T07:56:03.1173758Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2021-11-11T07:56:03.1174605Z self = <azure.identity._credentials.chained.ChainedTokenCredential object at 0x0000023C52710BA8>
2021-11-11T07:56:03.1175442Z scopes = ('https://management.azure.com/.default',), kwargs = {}
2021-11-11T07:56:03.1176625Z history = [(<azure.identity._credentials.azure_cli.AzureCliCredential object at 0x0000023C5275C550>, 'Failed to invoke the Azure...veBrowserCredential object at 0x0000023C52732828>, 'Timed out after waiting 300 seconds for the user to authenticate')]
2021-11-11T07:56:03.1177864Z credential = <azure.identity._credentials.browser.InteractiveBrowserCredential object at 0x0000023C52732828>
2021-11-11T07:56:03.1179086Z attempts = '\nAttempted credentials:\n\tAzureCliCredential: Failed to invoke the Azure CLI\n\tInteractiveBrowserCredential: Timed out after waiting 300 seconds for the user to authenticate'
2021-11-11T07:56:03.1180830Z message = 'ChainedTokenCredential failed to retrieve a token from the included credentials.\nAttempted credentials:\n\tAzureCliC...er to the troubleshooting guidelines here at https://aka.ms/azsdk/python/identity/defaultazurecredential/troubleshoot.'
2021-11-11T07:56:03.1426711Z ------------------------------ Captured log call ------------------------------
2021-11-11T07:56:03.1427773Z �[33mWARNING �[0m azure.identity._internal.decorators:decorators.py:41 AzureCliCredential.get_token failed: Failed to invoke the Azure CLI
2021-11-11T07:56:03.1428786Z Traceback (most recent call last):
2021-11-11T07:56:03.1429550Z File "c:\miniconda\envs\51333213\lib\subprocess.py", line 425, in run
2021-11-11T07:56:03.1430721Z stdout, stderr = process.communicate(input, timeout=timeout)
2021-11-11T07:56:03.1431643Z File "c:\miniconda\envs\51333213\lib\subprocess.py", line 863, in communicate
2021-11-11T07:56:03.1432446Z stdout, stderr = self._communicate(input, endtime, timeout)
2021-11-11T07:56:03.1433238Z File "c:\miniconda\envs\51333213\lib\subprocess.py", line 1114, in _communicate
2021-11-11T07:56:03.1434006Z raise TimeoutExpired(self.args, orig_timeout)
2021-11-11T07:56:03.1435013Z subprocess.TimeoutExpired: Command '['cmd', '/c', 'az account get-access-token --output json --resource https://management.azure.com']' timed out after 10 seconds
2021-11-11T07:56:03.1436106Z During handling of the above exception, another exception occurred:
2021-11-11T07:56:03.1436870Z Traceback (most recent call last):
2021-11-11T07:56:03.1437705Z File "c:\miniconda\envs\51333213\lib\site-packages\azure\identity_credentials\azure_cli.py", line 141, in _run_command
2021-11-11T07:56:03.1438575Z return subprocess.check_output(args, **kwargs)
2021-11-11T07:56:03.1439366Z File "c:\miniconda\envs\51333213\lib\subprocess.py", line 356, in check_output
2021-11-11T07:56:03.1440070Z **kwargs).stdout
2021-11-11T07:56:03.1440895Z File "c:\miniconda\envs\51333213\lib\subprocess.py", line 430, in run
2021-11-11T07:56:03.1441595Z stderr=stderr)
2021-11-11T07:56:03.1442515Z subprocess.TimeoutExpired: Command '['cmd', '/c', 'az account get-access-token --output json --resource https://management.azure.com']' timed out after 10 seconds
2021-11-11T07:56:03.1443608Z The above exception was the direct cause of the following exception:
2021-11-11T07:56:03.1444363Z Traceback (most recent call last):
2021-11-11T07:56:03.1445190Z File "c:\miniconda\envs\51333213\lib\site-packages\azure\identity_internal\decorators.py", line 30, in wrapper
2021-11-11T07:56:03.1445991Z token = fn(*args, **kwargs)
2021-11-11T07:56:03.1446820Z File "c:\miniconda\envs\51333213\lib\site-packages\azure\identity_credentials\azure_cli.py", line 73, in get_token
2021-11-11T07:56:03.1447630Z output = _run_command(command)
2021-11-11T07:56:03.1448621Z File "c:\miniconda\envs\51333213\lib\site-packages\azure\identity_credentials\azure_cli.py", line 162, in _run_command
2021-11-11T07:56:03.1449429Z six.raise_from(error, ex)
2021-11-11T07:56:03.1450057Z File "", line 3, in raise_from
2021-11-11T07:56:03.1450965Z azure.identity._exceptions.CredentialUnavailableError: Failed to invoke the Azure CLI
2021-11-11T07:56:03.1452689Z �[32mINFO �[0m azure.core.pipeline.policies.http_logging_policy:_universal.py:475 Request URL: 'https://login.microsoftonline.com/organizations/v2.0/.well-known/openid-configuration'/nRequest method: 'GET'/nRequest headers:/n 'User-Agent': 'azsdk-python-identity/1.7.1 Python/3.6.8 (Windows-10-10.0.17763-SP0) VSTS_8b119ea1-2e2a-4839-8db7-8c9e8d50f6fa_build_13339_0'/nNo body was attached to the request
2021-11-11T07:56:03.1454520Z �[35mDEBUG �[0m urllib3.connectionpool:connectionpool.py:975 Starting new HTTPS connection (1): login.microsoftonline.com:443
2021-11-11T07:56:03.1456088Z �[35mDEBUG �[0m urllib3.connectionpool:connectionpool.py:461 https://login.microsoftonline.com:443 "GET /organizations/v2.0/.well-known/openid-configuration HTTP/1.1" 200 1589
2021-11-11T07:56:03.1458835Z �[32mINFO �[0m azure.core.pipeline.policies.http_logging_policy:_universal.py:503 Response status: 200/nResponse headers:/n 'Cache-Control': 'max-age=86400, private'/n 'Content-Type': 'application/json; charset=utf-8'/n 'Strict-Transport-Security': 'REDACTED'/n 'X-Content-Type-Options': 'REDACTED'/n 'Access-Control-Allow-Origin': 'REDACTED'/n 'Access-Control-Allow-Methods': 'REDACTED'/n 'P3P': 'REDACTED'/n 'x-ms-request-id': 'cef116c9-1073-4ad3-861c-b643b8245d00'/n 'x-ms-ests-server': 'REDACTED'/n 'Set-Cookie': 'REDACTED'/n 'Date': 'Thu, 11 Nov 2021 07:43:14 GMT'/n 'Content-Leng
Describe the bug
AzureCliCredential fails intermittently on devops pipelines with CredentialUnavailableError because of timed out after 10 seconds, and resulting in the build failures.
'['cmd', '/c', 'az account get-access-token --output json --resource https://management.azure.com']' timed out after 10 seconds
To Reproduce
Intermittent CredentialUnavailableError in DevOps pipelines.
Expected behavior
Some random Az CLI tasks should not fail with an intermittent CredentialUnavailableError
Environment summary
[command]C:\Windows\system32\cmd.exe /D /S /C ""C:\Program Files (x86)\Microsoft SDKs\Azure\CLI2\wbin\az.cmd" --version"
azure-cli 2.30.0
Please let us know how we are doing: https://aka.ms/azureclihats
and let us know if you're interested in trying out our newest features: https://aka.ms/CLIUXstudy
core 2.30.0
telemetry 1.0.6
Extensions:
azure-devops 0.22.0
Additional context
Logs from build agent:
2021-11-11T07:56:03.1173758Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2021-11-11T07:56:03.1174605Z self = <azure.identity._credentials.chained.ChainedTokenCredential object at 0x0000023C52710BA8>
2021-11-11T07:56:03.1175442Z scopes = ('https://management.azure.com/.default',), kwargs = {}
2021-11-11T07:56:03.1176625Z history = [(<azure.identity._credentials.azure_cli.AzureCliCredential object at 0x0000023C5275C550>, 'Failed to invoke the Azure...veBrowserCredential object at 0x0000023C52732828>, 'Timed out after waiting 300 seconds for the user to authenticate')]
2021-11-11T07:56:03.1177864Z credential = <azure.identity._credentials.browser.InteractiveBrowserCredential object at 0x0000023C52732828>
2021-11-11T07:56:03.1179086Z attempts = '\nAttempted credentials:\n\tAzureCliCredential: Failed to invoke the Azure CLI\n\tInteractiveBrowserCredential: Timed out after waiting 300 seconds for the user to authenticate'
2021-11-11T07:56:03.1180830Z message = 'ChainedTokenCredential failed to retrieve a token from the included credentials.\nAttempted credentials:\n\tAzureCliC...er to the troubleshooting guidelines here at https://aka.ms/azsdk/python/identity/defaultazurecredential/troubleshoot.'
2021-11-11T07:56:03.1426711Z ------------------------------ Captured log call ------------------------------
2021-11-11T07:56:03.1427773Z �[33mWARNING �[0m azure.identity._internal.decorators:decorators.py:41 AzureCliCredential.get_token failed: Failed to invoke the Azure CLI
2021-11-11T07:56:03.1428786Z Traceback (most recent call last):
2021-11-11T07:56:03.1429550Z File "c:\miniconda\envs\51333213\lib\subprocess.py", line 425, in run
2021-11-11T07:56:03.1430721Z stdout, stderr = process.communicate(input, timeout=timeout)
2021-11-11T07:56:03.1431643Z File "c:\miniconda\envs\51333213\lib\subprocess.py", line 863, in communicate
2021-11-11T07:56:03.1432446Z stdout, stderr = self._communicate(input, endtime, timeout)
2021-11-11T07:56:03.1433238Z File "c:\miniconda\envs\51333213\lib\subprocess.py", line 1114, in _communicate
2021-11-11T07:56:03.1434006Z raise TimeoutExpired(self.args, orig_timeout)
2021-11-11T07:56:03.1435013Z subprocess.TimeoutExpired: Command '['cmd', '/c', 'az account get-access-token --output json --resource https://management.azure.com']' timed out after 10 seconds
2021-11-11T07:56:03.1436106Z During handling of the above exception, another exception occurred:
2021-11-11T07:56:03.1436870Z Traceback (most recent call last):
2021-11-11T07:56:03.1437705Z File "c:\miniconda\envs\51333213\lib\site-packages\azure\identity_credentials\azure_cli.py", line 141, in _run_command
2021-11-11T07:56:03.1438575Z return subprocess.check_output(args, **kwargs)
2021-11-11T07:56:03.1439366Z File "c:\miniconda\envs\51333213\lib\subprocess.py", line 356, in check_output
2021-11-11T07:56:03.1440070Z **kwargs).stdout
2021-11-11T07:56:03.1440895Z File "c:\miniconda\envs\51333213\lib\subprocess.py", line 430, in run
2021-11-11T07:56:03.1441595Z stderr=stderr)
2021-11-11T07:56:03.1442515Z subprocess.TimeoutExpired: Command '['cmd', '/c', 'az account get-access-token --output json --resource https://management.azure.com']' timed out after 10 seconds
2021-11-11T07:56:03.1443608Z The above exception was the direct cause of the following exception:
2021-11-11T07:56:03.1444363Z Traceback (most recent call last):
2021-11-11T07:56:03.1445190Z File "c:\miniconda\envs\51333213\lib\site-packages\azure\identity_internal\decorators.py", line 30, in wrapper
2021-11-11T07:56:03.1445991Z token = fn(*args, **kwargs)
2021-11-11T07:56:03.1446820Z File "c:\miniconda\envs\51333213\lib\site-packages\azure\identity_credentials\azure_cli.py", line 73, in get_token
2021-11-11T07:56:03.1447630Z output = _run_command(command)
2021-11-11T07:56:03.1448621Z File "c:\miniconda\envs\51333213\lib\site-packages\azure\identity_credentials\azure_cli.py", line 162, in _run_command
2021-11-11T07:56:03.1449429Z six.raise_from(error, ex)
2021-11-11T07:56:03.1450057Z File "", line 3, in raise_from
2021-11-11T07:56:03.1450965Z azure.identity._exceptions.CredentialUnavailableError: Failed to invoke the Azure CLI
2021-11-11T07:56:03.1452689Z �[32mINFO �[0m azure.core.pipeline.policies.http_logging_policy:_universal.py:475 Request URL: 'https://login.microsoftonline.com/organizations/v2.0/.well-known/openid-configuration'/nRequest method: 'GET'/nRequest headers:/n 'User-Agent': 'azsdk-python-identity/1.7.1 Python/3.6.8 (Windows-10-10.0.17763-SP0) VSTS_8b119ea1-2e2a-4839-8db7-8c9e8d50f6fa_build_13339_0'/nNo body was attached to the request
2021-11-11T07:56:03.1454520Z �[35mDEBUG �[0m urllib3.connectionpool:connectionpool.py:975 Starting new HTTPS connection (1): login.microsoftonline.com:443
2021-11-11T07:56:03.1456088Z �[35mDEBUG �[0m urllib3.connectionpool:connectionpool.py:461 https://login.microsoftonline.com:443 "GET /organizations/v2.0/.well-known/openid-configuration HTTP/1.1" 200 1589
2021-11-11T07:56:03.1458835Z �[32mINFO �[0m azure.core.pipeline.policies.http_logging_policy:_universal.py:503 Response status: 200/nResponse headers:/n 'Cache-Control': 'max-age=86400, private'/n 'Content-Type': 'application/json; charset=utf-8'/n 'Strict-Transport-Security': 'REDACTED'/n 'X-Content-Type-Options': 'REDACTED'/n 'Access-Control-Allow-Origin': 'REDACTED'/n 'Access-Control-Allow-Methods': 'REDACTED'/n 'P3P': 'REDACTED'/n 'x-ms-request-id': 'cef116c9-1073-4ad3-861c-b643b8245d00'/n 'x-ms-ests-server': 'REDACTED'/n 'Set-Cookie': 'REDACTED'/n 'Date': 'Thu, 11 Nov 2021 07:43:14 GMT'/n 'Content-Leng