-
Bug
-
Resolution: Unresolved
-
Normal
-
None
-
4.14.0
-
Moderate
-
No
-
5
-
False
-
I've noticed that sometimes on my dev-scripts environment fast-track mode does not actually work. I've seen a freshly inspected node going through a full power cycle for cleaning. In the agent logs I see
ar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client [-] An error occurred while attempting to discover the available Ironic API versions, falling back to using version 1.31: requests.exceptions.SSLError: HTTPSConnectionPool(host='192.168.111.5', port=6385): Max retries exceeded with url: / (Caused by SSLError(SSLError(1, '[SSL: WRONG_VERSION_NUMBER] wrong version number (_ssl.c:1129)'))) Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client Traceback (most recent call last): Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client File "/usr/lib/python3.9/site-packages/urllib3/connectionpool.py", line 699, in urlopen Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client httplib_response = self._make_request( Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client File "/usr/lib/python3.9/site-packages/urllib3/connectionpool.py", line 382, in _make_request Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client self._validate_conn(conn) Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client File "/usr/lib/python3.9/site-packages/urllib3/connectionpool.py", line 1010, in _validate_conn Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client conn.connect() Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client File "/usr/lib/python3.9/site-packages/urllib3/connection.py", line 411, in connect Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client self.sock = ssl_wrap_socket( Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client File "/usr/lib/python3.9/site-packages/urllib3/util/ssl_.py", line 453, in ssl_wrap_socket Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client ssl_sock = _ssl_wrap_socket_impl(sock, context, tls_in_tls) Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client File "/usr/lib/python3.9/site-packages/urllib3/util/ssl_.py", line 495, in _ssl_wrap_socket_impl Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client return ssl_context.wrap_socket(sock) Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client File "/usr/lib/python3.9/site-packages/eventlet/green/ssl.py", line 446, in wrap_socket Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client return GreenSSLSocket(sock, *a, _context=self, **kw) Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client File "/usr/lib/python3.9/site-packages/eventlet/green/ssl.py", line 140, in __init__ Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client self.do_handshake() Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client File "/usr/lib/python3.9/site-packages/eventlet/green/ssl.py", line 312, in do_handshake Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client return self._call_trampolining( Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client File "/usr/lib/python3.9/site-packages/eventlet/green/ssl.py", line 162, in _call_trampolining Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client return func(*a, **kw) Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client File "/usr/lib64/python3.9/ssl.py", line 1309, in do_handshake Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client self._sslobj.do_handshake() Mar 29 09:59:03 extraworker-1 podman[1337]: 2023-03-29 09:59:03.762 1 ERROR ironic_python_agent.ironic_api_client ssl.SSLError: [SSL: WRONG_VERSION_NUMBER] wrong version number (_ssl.c:1129)
Interestingly, the lookup then succeeds but without an agent token. Then heartbeats keep failing:
Mar 29 09:59:04 extraworker-1 ironic-agent[1355]: 2023-03-29 09:59:04.132 1 ERROR ironic_python_agent.agent Traceback (most recent call last): Mar 29 09:59:04 extraworker-1 podman[1337]: 2023-03-29 09:59:04.132 1 ERROR ironic_python_agent.agent [-] error sending heartbeat to https://192.168.111.5:6385: ironic_python_agent.errors.HeartbeatError: Error heartbeating to agent API: Error 400: Agent token is required for heartbeat processing. Mar 29 09:59:04 extraworker-1 podman[1337]: 2023-03-29 09:59:04.132 1 ERROR ironic_python_agent.agent Traceback (most recent call last): Mar 29 09:59:04 extraworker-1 podman[1337]: 2023-03-29 09:59:04.132 1 ERROR ironic_python_agent.agent File "/usr/lib/python3.9/site-packages/ironic_python_agent/agent.py", line 118, in do_heartbeat Mar 29 09:59:04 extraworker-1 podman[1337]: 2023-03-29 09:59:04.132 1 ERROR ironic_python_agent.agent self.api.heartbeat( Mar 29 09:59:04 extraworker-1 podman[1337]: 2023-03-29 09:59:04.132 1 ERROR ironic_python_agent.agent File "/usr/lib/python3.9/site-packages/ironic_python_agent/ironic_api_client.py", line 176, in heartbeat Mar 29 09:59:04 extraworker-1 podman[1337]: 2023-03-29 09:59:04.132 1 ERROR ironic_python_agent.agent raise errors.HeartbeatError(error) Mar 29 09:59:04 extraworker-1 podman[1337]: 2023-03-29 09:59:04.132 1 ERROR ironic_python_agent.agent ironic_python_agent.errors.HeartbeatError: Error heartbeating to agent API: Error 400: Agent token is required for heartbeat processing. Mar 29 09:59:04 extraworker-1 podman[1337]: 2023-03-29 09:59:04.132 1 ERROR ironic_python_agent.agent Mar 29 09:59:04 extraworker-1 ironic-agent[1355]: 2023-03-29 09:59:04.132 1 ERROR ironic_python_agent.agent File "/usr/lib/python3.9/site-packages/ironic_python_agent/agent.py", line 118, in do_heartbeat Mar 29 09:59:04 extraworker-1 ironic-agent[1355]: 2023-03-29 09:59:04.132 1 ERROR ironic_python_agent.agent self.api.heartbeat( Mar 29 09:59:04 extraworker-1 ironic-agent[1355]: 2023-03-29 09:59:04.132 1 ERROR ironic_python_agent.agent File "/usr/lib/python3.9/site-packages/ironic_python_agent/ironic_api_client.py", line 176, in heartbeat Mar 29 09:59:04 extraworker-1 ironic-agent[1355]: 2023-03-29 09:59:04.132 1 ERROR ironic_python_agent.agent raise errors.HeartbeatError(error) Mar 29 09:59:04 extraworker-1 ironic-agent[1355]: 2023-03-29 09:59:04.132 1 ERROR ironic_python_agent.agent ironic_python_agent.errors.HeartbeatError: Error heartbeating to agent API: Error 400: Agent token is required for heartbeat processing.
Steps to Reproduce: not sure yet. Maybe a race condition.
