Azure / Azure/azure-cli-extensions

[connectedk8s] Parallel invocation fails with Failed to fetch public key info from client proxyHTTPSConnectionPool

Open
#8,855 2 comments 0 reactions 0 assignees View on GitHub
Auto-Assign bug Connected Kubernetes Service Attention
Dominant language
Python
Stars
454
Forks
1.7k
Avg merge
2d 19h
Merged PRs (30d)
64

Description

### Describe the bug

### Issue
When trying to invoke multiple instances of `connectedk8s proxy` in **parallel** ( using gnu parallel or using parallel execution of ginkgo test framework ) only one instance of `connectedk8s proxy` starts while the other fails with

```
ERROR: Failed to fetch public key info from client proxyHTTPSConnectionPool(host='localhost', port=48012): Max retries exceeded with url: /identity/poppublickey (Caused by NewConnectionError(': Failed to establish a new connection: [Errno 111] Connection refused'))
Proxy is listening on port 48012
```

### What works
Invoking multiple instances of `connectedk8s proxy` but from different terminal instances works perfectly fine **( only if `--debug` flag is not provided )**

### How to replicate
Put the commands in a file
`connectedk8s proxy` commands that are being invoked

```
nohup az connectedk8s proxy --port 48007 --name cluster-001 --subscription --resource-group cluster-001-HostedResources-216D4F24 --file /tmp/test/001 > /tmp/test/001_proxy.log 2>&1
nohup az connectedk8s proxy --port 48012 --name cluster-002 --subscription --resource-group cluster-002-HostedResources-49E6812C --file /tmp/test/002 > /tmp/test/002_proxy.log 2>&1
```
Invoke the file using parallel

```
cat file | parallel
```

Check if both commands have started
```
ps aux | grep proxy
```
Keep checking the processes and one of the processes would have auto terminated.
Check the logs for the process that has terminated

It will have lines similar to

```
ERROR: Failed to fetch public key info from client proxyHTTPSConnectionPool(host='localhost', port=48007): Max retries exceeded with url: /identity/poppublickey (Caused by NewConnectionError(': Failed to establish a new connection: [Errno 111] Connection refused'))
Proxy is listening on port 48007
```

### Related command

`az connectedk8s proxy`

### Errors

```
ERROR: Failed to fetch public key info from client proxyHTTPSConnectionPool(host='localhost', port=48007): Max retries exceeded with url: /identity/poppublickey (Caused by NewConnectionError(': Failed to establish a new connection: [Errno 111] Connection refused'))
Proxy is listening on port 48007
```

### Issue script & Debug output

Multiple instance of connectedk8s proxy cannot be executed with `--debug` option.
From the 2nd invocation onwards it throws this error

```
DEBUG: urllib3.connectionpool: Starting new HTTPS connection (1): localhost:48012
level=warning msg="Listening profiling http://:6060"
level=info msg="Version: 1.3.029301"
level=info msg="Cloud_Config_Set: AZUREPUBLICCLOUD"
level=info msg="Cloud_Environment_Fetched: AzurePublicCloud"
level=info msg="Relay AAD Token Store is not configured." proxyVersion=1.3.029301
panic: listen tcp :6060: bind: address already in use

goroutine 6 [running]:
main.startProfiling.func1()
/__w/1/s/cmd/arcproxy/main.go:108 +0x9f
created by main.startProfiling in goroutine 1
/__w/1/s/cmd/arcproxy/main.go:107 +0x4f
DEBUG: urllib3.connectionpool: Starting new HTTPS connection (1): localhost:48012
DEBUG: urllib3.connectionpool: Starting new HTTPS connection (1): localhost:48012
DEBUG: urllib3.connectionpool: Starting new HTTPS connection (1): localhost:48012
DEBUG: urllib3.connectionpool: Starting new HTTPS connection (1): localhost:48012
DEBUG: urllib3.connectionpool: Starting new HTTPS connection (1): localhost:48012
DEBUG: urllib3.connectionpool: Starting new HTTPS connection (1): localhost:48012
DEBUG: urllib3.connectionpool: Starting new HTTPS connection (1): localhost:48012
DEBUG: urllib3.connectionpool: Starting new HTTPS connection (1): localhost:48012
DEBUG: urllib3.connectionpool: Starting new HTTPS connection (1): localhost:48012
DEBUG: urllib3.connectionpool: Starting new HTTPS connection (1): localhost:48012
DEBUG: urllib3.connectionpool: Starting new HTTPS connection (1): localhost:48012
DEBUG: cli.azure.cli.core.azclierror: Traceback (most recent call last):
File "/opt/az/lib/python3.12/site-packages/urllib3/connection.py", line 174, in _new_conn
conn = connection.create_connection(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/az/lib/python3.12/site-packages/urllib3/util/connection.py", line 95, in create_connection
raise err
File "/opt/az/lib/python3.12/site-packages/urllib3/util/connection.py", line 85, in create_connection
sock.connect(sa)
ConnectionRefusedError: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/opt/az/lib/python3.12/site-packages/urllib3/connectionpool.py", line 715, in urlopen
httplib_response = self._make_request(
^^^^^^^^^^^^^^^^^^^
File "/opt/az/lib/python3.12/site-packages/urllib3/connectionpool.py", line 404, in _make_request
self._validate_conn(conn)
File "/opt/az/lib/python3.12/site-packages/urllib3/connectionpool.py", line 1060, in _validate_conn
conn.connect()
File "/opt/az/lib/python3.12/site-packages/urllib3/connection.py", line 363, in connect
self.sock = conn = self._new_conn()
^^^^^^^^^^^^^^^^
File "/opt/az/lib/python3.12/site-packages/urllib3/connection.py", line 186, in _new_conn
raise NewConnectionError(
urllib3.exceptions.NewConnectionError: : Failed to establish a new connection: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/opt/az/lib/python3.12/site-packages/requests/adapters.py", line 667, in send
resp = conn.urlopen(
^^^^^^^^^^^^^
File "/opt/az/lib/python3.12/site-packages/urllib3/connectionpool.py", line 801, in urlopen
retries = retries.increment(
^^^^^^^^^^^^^^^^^^
File "/opt/az/lib/python3.12/site-packages/urllib3/util/retry.py", line 594, in increment
raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='localhost', port=48012): Max retries exceeded with url: /identity/poppublickey (Caused by NewConnectionError(': Failed to establish a new connection: [Errno 111] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/home/azureuser/.azure/cliextensions/connectedk8s/azext_connectedk8s/clientproxyhelper/_utils.py", line 85, in make_api_call_with_retries
response = requests.request(method, uri, json=data, verify=tls_verify)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/az/lib/python3.12/site-packages/requests/api.py", line 59, in request
return session.request(method=method, url=url, **kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/az/lib/python3.12/site-packages/requests/sessions.py", line 589, in request
resp = self.send(prep, **send_kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/az/lib/python3.12/site-packages/requests/sessions.py", line 703, in send
r = adapter.send(request, **kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/az/lib/python3.12/site-packages/requests/adapters.py", line 700, in send
raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPSConnectionPool(host='localhost', port=48012): Max retries exceeded with url: /identity/poppublickey (Caused by NewConnectionError(': Failed to establish a new connection: [Errno 111] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/opt/az/lib/python3.12/site-packages/knack/cli.py", line 233, in invoke
cmd_result = self.invocation.execute(args)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/az/lib/python3.12/site-packages/azure/cli/core/commands/__init__.py", line 666, in execute
raise ex
File "/opt/az/lib/python3.12/site-packages/azure/cli/core/commands/__init__.py", line 733, in _run_jobs_serially
results.append(self._run_job(expanded_arg, cmd_copy))
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/az/lib/python3.12/site-packages/azure/cli/core/commands/__init__.py", line 703, in _run_job
result = cmd_copy(params)
^^^^^^^^^^^^^^^^
File "/opt/az/lib/python3.12/site-packages/azure/cli/core/commands/__init__.py", line 336, in __call__
return self.handler(*args, **kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/az/lib/python3.12/site-packages/azure/cli/core/commands/command_operation.py", line 121, in handler
return op(**command_args)
^^^^^^^^^^^^^^^^^^
File "/home/azureuser/.azure/cliextensions/connectedk8s/azext_connectedk8s/custom.py", line 3601, in client_side_proxy_wrapper
client_side_proxy_main(
File "/home/azureuser/.azure/cliextensions/connectedk8s/azext_connectedk8s/custom.py", line 3631, in client_side_proxy_main
hc_expiry, at_expiry, clientproxy_process = client_side_proxy(
^^^^^^^^^^^^^^^^^^
File "/home/azureuser/.azure/cliextensions/connectedk8s/azext_connectedk8s/custom.py", line 3743, in client_side_proxy
at_expiry = proxylogic.handle_post_at_to_csp(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/azureuser/.azure/cliextensions/connectedk8s/azext_connectedk8s/clientproxyhelper/_proxylogic.py", line 38, in handle_post_at_to_csp
kid = clientproxyutils.fetch_pop_publickey_kid(api_server_port, clientproxy_process)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/azureuser/.azure/cliextensions/connectedk8s/azext_connectedk8s/clientproxyhelper/_utils.py", line 111, in fetch_pop_publickey_kid
get_publickey_response = make_api_call_with_retries(
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/azureuser/.azure/cliextensions/connectedk8s/azext_connectedk8s/clientproxyhelper/_utils.py", line 95, in make_api_call_with_retries
close_subprocess_and_raise_cli_error(
File "/home/azureuser/.azure/cliextensions/connectedk8s/azext_connectedk8s/clientproxyhelper/_utils.py", line 66, in close_subprocess_and_raise_cli_error
raise CLIInternalError(msg)
azure.cli.core.azclierror.CLIInternalError: Failed to fetch public key info from client proxyHTTPSConnectionPool(host='localhost', port=48012): Max retries exceeded with url: /identity/poppublickey (Caused by NewConnectionError(': Failed to establish a new connection: [Errno 111] Connection refused'))

ERROR: cli.azure.cli.core.azclierror: Failed to fetch public key info from client proxyHTTPSConnectionPool(host='localhost', port=48012): Max retries exceeded with url: /identity/poppublickey (Caused by NewConnectionError(': Failed to establish a new connection: [Errno 111] Connection refused'))
ERROR: az_command_data_logger: Failed to fetch public key info from client proxyHTTPSConnectionPool(host='localhost', port=48012): Max retries exceeded with url: /identity/poppublickey (Caused by NewConnectionError(': Failed to establish a new connection: [Errno 111] Connection refused'))
DEBUG: cli.knack.cli: Event: Cli.PostExecute []
INFO: az_command_data_logger: exit code: 1
INFO: cli.__main__: Command ran in 63.750 seconds (init: 0.187, invoke: 63.563)
DEBUG: cli.__main__: Intercept survey prompt failed. I/O operation on closed file
INFO: telemetry.main: Begin splitting cli events and extra events, total events: 1
INFO: telemetry.client: Accumulated 0 events. Flush the clients.
INFO: telemetry.main: Finish splitting cli events and extra events, cli events: 1
INFO: telemetry.save: Save telemetry record of length 9133 in cache file under /home/azureuser/.azure/telemetry/20250611101240849
INFO: telemetry.main: Begin creating telemetry upload process.
INFO: telemetry.process: Creating upload process: "/opt/az/bin/python3 /opt/az/lib/python3.12/site-packages/azure/cli/telemetry/__init__.py /home/azureuser/.azure /home/azureuser/.azure/telemetry/20250611101240849"
INFO: telemetry.process: Return from creating process 47162
INFO: telemetry.main: Finish creating telemetry upload process.
```

### Expected behavior

Since `connectedk8s proxy` supports multiple instance invocation; it should work when executed in parallel

### Environment Summary

```
azure-cli 2.67.0 *

core 2.67.0 *
telemetry 1.1.0

Extensions:
azure-devops 1.0.1
connectedk8s 1.10.5
connectedmachine 0.6.0
k8s-extension 1.6.2
log-analytics 1.0.0b1
managednetworkfabric 7.0.0
monitor-control-service 1.2.0
networkcloud 2.0.0
ssh 2.0.6

Dependencies:
msal 1.31.0
azure-mgmt-resource 23.1.1

Python location '/opt/az/bin/python3'
Extensions directory '/home/azureuser/.azure/cliextensions'

Python (Linux) 3.12.7 (main, Nov 13 2024, 04:06:34) [GCC 13.2.0]
```

### Additional context

_No response_

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.