test_clusterip_service_endpoint Failed to connect to clusterIP port 80 after x ms: Connection timed out

[Bas de Bruijne]

In testrun https://solutions.qa.canonical.com/v2/testruns/a9c727a4-7670-49ee-a617-127787248841 (ck8s 1.25 on jammy, juju3), the test suite fails with:

```
=================================== FAILURES ===================================
_______________________ test_clusterip_service_endpoint ________________________
Traceback (most recent call last):
  File "/home/ubuntu/k8s-validation/jobs/integration/test_service_endpoints.py", line 122, in test_clusterip_service_endpoint
    action = await juju_run(unit, cmd)
  File "/home/ubuntu/k8s-validation/jobs/integration/utils.py", line 623, in juju_run
    raise JujuRunError(unit, cmd, result)
integration.utils.JujuRunError: `curl -vk --noproxy "10.152.183.59" http://10.152.183.59:80` failed on kubernetes-worker/4:

* Trying 10.152.183.59:80...
  % Total % Received % Xferd Average Speed Time Time Time Current
                                 Dload Upload Total Spent Left Speed

  0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:01 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:02 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:03 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:04 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:05 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:06 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:07 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:08 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:09 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:10 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:11 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:12 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:13 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:14 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:15 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:16 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:17 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:18 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:19 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:20 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:21 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:22 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:23 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:24 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:25 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:26 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:27 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:28 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:29 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:30 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:31 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:32 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:33 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:34 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:35 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:36 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:37 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:38 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:39 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:40 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:41 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:42 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:43 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:44 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:45 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:46 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:47 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:48 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:49 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:50 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:51 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:52 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:53 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:54 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:55 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:56 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:57 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:58 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:00:59 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:00 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:01 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:02 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:03 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:04 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:05 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:06 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:07 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:08 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:09 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:10 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:11 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:12 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:13 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:14 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:15 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:16 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:17 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:18 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:19 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:20 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:21 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:22 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:23 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:24 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:25 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:26 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:27 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:28 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:29 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:30 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:31 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:32 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:33 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:34 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:35 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:36 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:37 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:38 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:39 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:40 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:41 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:42 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:43 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:44 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:45 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:46 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:47 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:48 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:49 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:50 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:51 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:52 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:53 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:54 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:55 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:56 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:57 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:58 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:01:59 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:02:00 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:02:01 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:02:02 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:02:03 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:02:04 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:02:05 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:02:06 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:02:07 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:02:08 --:--:-- 0
  0 0 0 0 0 0 0 0 --:--:-- 0:02:09 --:--:-- 0* connect to 10.152.183.59 port 80 failed: Connection timed out
* Failed to connect to 10.152.183.59 port 80 after 129467 ms: Connection timed out

  0 0 0 0 0 0 0 0 --:--:-- 0:02:09 --:--:-- 0
* Closing connection 0
curl: (28) Failed to connect to 10.152.183.59 port 80 after 129467 ms: Connection timed out
------------------------------ Captured log call -------------------------------
INFO sh.command:sh.py:646 <Command '/snap/bin/kubectl create deployment hello-world --image=rocks.canonical.com/cdk/google-samples/hello-app:1.0', pid 80102>: process started
INFO sh.command:sh.py:646 <Command '/snap/bin/kubectl set env deployment/hello-world PORT=50000', pid 80129>: process started
INFO sh.command:sh.py:646 <Command '/snap/bin/kubectl expose deployment hello-world --type=ClusterIP --name=hello-world --protocol=TCP --port=80 --target-port=50000', pid 80157>: process started
INFO sh.command:sh.py:646 <Command '/snap/bin/kubectl get po -o yaml --selector=app=hello-world', pid 80184>: process started
INFO sh.command:sh.py:646 <Command '/snap/bin/kubectl get po -o yaml --selector=app=hello-world', pid 80210>: process started
INFO sh.command:sh.py:646 <Command '/snap/bin/kubectl get po -o yaml --selector=app=hello-world', pid 80236>: process started
INFO sh.command:sh.py:646 <Command '/snap/bin/kubectl get svc -o yaml --selector=app=hello-world', pid 80263>: process started
INFO sh.command:sh.py:646 <Command '/snap/bin/kubectl delete deployment hello-world', pid 80291>: process started
INFO sh.command:sh.py:646 <Command '/snap/bin/kubectl delete service hello-world', pid 80318>: process started
INFO sh.command:sh.py:646 <Command '/snap/bin/kubectl get po -o yaml --selector=app=hello-world', pid 80344>: process started
INFO sh.command:sh.py:646 <Command '/snap/bin/kubectl get po -o yaml --selector=app=hello-world', pid 80370>: process started
=============================== warnings summary ===============================
.tox/py3/lib/python3.10/site-packages/invoke/loader.py:3
  /home/ubuntu/k8s-validation/.tox/py3/lib/python3.10/site-packages/invoke/loader.py:3: DeprecationWarning: the imp module is deprecated in favour of importlib and slated for removal in Python 3.12; see the module's documentation for alternative uses
    import imp

jobs/integration/conftest.py:531
  /home/ubuntu/k8s-validation/jobs/integration/conftest.py:531: PytestDeprecationWarning: The hookimpl pytest_metadata uses old-style configuration options (marks or attributes).
  Please use the pytest.hookimpl(optionalhook=True) decorator instead
   to configure the hooks.
   See https://docs.pytest.org/en/latest/deprecations.html#configuring-hook-specs-impls-using-markers
    @pytest.mark.optionalhook

-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
- generated xml file: /home/ubuntu/project/generated/kubernetes-maas/k8s-suite/test_clusterip_service_endpoint-junit.xml -
----- generated html file: file:///home/ubuntu/k8s-validation/report.html ------
=========================== short test summary info ============================
FAILED jobs/integration/test_service_endpoints.py::test_clusterip_service_endpoint
================== 1 failed, 2 warnings in 152.73s (0:02:32) ===================
Task was destroyed but it is pending!
task: <Task pending name='Task-36' coro=<WebSocketCommonProtocol.keepalive_ping() running at /home/ubuntu/k8s-validation/.tox/py3/lib/python3.10/site-packages/websockets/legacy/protocol.py:1234> wait_for=<Future pending cb=[Task.task_wakeup()]>>
Task was destroyed but it is pending!
task: <Task pending name='Task-43' coro=<Connection._pinger() running at /home/ubuntu/k8s-validation/.tox/py3/lib/python3.10/site-packages/juju/client/connection.py:583> wait_for=<Future pending cb=[Task.task_wakeup()]>>
Fatal error on SSL transport
protocol: <asyncio.sslproto.SSLProtocol object at 0x7f429ad319f0>
transport: <_SelectorSocketTransport closing fd=10>
Traceback (most recent call last):
  File "/usr/lib/python3.10/asyncio/selector_events.py", line 916, in write
    n = self._sock.send(data)
OSError: [Errno 9] Bad file descriptor

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.10/asyncio/sslproto.py", line 690, in _process_write_backlog
    self._transport.write(chunk)
  File "/usr/lib/python3.10/asyncio/selector_events.py", line 922, in write
    self._fatal_error(exc, 'Fatal write error on socket transport')
  File "/usr/lib/python3.10/asyncio/selector_events.py", line 717, in _fatal_error
    self._force_close(exc)
  File "/usr/lib/python3.10/asyncio/selector_events.py", line 729, in _force_close
    self._loop.call_soon(self._call_connection_lost, exc)
  File "/usr/lib/python3.10/asyncio/base_events.py", line 750, in call_soon
    self._check_closed()
  File "/usr/lib/python3.10/asyncio/base_events.py", line 515, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
Task was destroyed but it is pending!
task: <Task pending name='Task-35' coro=<WebSocketCommonProtocol.transfer_data() running at /home/ubuntu/k8s-validation/.tox/py3/lib/python3.10/site-packages/websockets/legacy/protocol.py:945> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[Task.task_wakeup(), _wait.<locals>._on_completion() at /usr/lib/python3.10/asyncio/tasks.py:475]>
Task was destroyed but it is pending!
task: <Task pending name='Task-37' coro=<WebSocketCommonProtocol.close_connection() running at /home/ubuntu/k8s-validation/.tox/py3/lib/python3.10/site-packages/websockets/legacy/protocol.py:1289> wait_for=<Task pending name='Task-35' coro=<WebSocketCommonProtocol.transfer_data() running at /home/ubuntu/k8s-validation/.tox/py3/lib/python3.10/site-packages/websockets/legacy/protocol.py:945> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[Task.task_wakeup(), _wait.<locals>._on_completion() at /usr/lib/python3.10/asyncio/tasks.py:475]>>
Task was destroyed but it is pending!
task: <Task pending name='Task-38' coro=<Connection._receiver() running at /home/ubuntu/k8s-validation/.tox/py3/lib/python3.10/site-packages/juju/client/connection.py:535> wait_for=<Future pending cb=[Task.task_wakeup()]>>
Exception ignored in: <coroutine object WebSocketCommonProtocol.close_connection at 0x7f429b0c2c00>
Traceback (most recent call last):
  File "/home/ubuntu/k8s-validation/.tox/py3/lib/python3.10/site-packages/websockets/legacy/protocol.py", line 1329, in close_connection
    await self.close_transport()
  File "/home/ubuntu/k8s-validation/.tox/py3/lib/python3.10/site-packages/websockets/legacy/protocol.py", line 1347, in close_transport
    if await self.wait_for_connection_lost():
  File "/home/ubuntu/k8s-validation/.tox/py3/lib/python3.10/site-packages/websockets/legacy/protocol.py", line 1372, in wait_for_connection_lost
    await asyncio.wait_for(
  File "/usr/lib/python3.10/asyncio/tasks.py", line 405, in wait_for
    loop = events.get_running_loop()
RuntimeError: no running event loop
Task was destroyed but it is pending!
task: <Task pending name='Task-533' coro=<WebSocketCommonProtocol.recv() done, defined at /home/ubuntu/k8s-validation/.tox/py3/lib/python3.10/site-packages/websockets/legacy/protocol.py:486> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[create_task_with_handler.<locals>._task_result_exp_handler(task_name='tmp', logger=<Logger juju....ion (WARNING)>)() at /home/ubuntu/k8s-validation/.tox/py3/lib/python3.10/site-packages/juju/jasyncio.py:64]>
Task was destroyed but it is pending!
task: <Task pending name='Task-534' coro=<Event.wait() done, defined at /usr/lib/python3.10/asyncio/locks.py:201> wait_for=<Future pending cb=[Task.task_wakeup()]>>
ERROR: InvocationError for command /home/ubuntu/k8s-validation/.tox/py3/bin/pytest -v -s --junit-xml=/home/ubuntu/project/generated/kubernetes-maas/k8s-suite/test_clusterip_service_endpoint-junit.xml --controller=foundations-maas --model=kubernetes-maas /home/ubuntu/k8s-validation/jobs/integration/test_service_endpoints.py::test_clusterip_service_endpoint (exited with code 1)
```

It looks similar to LP: #1983990

Crashdumps and configs can be found here:
https://oil-jenkins.canonical.com/artifacts/a9c727a4-7670-49ee-a617-127787248841/index.html