azure-cli: az acr login hangs
Describe the bug
Running az acr login --name ensuretouchdev
never finishes
To Reproduce Run command
Expected behavior Login into registry
Environment summary
Ubuntu 18.04
$ az --version
azure-cli 2.16.0
core 2.16.0
telemetry 1.0.6
Extensions:
azure-devops 0.18.0
Python location '/opt/az/bin/python3'
Extensions directory '/home/jcormier/.azure/cliextensions'
Python (Linux) 3.6.10 (default, Dec 4 2020, 12:36:15)
[GCC 7.5.0]
Your CLI is up-to-date.
$ docker version
Client:
Version: 19.03.6
API version: 1.40
Go version: go1.12.17
Git commit: 369ce74a3c
Built: Wed Oct 14 19:00:27 2020
OS/Arch: linux/amd64
Experimental: false
Server:
Engine:
Version: 19.03.6
API version: 1.40 (minimum version 1.12)
Go version: go1.12.17
Git commit: 369ce74a3c
Built: Wed Oct 14 16:52:50 2020
OS/Arch: linux/amd64
Experimental: false
containerd:
Version: 1.3.3-0ubuntu1~18.04.2
GitCommit:
runc:
Version: spec: 1.0.1-dev
GitCommit:
docker-init:
Version: 0.18.0
GitCommit:
Additional context
$ az acr login --name ensuretouchdev --verbose --debug
Command arguments: ['acr', 'login', '--name', 'ensuretouchdev', '--verbose', '--debug']
Event: Cli.PreExecute []
Event: CommandParser.OnGlobalArgumentsCreate [<function CLILogging.on_global_arguments at 0x7f4e1a6a7950>, <function OutputProducer.on_global_arguments at 0x7f4e1a1f96a8>, <function CLIQuery.on_global_argument
s at 0x7f4e19f8e950>]
Event: CommandInvoker.OnPreCommandTableCreate []
Modules found from index for 'acr': ['azure.cli.command_modules.acr']
Loading command modules:
Name Load Time Groups Commands
acr 0.004 25 103
Total (1) 0.004 25 103
These extensions are not installed and will be skipped: ['azext_ai_examples']
Loading extensions:
Name Load Time Groups Commands Directory
Total (0) 0.000 0 0
Loaded 25 groups, 103 commands.
Found a match in the command table.
Raw command : acr login
Command table: acr login
Event: CommandInvoker.OnPreCommandTableTruncate [<function AzCliLogging.init_command_file_logging at 0x7f4e194119d8>]
az_command_data_logger : command args: acr login --name {} --verbose --debug
metadata file logging enabled - writing logs to '/home/jcormier/.azure/commands'.
Event: CommandInvoker.OnPreArgumentLoad [<function register_global_subscription_argument.<locals>.add_subscription_parameter at 0x7f4e193c2b70>, <function register_global_query_examples_argument.<locals>.regis
ter_query_examples at 0x7f4e1931f2f0>]
Event: CommandInvoker.OnPostArgumentLoad []
Event: CommandInvoker.OnPostCommandTableCreate [<function register_ids_argument.<locals>.add_ids_arguments at 0x7f4e1931f378>, <function register_cache_arguments.<locals>.add_cache_arguments at 0x7f4e1931f488>
]
Event: CommandInvoker.OnCommandTableLoaded []
Event: CommandInvoker.OnPreParseArgs []
Event: CommandInvoker.OnPostParseArgs [<function OutputProducer.handle_output_argument at 0x7f4e1a1f9730>, <function CLIQuery.handle_query_parameter at 0x7f4e19f8e9d8>, <function register_global_query_examples
_argument.<locals>.handle_example_parameter at 0x7f4e1931f268>, <function register_ids_argument.<locals>.parse_ids_arguments at 0x7f4e1931f400>]
Getting management service client client_type=ResourceManagementClient
msrest.universal_http.requests : Configuring retry: max_retries=4, backoff_factor=0.8, max_backoff=90
Adding custom headers to the client:
'x-ms-client-request-id': 'a88bfe4f-4092-11eb-8496-309c2321fb76'
'CommandName': 'acr login'
'ParameterSetName': '--name --verbose --debug'
msrest.async_paging : Paging async iterator protocol is not available for GenericResourceExpandedPaged
AdalAuthentication.signed_session invoked by Track 1 SDK
Retrieving token from ADAL for resource 'https://management.core.windows.net/'
attempting to read file /home/jcormier/.azure/accessTokens.json as utf-8-sig
adal-python : 4850b117-3d1e-4cc9-8542-b3f4005dfca9 - Authority:Performing instance discovery: ...
adal-python : 4850b117-3d1e-4cc9-8542-b3f4005dfca9 - Authority:Performing static instance discovery [73/7640]
adal-python : 4850b117-3d1e-4cc9-8542-b3f4005dfca9 - Authority:Authority validated via static instance discovery
adal-python : 4850b117-3d1e-4cc9-8542-b3f4005dfca9 - TokenRequest:Getting token from cache with refresh if necessary.
adal-python : 4850b117-3d1e-4cc9-8542-b3f4005dfca9 - CacheDriver:finding with query keys: {'_clientId': '...', 'userId': '...'}
adal-python : 4850b117-3d1e-4cc9-8542-b3f4005dfca9 - CacheDriver:Looking for potential cache entries: {'_clientId': '...', 'userId': '...'}
adal-python : 4850b117-3d1e-4cc9-8542-b3f4005dfca9 - CacheDriver:Found 4 potential entries.
adal-python : 4850b117-3d1e-4cc9-8542-b3f4005dfca9 - CacheDriver:Resource specific token found.
adal-python : 4850b117-3d1e-4cc9-8542-b3f4005dfca9 - CacheDriver:Returning token from cache lookup, AccessTokenId: b'QRuqbIhPkNx9myZm1VOuTW3RNzIWQyWL+IWBXuz6GIo=', RefreshTokenId: b'duW+Q1xAb4tYSekaf6z1J6cWa8n
NR9DfkUjme/B9IJE='
msrest.http_logger : Request URL: 'https://management.azure.com/subscriptions/4c1c123b-e4e5-4068-b1f0-439062b6a102/resources?$filter=resourceType%20eq%20%27Microsoft.ContainerRegistry%2Fregistries%27&api-versi
on=2020-06-01'
msrest.http_logger : Request method: 'GET'
msrest.http_logger : Request headers:
msrest.http_logger : 'Accept': 'application/json'
msrest.http_logger : 'accept-language': 'en-US'
msrest.http_logger : 'User-Agent': 'python/3.6.10 (Linux-4.15.0-118-generic-x86_64-with-debian-buster-sid) msrest/0.6.18 msrest_azure/0.6.3 azure-mgmt-resource/10.3.0 Azure-SDK-For-Python AZURECLI/2.16.0 (
DEB)'
msrest.http_logger : Request body:
msrest.http_logger : None
msrest.universal_http : Configuring redirects: allow=True, max=30
msrest.universal_http : Configuring request: timeout=100, verify=True, cert=None
msrest.universal_http : Configuring proxies: ''
msrest.universal_http : Evaluate proxies against ENV settings: True
urllib3.connectionpool : Starting new HTTPS connection (1): management.azure.com:443
urllib3.connectionpool : https://management.azure.com:443 "GET /subscriptions/4c1c123b-e4e5-4068-b1f0-439062b6a102/resources?$filter=resourceType%20eq%20%27Microsoft.ContainerRegistry%2Fregistries%27&api-versi
on=2020-06-01 HTTP/1.1" 200 452
msrest.http_logger : Response status: 200
msrest.http_logger : Response headers:
msrest.http_logger : 'Cache-Control': 'no-cache'
msrest.http_logger : 'Pragma': 'no-cache'
msrest.http_logger : 'Content-Type': 'application/json; charset=utf-8'
msrest.http_logger : 'Content-Encoding': 'gzip'
msrest.http_logger : 'Expires': '-1'
msrest.http_logger : 'Vary': 'Accept-Encoding'
msrest.http_logger : 'x-ms-request-id': '292d275c-d8df-4c2b-aabf-e2b9ce3fdaaf'
msrest.http_logger : 'x-ms-correlation-request-id': '292d275c-d8df-4c2b-aabf-e2b9ce3fdaaf'
msrest.http_logger : 'x-ms-routing-request-id': 'CANADACENTRAL:20201217T180700Z:292d275c-d8df-4c2b-aabf-e2b9ce3fdaaf'
msrest.http_logger : 'Strict-Transport-Security': 'max-age=31536000; includeSubDomains'
msrest.http_logger : 'X-Content-Type-Options': 'nosniff'
msrest.http_logger : 'Date': 'Thu, 17 Dec 2020 18:07:00 GMT'
msrest.http_logger : 'Content-Length': '452'
msrest.http_logger : Response content:
msrest.http_logger : {"value":[{"id":"/subscriptions/4c1c123b-e4e5-4068-b1f0-439062b6a102/resourceGroups/EnsureTouch-Dev/providers/Microsoft.ContainerRegistry/registries/EnsureTouchDev","name":"EnsureTouchDev"
,"type":"Microsoft.ContainerRegistry/registries","sku":{"name":"Premium","tier":"Premium"},"location":"westus","tags":{},"systemData":{"createdBy":"anudelman@hygiena.com","createdByType":"User","createdAt":"20
20-12-14T23:34:26.2600584Z","lastModifiedBy":"anudelman@hygiena.com","lastModifiedByType":"User","lastModifiedAt":"2020-12-15T22:29:42.0884895Z"}}]}
Getting management service client client_type=ContainerRegistryManagementClient
msrest.universal_http.requests : Configuring retry: max_retries=4, backoff_factor=0.8, max_backoff=90
Adding custom headers to the client:
'x-ms-client-request-id': 'a88bfe4f-4092-11eb-8496-309c2321fb76'
'CommandName': 'acr login'
'ParameterSetName': '--name --verbose --debug'
AdalAuthentication.signed_session invoked by Track 1 SDK
Retrieving token from ADAL for resource 'https://management.core.windows.net/'
adal-python : cdfbc30c-9d94-447d-8237-a1dd7af4038c - Authority:Performing instance discovery: ...
adal-python : cdfbc30c-9d94-447d-8237-a1dd7af4038c - Authority:Performing static instance discovery
adal-python : cdfbc30c-9d94-447d-8237-a1dd7af4038c - Authority:Authority validated via static instance discovery
adal-python : cdfbc30c-9d94-447d-8237-a1dd7af4038c - TokenRequest:Getting token from cache with refresh if necessary.
adal-python : cdfbc30c-9d94-447d-8237-a1dd7af4038c - CacheDriver:finding with query keys: {'_clientId': '...', 'userId': '...'}
adal-python : cdfbc30c-9d94-447d-8237-a1dd7af4038c - CacheDriver:Looking for potential cache entries: {'_clientId': '...', 'userId': '...'}
adal-python : cdfbc30c-9d94-447d-8237-a1dd7af4038c - CacheDriver:Found 4 potential entries.
adal-python : cdfbc30c-9d94-447d-8237-a1dd7af4038c - CacheDriver:Resource specific token found.
adal-python : cdfbc30c-9d94-447d-8237-a1dd7af4038c - CacheDriver:Returning token from cache lookup, AccessTokenId: b'QRuqbIhPkNx9myZm1VOuTW3RNzIWQyWL+IWBXuz6GIo=', RefreshTokenId: b'duW+Q1xAb4tYSekaf6z1J6cWa8n
NR9DfkUjme/B9IJE='
msrest.http_logger : Request URL: 'https://management.azure.com/subscriptions/4c1c123b-e4e5-4068-b1f0-439062b6a102/resourceGroups/ensuretouch-dev/providers/Microsoft.ContainerRegistry/registries/ensuretouchdev
?api-version=2019-12-01-preview'
msrest.http_logger : Request method: 'GET'
msrest.http_logger : Request headers:
msrest.http_logger : 'Accept': 'application/json'
msrest.http_logger : 'accept-language': 'en-US'
msrest.http_logger : 'User-Agent': 'python/3.6.10 (Linux-4.15.0-118-generic-x86_64-with-debian-buster-sid) msrest/0.6.18 msrest_azure/0.6.3 azure-mgmt-containerregistry/3.0.0rc15 Azure-SDK-For-Python AZURE
CLI/2.16.0 (DEB)'
msrest.http_logger : Request body:
msrest.http_logger : None
msrest.universal_http : Configuring redirects: allow=True, max=30
msrest.universal_http : Configuring request: timeout=100, verify=True, cert=None
msrest.universal_http : Configuring proxies: ''
msrest.universal_http : Evaluate proxies against ENV settings: True
urllib3.connectionpool : Starting new HTTPS connection (1): management.azure.com:443
urllib3.connectionpool : https://management.azure.com:443 "GET /subscriptions/4c1c123b-e4e5-4068-b1f0-439062b6a102/resourceGroups/ensuretouch-dev/providers/Microsoft.ContainerRegistry/registries/ensuretouchdev
?api-version=2019-12-01-preview HTTP/1.1" 200 None
msrest.http_logger : Response status: 200
msrest.http_logger : Response headers:
msrest.http_logger : 'Cache-Control': 'no-cache'
msrest.http_logger : 'Pragma': 'no-cache'
msrest.http_logger : 'Transfer-Encoding': 'chunked'
msrest.http_logger : 'Content-Type': 'application/json; charset=utf-8'
msrest.http_logger : 'Content-Encoding': 'gzip'
msrest.http_logger : 'Expires': '-1'
msrest.http_logger : 'Vary': 'Accept-Encoding'
msrest.http_logger : 'Strict-Transport-Security': 'max-age=31536000; includeSubDomains'
msrest.http_logger : 'Server': 'Microsoft-HTTPAPI/2.0'
msrest.http_logger : 'x-ms-ratelimit-remaining-subscription-reads': '11999'
msrest.http_logger : 'x-ms-request-id': '2bce4e35-e54e-4047-baf2-6181c5548eca'
msrest.http_logger : 'x-ms-correlation-request-id': '2bce4e35-e54e-4047-baf2-6181c5548eca'
msrest.http_logger : 'x-ms-routing-request-id': 'CANADACENTRAL:20201217T180701Z:2bce4e35-e54e-4047-baf2-6181c5548eca'
msrest.http_logger : 'X-Content-Type-Options': 'nosniff'
msrest.http_logger : 'Date': 'Thu, 17 Dec 2020 18:07:00 GMT'
msrest.http_logger : Response content:
msrest.http_logger : {"sku":{"name":"Premium","tier":"Premium"},"type":"Microsoft.ContainerRegistry/registries","id":"/subscriptions/4c1c123b-e4e5-4068-b1f0-439062b6a102/resourceGroups/EnsureTouch-Dev/provider
s/Microsoft.ContainerRegistry/registries/EnsureTouchDev","name":"EnsureTouchDev","location":"westus","tags":{},"systemData":{"createdBy":"anudelman@hygiena.com","createdByType":"User","createdAt":"2020-12-14T2
3:34:26.2600584+00:00","lastModifiedBy":"anudelman@hygiena.com","lastModifiedByType":"User","lastModifiedAt":"2020-12-15T22:29:42.0884895+00:00"},"properties":{"loginServer":"ensuretouchdev.azurecr.io","creationDate":"2020-12-14T23:34:26.2600584Z","provisioningState":"Succeeded","adminUserEnabled":false,"networkRuleSet":{"defaultAction":"Allow","virtualNetworkRules":[],"ipRules":[]},"policies":{"quarantinePolicy":{
"status":"disabled"},"trustPolicy":{"type":"Notary","status":"disabled"},"retentionPolicy":{"days":7,"lastUpdatedTime":"2020-12-14T23:34:27.1103104+00:00","status":"disabled"}},"encryption":{"status":"disabled"},"dataEndpointEnabled":false,"dataEndpointHostNames":[],"privateEndpointConnections":[],"publicNetworkAccess":"Enabled","networkRuleBypassOptions":"AzureServices"}}
urllib3.connectionpool : Starting new HTTPS connection (1): ensuretouchdev.azurecr.io:443
urllib3.connectionpool : https://ensuretouchdev.azurecr.io:443 "GET /v2/ HTTP/1.1" 401 149
Attempting to retrieve AAD refresh token...
urllib3.connectionpool : Starting new HTTPS connection (1): ensuretouchdev.azurecr.io:443
urllib3.connectionpool : https://ensuretouchdev.azurecr.io:443 "GET /v2/ HTTP/1.1" 401 149
Profile.get_raw_token invoked with resource=None, subscription='4c1c123b-e4e5-4068-b1f0-439062b6a102', tenant=None
adal-python : 7e7d818d-561f-443c-949b-e9dc26082717 - Authority:Performing instance discovery: ...
adal-python : 7e7d818d-561f-443c-949b-e9dc26082717 - Authority:Performing static instance discovery
adal-python : 7e7d818d-561f-443c-949b-e9dc26082717 - Authority:Authority validated via static instance discovery
adal-python : 7e7d818d-561f-443c-949b-e9dc26082717 - TokenRequest:Getting token from cache with refresh if necessary.
adal-python : 7e7d818d-561f-443c-949b-e9dc26082717 - CacheDriver:finding with query keys: {'_clientId': '...', 'userId': '...'}
adal-python : 7e7d818d-561f-443c-949b-e9dc26082717 - CacheDriver:Looking for potential cache entries: {'_clientId': '...', 'userId': '...'}
adal-python : 7e7d818d-561f-443c-949b-e9dc26082717 - CacheDriver:Found 4 potential entries.
adal-python : 7e7d818d-561f-443c-949b-e9dc26082717 - CacheDriver:Resource specific token found.
adal-python : 7e7d818d-561f-443c-949b-e9dc26082717 - CacheDriver:Returning token from cache lookup, AccessTokenId: b'QRuqbIhPkNx9myZm1VOuTW3RNzIWQyWL+IWBXuz6GIo=', RefreshTokenId: b'duW+Q1xAb4tYSekaf6z1J6cWa8n
NR9DfkUjme/B9IJE='
urllib3.connectionpool : Starting new HTTPS connection (1): ensuretouchdev.azurecr.io:443
urllib3.connectionpool : https://ensuretouchdev.azurecr.io:443 "POST /oauth2/exchange HTTP/1.1" 200 None
About this issue
- Original URL
- State: open
- Created 4 years ago
- Reactions: 5
- Comments: 22 (4 by maintainers)
(Relaying part of the email conversation here, in the hopes that it’ll help folks debug this issue if they run into it.)
A working theory on this is that
acr login
is doing some sort ofdocker
call/command during the hang.In the course of debugging something completely separate, I discovered that Docker for OS X on my machine was hung; the whale icon in the menu was grey, and hovering over it got me the beachball. It occurs to me (since I don’t know how long that was going on) that it could be related to this; perhaps a recent Docker update has introduced some bug recently that causes hangs, and that also translates to hangs inside
acr login
, and that’s just how I’m noticing it.It sounds like
acr login
is doing something docker related at this point. (If you read the logs posted here, you see that thePOST /oauth2/exchange
call appears to have completed, but that raises the question: if that finished, then what are we waiting on?) I’ve asked thatacr login
log whatever it is that it is doing here, since then it would provide clear feedback (at least, if you’re using--debug
) as to what the hang was for.Restarting Docker Desktop, then running
az acr login
again worked for me on Pop!_OS 22.04 LTSStill an issue
Having the same issue. Other suggestions here are not working. I’ve tried restarting docker desktop and re-running
az login
.