Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

WS between UI and task executer is not working and job logs are not streamed until the job ends #15544

Open
6 of 11 tasks
BorisWix opened this issue Sep 22, 2024 · 1 comment
Open
6 of 11 tasks

Comments

@BorisWix
Copy link

Please confirm the following

  • I agree to follow this project's code of conduct.
  • I have checked the current issues for duplicates.
  • I understand that AWX is open source software provided for free and that I might not receive a timely response.
  • I am NOT reporting a (potential) security vulnerability. (These should be emailed to [email protected] instead.)

Bug Summary

When a job is being triggered I expect to see its output in AWX UI- but the output shown only when the job finished.

Checking the logs of the UI pod and the task executer pod, I get the next errors (which I was not able to find similar behaviour in previous tickets)

UI pod logs:

2024-09-22 09:22:32,911 DEBUG    [1f0776fad4e74edb906e15a9d0289dca] awx.main.dispatch task 904b0daa-f273-46fd-80bc-b4f496aaba76 starting awx.main.analytics.analytics_tasks.send_subsystem_metrics(*[])
2024-09-22 09:22:34,895 INFO     [-] awx.main.wsrelay Adding {'awx-web-54757db445-d7rg6', 'awx-web-66c6bd4c69-p7ws2', 'awx-web-66c6bd4c69-vvkrc', 'dbops-awx-web-6dfc49fcf8-j6k4q', 'awx-web-54757db445-wrr9t'} to websocket broadcast list
2024-09-22 09:22:34,897 DEBUG    [-] awx.main.wsrelay Connection attempt from dbops-awx-task-7b8f544498-s2czg to 10.153.29.217
2024-09-22 09:22:34,898 DEBUG    [-] awx.main.wsrelay Connection attempt from dbops-awx-task-7b8f544498-s2czg to 10.23.55.216
2024-09-22 09:22:34,898 DEBUG    [-] awx.main.wsrelay Connection attempt from dbops-awx-task-7b8f544498-s2czg to 10.23.9.247
2024-09-22 09:22:34,898 DEBUG    [-] awx.main.wsrelay Connection attempt from dbops-awx-task-7b8f544498-s2czg to 10.23.146.182
2024-09-22 09:22:34,899 DEBUG    [-] awx.main.wsrelay Connection attempt from dbops-awx-task-7b8f544498-s2czg to 10.153.45.191
2024-09-22 09:22:34,905 WARNING  [-] awx.main.wsrelay Connection from dbops-awx-task-7b8f544498-s2czg to 10.153.45.191 failed for unknown reason: '403, message='Invalid response status', url=URL('http://10.173.45.191:8052/websocket/relay/')'.
Traceback (most recent call last):
  File "/var/lib/awx/venv/awx/lib64/python3.11/site-packages/awx/main/wsrelay.py", line 90, in connect
    async with session.ws_connect(uri, ssl=self.verify_ssl, heartbeat=20) as websocket:
  File "/var/lib/awx/venv/awx/lib64/python3.11/site-packages/aiohttp/client.py", line 1194, in __aenter__
    self._resp = await self._coro
                 ^^^^^^^^^^^^^^^^
  File "/var/lib/awx/venv/awx/lib64/python3.11/site-packages/aiohttp/client.py", line 848, in _ws_connect
    raise WSServerHandshakeError(
aiohttp.client_exceptions.WSServerHandshakeError: 403, message='Invalid response status', url=URL('http://10.173.45.191:8052/websocket/relay/')
2024-09-22 09:22:34,906 WARNING  [-] awx.main.wsrelay Connection from dbops-awx-task-7b8f544498-s2czg to 10.153.29.217 failed for unknown reason: '403, message='Invalid response status', url=URL('http://10.173.29.217:8052/websocket/relay/')'.
Traceback (most recent call last):
  File "/var/lib/awx/venv/awx/lib64/python3.11/site-packages/awx/main/wsrelay.py", line 90, in connect
    async with session.ws_connect(uri, ssl=self.verify_ssl, heartbeat=20) as websocket:
  File "/var/lib/awx/venv/awx/lib64/python3.11/site-packages/aiohttp/client.py", line 1194, in __aenter__
    self._resp = await self._coro
                 ^^^^^^^^^^^^^^^^
  File "/var/lib/awx/venv/awx/lib64/python3.11/site-packages/aiohttp/client.py", line 848, in _ws_connect
    raise WSServerHandshakeError(
aiohttp.client_exceptions.WSServerHandshakeError: 403, message='Invalid response status', url=URL('http://10.173.29.217:8052/websocket/relay/')
2024-09-22 09:22:35,948 DEBUG    [-] awx.main.wsrelay Web host dbops-awx-web-6dfc49fcf8-gs24m (10.23.157.145) online heartbeat received.
2024-09-22 09:22:36,241 DEBUG    [-] awx.main.wsrelay Web host dbops-awx-web-5cbd44dcc4-5rh44 (10.153.151.253) online heartbeat received.
2024-09-22 09:22:40,527 DEBUG    [-] awx.main.wsrelay Web host awx-web-66c6bd4c69-vvkrc (10.23.9.247) online heartbeat received.
2024-09-22 09:22:40,611 DEBUG    [-] awx.main.wsrelay Web host dbops-awx-web-5cbd44dcc4-fwlx7 (10.153.151.40) online heartbeat received.
2024-09-22 09:22:40,618 DEBUG    [-] awx.main.wsrelay Web host awx-web-54757db445-d7rg6 (10.153.29.217) online heartbeat received.

task executer pods:

10.153.146.166 - - [22/Sep/2024:09:23:34 +0000] "GET /websocket/relay/ HTTP/1.1" 403 5 "-" "Python/3.11 aiohttp/3.9.3" "-"
2024-09-22 09:23:34,923 INFO     [-] awx.main.consumers client 'specific.a2b9fbc1989d421d96cf1825cac94e99!dcf33113db2649a595fd99c57cd7156b' disconnected from the broadcast group.
2024-09-22 09:23:34,923 INFO     [-] awx.main.consumers client 'specific.a2b9fbc1989d421d96cf1825cac94e99!dcf33113db2649a595fd99c57cd7156b' disconnected from the broadcast group.
2024-09-22 09:23:34,923 INFO     client 'specific.a2b9fbc1989d421d96cf1825cac94e99!dcf33113db2649a595fd99c57cd7156b' disconnected from the broadcast group.
2024-09-22 09:23:40,824 DEBUG    [-] awx.main.commands.run_ws_heartbeat Sending heartbeat
2024-09-22 09:23:48,272 WARNING  [-] awx.main.consumers client 'specific.a2b9fbc1989d421d96cf1825cac94e99!51d1f8e9016a49abb2c8c8cbf3d4b8d3' failed to authorize against the broadcast endpoint.
2024-09-22 09:23:48,272 WARNING  [-] awx.main.consumers client 'specific.a2b9fbc1989d421d96cf1825cac94e99!51d1f8e9016a49abb2c8c8cbf3d4b8d3' failed to authorize against the broadcast endpoint.
2024-09-22 09:23:48,272 WARNING  client 'specific.a2b9fbc1989d421d96cf1825cac94e99!51d1f8e9016a49abb2c8c8cbf3d4b8d3' failed to authorize against the broadcast endpoint.
10.153.147.147 - - [22/Sep/2024:09:23:48 +0000] "GET /websocket/relay/ HTTP/1.1" 403 5 "-" "Python/3.11 aiohttp/3.9.3" "-"
2024-09-22 09:23:48,275 INFO     [-] awx.main.consumers client 'specific.a2b9fbc1989d421d96cf1825cac94e99!51d1f8e9016a49abb2c8c8cbf3d4b8d3' disconnected from the broadcast group.
2024-09-22 09:23:48,275 INFO     [-] awx.main.consumers client 'specific.a2b9fbc1989d421d96cf1825cac94e99!51d1f8e9016a49abb2c8c8cbf3d4b8d3' disconnected from the broadcast group.
2024-09-22 09:23:48,275 INFO     client 'specific.a2b9fbc1989d421d96cf1825cac94e99!51d1f8e9016a49abb2c8c8cbf3d4b8d3' disconnected from the broadcast group.
2024-09-22 09:23:55,840 DEBUG    [-] awx.main.commands.run_ws_heartbeat Sending heartbeat
2024-09-22 09:24:04,929 WARNING  [-] awx.main.consumers client 'specific.a2b9fbc1989d421d96cf1825cac94e99!8f405319b222484686e81a8f48a127fc' failed to authorize against the broadcast endpoint.
2024-09-22 09:24:04,929 WARNING  [-] awx.main.consumers client 'specific.a2b9fbc1989d421d96cf1825cac94e99!8f405319b222484686e81a8f48a127fc' failed to authorize against the broadcast endpoint.
2024-09-22 09:24:04,929 WARNING  client 'specific.a2b9fbc1989d421d96cf1825cac94e99!8f405319b222484686e81a8f48a127fc' failed to authorize against the broadcast endpoint.
10.153.146.166 - - [22/Sep/2024:09:24:04 +0000] "GET /websocket/relay/ HTTP/1.1" 403 5 "-" "Python/3.11 aiohttp/3.9.3" "-"
2024-09-22 09:24:04,932 INFO     [-] awx.main.consumers client 'specific.a2b9fbc1989d421d96cf1825cac94e99!8f405319b222484686e81a8f48a127fc' disconnected from the broadcast group.
2024-09-22 09:24:04,932 INFO     [-] awx.main.consumers client 'specific.a2b9fbc1989d421d96cf1825cac94e99!8f405319b222484686e81a8f48a127fc' disconnected from the broadcast group.
2024-09-22 09:24:04,932 INFO     client 'specific.a2b9fbc1989d421d96cf1825cac94e99!8f405319b222484686e81a8f48a127fc' disconnected from the broadcast group.
2024-09-22 09:24:10,845 DEBUG    [-] awx.main.commands.run_ws_heartbeat Sending heartbeat
2024-09-22 09:24:18,281 WARNING  [-] awx.main.consumers client 'specific.a2b9fbc1989d421d96cf1825cac94e99!8f115f696a1740e6b3eb549b9254d813' failed to authorize against the broadcast endpoint.
2024-09-22 09:24:18,281 WARNING  [-] awx.main.consumers client 'specific.a2b9fbc1989d421d96cf1825cac94e99!8f115f696a1740e6b3eb549b9254d813' failed to authorize against the broadcast endpoint.
2024-09-22 09:24:18,281 WARNING  client 'specific.a2b9fbc1989d421d96cf1825cac94e99!8f115f696a1740e6b3eb549b9254d813' failed to authorize against the broadcast endpoint.
10.153.147.147 - - [22/Sep/2024:09:24:18 +0000] "GET /websocket/relay/ HTTP/1.1" 403 5 "-" "Python/3.11 aiohttp/3.9.3" "-"

I already verified that the value of SECRET_KEY is the same on both pods.

AWX version

24.4.0

Select the relevant components

  • UI
  • UI (tech preview)
  • API
  • Docs
  • Collection
  • CLI
  • Other

Installation method

kubernetes

Modifications

no

Ansible version

2.15.8

Operating system

Docker image CentOS Stream 9

Web browser

Chrome

Steps to reproduce

Spinup AWX in eks using the official helm chart,
And that it, no need to run any job.

Expected results

Expect to print normal info logs

Actual results

Getting http and WS errors

Additional information

No response

@dmarav
Copy link

dmarav commented Sep 23, 2024

Seems like the same issue as #14876

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants