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

[kroyburman]

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('<urllib3.connection.HTTPSConnection object at 0x73c7adbe97f0>: 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 <some_uuid> --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 <some_uuid> --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('<urllib3.connection.HTTPSConnection object at 0x70aa717e7c50>: 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('<urllib3.connection.HTTPSConnection object at 0x70aa717e7c50>: 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: <urllib3.connection.HTTPSConnection object at 0x7f9233d0a7b0>: 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('<urllib3.connection.HTTPSConnection object at 0x7f9233d0a7b0>: 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('<urllib3.connection.HTTPSConnection object at 0x7f9233d0a7b0>: 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('<urllib3.connection.HTTPSConnection object at 0x7f9233d0a7b0>: 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('<urllib3.connection.HTTPSConnection object at 0x7f9233d0a7b0>: 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('<urllib3.connection.HTTPSConnection object at 0x7f9233d0a7b0>: Failed to establish a new connection: [Errno 111] Connection refused'))
DEBUG: cli.knack.cli: Event: Cli.PostExecute [<function AzCliLogging.deinit_cmd_metadata_logging at 0x7f9236c52e80>]
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

[yonzhan]

Thank you for opening this issue, we will look into it.

[pranayp-coles]

I am interested in this fix as well