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

SUPERVISOR - Failed to get logs using advanced API (NEW - NOT THE SAME) #5606

Open
RafAustralia opened this issue Feb 5, 2025 · 5 comments
Labels

Comments

@RafAustralia
Copy link

Describe the issue you are experiencing

Hi all

I have read through both previous issues and cases which simply refer to each other and are now closed and limited...

This issue has not been solved from research I have done.

I was told this issue is a similar issue to what happens when a docker is installed, but now I have this issue with bare metal HAOS install.

What type of installation are you running?

Home Assistant OS

Which operating system are you running on?

Home Assistant Operating System

Steps to reproduce the issue

  1. At random times supervisor logs stop and supervisor crashes all together
    2.We have rebuilt new NVME 2 Drive and new HAOS and reinstated the backup - same or very similar issue occurs.
  2. When supervisor crashes - system cannot be accessed, nor rebooted nor diagnosed in any other way but via ssh
  3. Happens now around once weekly...
  4. Might be related to Websockets, might be related to supervisors connectivity all together.
  5. It appears there is an issue with obtaining advanced logs when call is being issued to get these... and timouts occur perhaps...
    ...

Anything in the Supervisor logs that might be useful for us?

copy of the error, since rebuild last night:

2025-02-05 21:52:41.298 INFO (MainThread) [supervisor.resolution.fixup] Starting system autofix at state running
2025-02-05 21:52:41.298 INFO (MainThread) [supervisor.resolution.fixup] System autofix complete
2025-02-05 22:06:30.107 ERROR (MainThread) [supervisor.api] Failed to get supervisor logs using advanced_logs API
Traceback (most recent call last):
  File "/usr/src/supervisor/supervisor/api/host.py", line 262, in advanced_logs_handler
    await response.prepare(request)
  File "/usr/local/lib/python3.13/site-packages/aiohttp/web_response.py", line 453, in prepare
    return await self._start(request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/web_response.py", line 461, in _start
    await self._write_headers()
  File "/usr/local/lib/python3.13/site-packages/aiohttp/web_response.py", line 538, in _write_headers
    await writer.write_headers(status_line, self._headers)
  File "/usr/local/lib/python3.13/site-packages/aiohttp/http_writer.py", line 152, in write_headers
    self._write(buf)
    ~~~~~~~~~~~^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/http_writer.py", line 81, in _write
    raise ClientConnectionResetError("Cannot write to closing transport")
aiohttp.client_exceptions.ClientConnectionResetError: Cannot write to closing transport
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
  File "/usr/src/supervisor/supervisor/api/__init__.py", line 403, in get_supervisor_logs
    return await self._api_host.advanced_logs_handler(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
        *args, identifier="hassio_supervisor", **kwargs
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/src/supervisor/supervisor/api/host.py", line 269, in advanced_logs_handler
    raise APIError(
        "Connection reset when trying to fetch data from systemd-journald."
    ) from ex
supervisor.exceptions.APIError: Connection reset when trying to fetch data from systemd-journald.
2025-02-05 22:09:12.617 INFO (MainThread) [supervisor.homeassistant.api] Updated Home Assistant API token
2025-02-05 22:39:17.531 INFO (MainThread) [supervisor.homeassistant.api] Updated Home Assistant API token
2025-02-05 22:52:41.301 INFO (MainThread) [supervisor.resolution.check] Starting system checks with state running
2025-02-05 22:52:41.301 INFO (MainThread) [supervisor.resolution.checks.base] Run check for

System Health information

Installation type | Home Assistant OS
Development | false
Supervisor | true
Docker | true
User | root
Virtual environment | false
Python version | 3.13.1
Operating system family | Linux
Operating system version | 6.6.73-haos
CPU architecture | x86_64
Timezone | Australia/Brisbane
Configuration directory | /config

Home Assistant Supervisor
Host operating system | Home Assistant OS 14.2

Update channel | stable
Supervisor version | supervisor-2025.02.0
Agent version | 1.6.0
Docker version | 27.2.0
Disk total | 916.2 GB
Disk used | 28.1 GB
Healthy | true
Supported | true
host_connectivity | true
supervisor_connectivity | true
ntp_synchronized | true
virtualization |  
Board | generic-x86-64
Supervisor API | ok
Version API | ok
Installed add-ons | Matter Server (7.0.0),
Advanced SSH & Web Terminal (20.0.0),
Amber2MQTT (2025.2.4),
AppDaemon (0.16.7), EMHASS (v0.12.4),
EMHASS-GeoDerp-test (test),
ESPHome Device Builder (2024.12.4),
File editor (5.8.0), Git pull (7.14.1),
Mosquitto broker (6.5.0),
WiNet Extractor (0.2.2)

Supervisor diagnostics

No response

Additional information

I would love if this was not just referred to other two issues and closed off... as I cannot find any related answer to the problem.
System is bran new and fresh - only 12 hours old now, since rebuild...
Network doesnt seem to be an issue, we have gone through it yesterday,
I run unify, and over 60 tuya devices communicating on that network and not timing out...

We have removed vscode as it was misbehaving badly and landing a lot of errors...
supervisor appears to be the main and only remaining source of crashes now...
I am not quite sure what drives these though

Any help would be amazing - please.

Thank you in advance - much appreciated.

@purcell-lab
@agners

Raf

@agners
Copy link
Member

agners commented Feb 6, 2025

Can you share the host logs of that system as well?

When supervisor crashes - system cannot be accessed, nor rebooted nor diagnosed in any other way but via ssh

I wonder if Supervisor crash is just a symptom of a bigger issue. To me it sounds as if the system hangs completely on I/O or something.

What do you mean by system cannot be accessed? The Home Assistant Core frontend is also not available?

@RafAustralia
Copy link
Author

Hi Stefan.

Thank u so much for saying hi.

Its bizzare type of behaviour.
Initially we thought maybe u it was too hot (once) then we saw few vscode errors and we deleted it
It did not help. Or nor enough.

Still crashed.
When it crashes… no directories are available. No backups. Not reboot. No logs. No advanced logs. Just ssh only. So to me system fully crashed.
Supervisor could be restarted via ssh but it does not enable reboot from gui only safe mode if lucky.
So best way to reboot is ssh host reboot. Then it comes back.

Ive left it alone today. And I can say logs are all green. Nothing happened since 10pm last night.
But I had no chance to do anything. Just a busy day. Unit running on full auto.

When things happen often message relates to aiohttp or websocket.api or journald which all in all looks like a timeouts or rejections in connections.

Again its been ok today but we are wondering what could be causing these.

These crashes are extreme. Sudden. Unexpected.

Finally. Brand new ssd. Brand new haos. And restored backup. One crash pretty much straight after restore….

Ill try to give u any logs u need if u r interested trying to conquer this issue. Just ket me know which parts specifically would help u. I do have screenshots if crashes from the past if these help

I am once more very grateful.

Raf

@Failure404
Copy link

Failure404 commented Feb 6, 2025

I am getting the very same error on a supervised debian 12 installation with Hass 2025.2.0 and Supervisor 2025.2.0.

Additionally I get another random occuring error since Supervisor 2025.2.0. I can't tell what triggers the error since it happens in intervals of 5 minutes to several hours and I don't think it is related to logs, but might be related to a bigger problem.

Today, even the whole system rebooted itself after it apparently crashed - I've never seen that before. I can't find anything suspicious in any log, except the OP's error and the one below coming from Supervisor.

Exception ignored in: <http.client.HTTPResponse object at 0x7f5f07f31b70>
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/http/client.py", line 432, in close
    super().close() # set "closed" flag
  File "/usr/local/lib/python3.13/http/client.py", line 445, in flush
    self.fp.flush()
ValueError: I/O operation on closed file.

@RafAustralia
Copy link
Author

Can you share the host logs of that system as well?

When supervisor crashes - system cannot be accessed, nor rebooted nor diagnosed in any other way but via ssh

I wonder if Supervisor crash is just a symptom of a bigger issue. To me it sounds as if the system hangs completely on I/O or something.

What do you mean by system cannot be accessed? The Home Assistant Core frontend is also not available?

.........................................................................................................................................................................

First crash since rebuild...
benign task... was creating a theme... half way through it - it decided to crash....

throughts?

application
2025-02-11 07:13:56.034 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/aiohttp/client_proto.py", line 92, in connection_lost
    uncompleted = self._parser.feed_eof()
  File "aiohttp/_http_parser.pyx", line 508, in aiohttp._http_parser.HttpParser.feed_eof
aiohttp.http_exceptions.TransferEncodingError: 400, message:
  Not enough data for satisfy transfer length header.
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/aiohttp/web_protocol.py", line 480, in _handle_request
    resp = await request_handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/web_app.py", line 569, in _handle
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/web_middlewares.py", line 117, in impl
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/middleware/security.py", line 199, in block_bad_requests
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/middleware/security.py", line 215, in system_validation
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/middleware/security.py", line 285, in token_validation
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/middleware/security.py", line 298, in core_proxy
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/utils.py", line 108, in wrap_api
    msg_data = await method(api, *args, **kwargs)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/host.py", line 279, in advanced_logs
    return await self.advanced_logs_handler(request, identifier, follow)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/host.py", line 257, in advanced_logs_handler
    async for cursor, line in journal_logs_reader(resp, log_formatter):
    ...<9 lines>...
            await response.write(line.encode("utf-8") + b"\n")
  File "/usr/src/supervisor/supervisor/utils/systemd_journal.py", line 80, in journal_logs_reader
    line = await resp.content.readuntil(b"\n")
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/streams.py", line 386, in readuntil
    await self._wait("readuntil")
  File "/usr/local/lib/python3.13/site-packages/aiohttp/streams.py", line 347, in _wait
    await waiter
aiohttp.client_exceptions.ClientPayloadError: Response payload is not completed: <TransferEncodingError: 400, message='Not enough data for satisfy transfer length header.'>
2025-02-11 07:13:56.036 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/aiohttp/client_proto.py", line 92, in connection_lost
    uncompleted = self._parser.feed_eof()
  File "aiohttp/_http_parser.pyx", line 508, in aiohttp._http_parser.HttpParser.feed_eof
aiohttp.http_exceptions.TransferEncodingError: 400, message:
  Not enough data for satisfy transfer length header.
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/aiohttp/web_protocol.py", line 480, in _handle_request
    resp = await request_handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/web_app.py", line 569, in _handle
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/web_middlewares.py", line 117, in impl
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/middleware/security.py", line 199, in block_bad_requests
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/middleware/security.py", line 215, in system_validation
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/middleware/security.py", line 285, in token_validation
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/middleware/security.py", line 298, in core_proxy
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/utils.py", line 108, in wrap_api
    msg_data = await method(api, *args, **kwargs)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/host.py", line 279, in advanced_logs
    return await self.advanced_logs_handler(request, identifier, follow)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/host.py", line 257, in advanced_logs_handler
    async for cursor, line in journal_logs_reader(resp, log_formatter):
    ...<9 lines>...
            await response.write(line.encode("utf-8") + b"\n")
  File "/usr/src/supervisor/supervisor/utils/systemd_journal.py", line 80, in journal_logs_reader
    line = await resp.content.readuntil(b"\n")
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/streams.py", line 386, in readuntil
    await self._wait("readuntil")
  File "/usr/local/lib/python3.13/site-packages/aiohttp/streams.py", line 347, in _wait
    await waiter
aiohttp.client_exceptions.ClientPayloadError: Response payload is not completed: <TransferEncodingError: 400, message='Not enough data for satisfy transfer length header.'>
2025-02-11 07:13:56.038 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/aiohttp/client_proto.py", line 92, in connection_lost
    uncompleted = self._parser.feed_eof()
  File "aiohttp/_http_parser.pyx", line 508, in aiohttp._http_parser.HttpParser.feed_eof
aiohttp.http_exceptions.TransferEncodingError: 400, message:
  Not enough data for satisfy transfer length header.
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/aiohttp/web_protocol.py", line 480, in _handle_request
    resp = await request_handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/web_app.py", line 569, in _handle
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/web_middlewares.py", line 117, in impl
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/middleware/security.py", line 199, in block_bad_requests
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/middleware/security.py", line 215, in system_validation
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/middleware/security.py", line 285, in token_validation
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/middleware/security.py", line 298, in core_proxy
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/utils.py", line 108, in wrap_api
    msg_data = await method(api, *args, **kwargs)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/host.py", line 279, in advanced_logs
    return await self.advanced_logs_handler(request, identifier, follow)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/host.py", line 257, in advanced_logs_handler
    async for cursor, line in journal_logs_reader(resp, log_formatter):
    ...<9 lines>...
            await response.write(line.encode("utf-8") + b"\n")
  File "/usr/src/supervisor/supervisor/utils/systemd_journal.py", line 80, in journal_logs_reader
    line = await resp.content.readuntil(b"\n")
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/streams.py", line 386, in readuntil
    await self._wait("readuntil")
  File "/usr/local/lib/python3.13/site-packages/aiohttp/streams.py", line 347, in _wait
    await waiter
aiohttp.client_exceptions.ClientPayloadError: Response payload is not completed: <TransferEncodingError: 400, message='Not enough data for satisfy transfer length header.'>
s6-rc: info: service legacy-services: stopping
2025-02-11 07:13:56.093 INFO (MainThread) [supervisor.misc.scheduler] Shutting down scheduled tasks
2025-02-11 07:13:56.093 INFO (MainThread) [supervisor.docker.monitor] Stopped docker events monitor
2025-02-11 07:13:56.093 INFO (MainThread) [supervisor.api] Stopping API on 172.30.32.2
[21:13:56] INFO: Watchdog restart after closing

@RafAustralia
Copy link
Author

has anyone had any more success with all of this? this post has gone quiet....

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

No branches or pull requests

3 participants