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

Live Log Issues Through Reverse Proxies #5509

Open
DanGarion opened this issue Dec 23, 2024 · 16 comments · May be fixed by #5544
Open

Live Log Issues Through Reverse Proxies #5509

DanGarion opened this issue Dec 23, 2024 · 16 comments · May be fixed by #5544
Labels

Comments

@DanGarion
Copy link

Describe the issue you are experiencing

I'm using a reverse proxy to access HA (SWAG). I use the basic config for nginx that they provide and have made no edits over the past year. After an update approximately 2 months ago (I think having to do with Live logs) I can only see live logs when I'm using my server IP or internal network URL. When I try to access the "live" logs for anything HA related (including Addons) I only see "Loading full log..."
image

One note: I can download the logs if I use the download icon, and I also have access to them if I install the Portainer add-on and review them from Portainer.

An additional note this happens in multiple browsers and on my multiple devices and the issue occurs when accessing logs through the HA Android App as well.

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. Access HA through a reverse proxy
  2. Go to System > Logs > Change to Supervisor
  3. Logs will NOT load and will eventually time out, displaying the following.
    image

If I access HA though a direct IP or internal network URL the live logs are accessible.
...

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

2024-12-23 15:36:21.201 INFO (MainThread) [supervisor.homeassistant.api] Updated Home Assistant API token
2024-12-23 15:39:39.504 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 261, in advanced_logs_handler
    await response.prepare(request)
  File "/usr/local/lib/python3.12/site-packages/aiohttp/web_response.py", line 453, in prepare
    return await self._start(request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohttp/web_response.py", line 461, in _start
    await self._write_headers()
  File "/usr/local/lib/python3.12/site-packages/aiohttp/web_response.py", line 538, in _write_headers
    await writer.write_headers(status_line, self._headers)
  File "/usr/local/lib/python3.12/site-packages/aiohttp/http_writer.py", line 148, in write_headers
    self._write(buf)
  File "/usr/local/lib/python3.12/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(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/supervisor/supervisor/api/host.py", line 268, in advanced_logs_handler
    raise APIError(
supervisor.exceptions.APIError: Connection reset when trying to fetch data from systemd-journald.

System Health information

System Information

version core-2024.12.5
installation_type Home Assistant OS
dev false
hassio true
docker true
user root
virtualenv false
python_version 3.13.0
os_name Linux
os_version 6.6.66-haos
arch x86_64
timezone America/Los_Angeles
config_dir /config
Home Assistant Community Store
GitHub API ok
GitHub Content ok
GitHub Web ok
HACS Data ok
GitHub API Calls Remaining 5000
Installed Version 2.0.1
Stage running
Available Repositories 1559
Downloaded Repositories 27
Home Assistant Cloud
logged_in true
subscription_expiration August 23, 2025 at 5:00 PM
relayer_connected true
relayer_region us-east-1
remote_enabled true
remote_connected true
alexa_enabled false
google_enabled true
cloud_ice_servers_enabled true
remote_server us-east-1-10.ui.nabu.casa
certificate_status ready
instance_id 8f8637b1554c48ba826c50b7c9d5f835
can_reach_cert_server ok
can_reach_cloud_auth ok
can_reach_cloud ok
Home Assistant Supervisor
host_os Home Assistant OS 14.1
update_channel stable
supervisor_version supervisor-2024.12.0
agent_version 1.6.0
docker_version 27.2.0
disk_total 916.9 GB
disk_used 71.7 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_addons Matter Server (6.6.1), Mosquitto broker (6.4.1), ESPHome Device Builder (2024.12.2), Advanced SSH & Web Terminal (19.0.0), Studio Code Server (5.17.3), Plex Media Server (3.6.2), Portainer (2.25.1), Log Viewer (0.17.1), Govee to MQTT Bridge (2024.07.13-82ddc6e9), SQLite Web (4.3.0), Home Assistant Google Drive Backup (0.112.1), Music Assistant Server (beta) (2.4.0b8), Samba share (12.3.2), Z-Wave JS UI (3.18.0), Homebridge (0.1.8), Frigate Beta (0.15.0-beta4)
Dashboards
dashboards 7
resources 42
views 14
mode storage
Recorder
oldest_recorder_run December 11, 2024 at 6:23 PM
current_recorder_run December 23, 2024 at 1:41 PM
estimated_db_size 936.47 MiB
database_engine sqlite
database_version 3.45.3
Sonoff
version 3.8.1 (ffa7e22)
cloud_online 8 / 9
local_online 8 / 8
Spotify
api_endpoint_reachable ok
SpotifyPlus
integration_version v1.0.75
clients_configured 1: Daniel Schoonover (premium)
api_endpoint_reachable ok

Supervisor diagnostics

config_entry-hassio-01JDDQTE6MBNXC3KSBH487VZ35.json

Additional information

No response

@DanGarion DanGarion added the bug label Dec 23, 2024
@amordicus
Copy link

amordicus commented Dec 25, 2024

I have the same problem since 2024.12.0, and most likely related to live log. And very often I don't see the hidden menu (the 3 vertical dots) when in system->logs. When using companion, the logs are displayed, but the 3 dots (the menu to Show HAOS startups) are not.

Strangely, when in a browser while getting the dreadful "Loading full log..." the menu "Show HAOS startups" (the 3 dots) is accessible.

More info:

@agners
Copy link
Member

agners commented Dec 30, 2024

The log requests are long running HTTP requests, but typically proxies should handle them transparently. We do use a somewhat special request header Range, so in case your proxy filters request headers that might be a problem as well. But other than that, not sure why a reverse proxy would lead to such problems.

FWIW, on my test setup with the NGINX Home Assistant SSL proxy add-on (which acts as a reverse proxy too), the new logs are displayed correctly and actively followed just fine.

@DanGarion
Copy link
Author

I'm just as stumped with this. What is really strange is that if I try to access the logs for Frigate it hangs, but then if I launch the Frigate UI and then go back to access/load the logs for Frigate it comes up. None of the other addons do that. I guess I'll just need to live with only being able to access the logs when I'm local.

@elcajon
Copy link

elcajon commented Dec 30, 2024

I'm not sure if it fits thematically or is a separate issue, but the live logs also don't work via Cloudflare DNS Proxy (specifically Cloudflare Tunnel, which acts as reverse proxy as well).

brenner-tobias/addon-cloudflared#744

@UplandJacob
Copy link

UplandJacob commented Jan 3, 2025

I'm not sure if it fits thematically or is a separate issue, but the live logs also don't work via Cloudflare DNS Proxy (specifically Cloudflare Tunnel, which acts as reverse proxy as well).

Same here, but it also (inconsistently) doesn't work with the internal homeassistant.local:8123 url.

Most of the time when it doesn't work it's when I hit the reload button; it will say "Failed to get someaddon logs, Load failed". Sometimes it did load the logs, just didn't continue to update; sometimes doesn't update at all.

@nonameboy007
Copy link

Same problem for me:

https://community.home-assistant.io/t/live-logs-and-reverse-proxy/801448

between local and outside url:

it’s look like that the follow function using this URL:

WEBSITEFQN/api/hassio/addons/a0d7b954_grafana/logs/follow?lines=100
but im using
WEBSITEFQN/hassio/addon/a0d7b954_grafana/logs

any clue?

@amordicus
Copy link

Log doesn't work when using the addon ZeroTier by Franck Nijhof. @agners to reproduce the problem, one could start with that in a very simple setup perhaps.

@MRobi1
Copy link

MRobi1 commented Jan 6, 2025

I had previously posted my issue here

My setup is pretty straight forward. Cloudflare hosts my FQDN, NPM running internally to point to HA.

If I access the logs via the internal IP, they work.
I setup a local domain in NPM to test, and when using hass.test, they work
But when I access via my external domain, no logs.

So for fun I logged into cloudflare, and changed the proxy status from proxied, to DNS only.
image
Logs work! Going back to proxied, no more logs.

So my hunch here is that this has something to do with Cloudflare and not necessarily the fact that it's through a reverse proxy.

@zelch
Copy link

zelch commented Jan 11, 2025

Alright, so, I figured out the cause when it's a nginx reverse proxy: Buffering.

But importantly, setting proxy_request_buffering off; is insufficient.

You need proxy_buffering off; instead.

I'm not sure that HA can do much about it except for documenting it, and explicitly calling it out as a possibility when getting the log fails in a manner consistent with proxy buffering screwing things up.

Well, barring solutions that replace the live log streaming with some other method of transit aside from an unending chunked stream.

For those of you following from home, the very short version of the problem is that nginx is trying to read the entire response before it sends the response off to the client, and this works fine the vast majority of the time. Except live logs are sent in chunks, with more chunks coming over time as more log lines come in.

There will never be an 'end' to those chunks, and so the response never finishes... And at best nginx sends some of the data after a significant delay.

I strongly suspect that Cloudflare's proxy is doing exactly the same thing, expecting the response to come to an end, and not bothering to send chunks to the client until it does.

Reading through the nginx reverse proxy code, it definitely attempts to handle this case correctly, so this feels to be, at least in part, like an nginx bug.

But I'd have to spend a lot more time debugging to figure out what's going on with nginx.

@agners
Copy link
Member

agners commented Jan 11, 2025

Nice find! I wonder why my tests with the add-on didn't show the problem 🤔. I'll have to retest again and check the options set in the add-on.

It does seem there is the X-Accel-Buffering header we could set to prevent buffering by default (see http://nginx.org/en/docs/http/ngx_http_proxy_module.html#proxy_buffering). I'll look into that next week.

@othorp
Copy link

othorp commented Jan 11, 2025

Please consider changing the Content-Type for these live-log responses to fix cloudflare proxies - see discussion at: cloudflare/cloudflared#199.

The combination of the response headers recommended at https://developer.mozilla.org/en-US/docs/Web/API/Server-sent_events/Using_server-sent_events#sending_events_from_the_server might do the trick:

X-Accel-Buffering: no
Content-Type: text/event-stream
Cache-Control: no-cache

The first should fix NGINX per the discussion above.
The second seems to stop buffering in cloudflared.

@agners
Copy link
Member

agners commented Jan 11, 2025

But this are not SSEs, that would be the wrong MIME type for this content...

@othorp
Copy link

othorp commented Jan 11, 2025

Nonetheless, it does seem to work. I'm testing with nginx in front of cloudflared tunnel. Live logs are now working without having to translate the content-type back again on the Cloudflare side. My test config through NGINX Proxy Manager is shown below:

nginx rewrite

@DanGarion
Copy link
Author

Alright, so, I figured out the cause when it's a nginx reverse proxy: Buffering.

But importantly, setting proxy_request_buffering off; is insufficient.

You need proxy_buffering off; instead.

I'm not sure that HA can do much about it except for documenting it, and explicitly calling it out as a possibility when getting the log fails in a manner consistent with proxy buffering screwing things up.

Well, barring solutions that replace the live log streaming with some other method of transit aside from an unending chunked stream.

For those of you following from home, the very short version of the problem is that nginx is trying to read the entire response before it sends the response off to the client, and this works fine the vast majority of the time. Except live logs are sent in chunks, with more chunks coming over time as more log lines come in.

There will never be an 'end' to those chunks, and so the response never finishes... And at best nginx sends some of the data after a significant delay.

I strongly suspect that Cloudflare's proxy is doing exactly the same thing, expecting the response to come to an end, and not bothering to send chunks to the client until it does.

Reading through the nginx reverse proxy code, it definitely attempts to handle this case correctly, so this feels to be, at least in part, like an nginx bug.

But I'd have to spend a lot more time debugging to figure out what's going on with nginx.

I assumed it was probably something like this! Great find.

@agners
Copy link
Member

agners commented Jan 13, 2025

Alright, so, I figured out the cause when it's a nginx reverse proxy: Buffering.

But importantly, setting proxy_request_buffering off; is insufficient.

You need proxy_buffering off; instead.

So in an attempt trying to reproduce this here, I looked into the configuration of the NGINX add-on again. Live logs indeed seem to work fine, but I then noticed that buffering is disabled by default:

https://github.com/home-assistant/addons/blob/7678e871a4d4786b55e940963fffecc5ced909e4/nginx_proxy/rootfs/etc/nginx/nginx.conf.gtpl#L79

However, even after removing that setting in a local test (and explicitly set it to on), live logs seem to work just fine here. I can open a add-on log, and when new logs get posted by the add-on, they appear immediately.

It seems there is some other component contributing to this. Maybe some of the other configuration options influence the behavior?

@agners
Copy link
Member

agners commented Jan 13, 2025

Ok, I found the culprit why I wasn't able to reproduce: The NGINX add-on config also sets http2 on. It seems that using HTTP/2 sort of bypasses buffering as well 🤷

So, without http2, and no proxy_buffering or proxy_buffering: on, I was able to reproduce the problem. Furthermore, at least for NGINX, using X-Accel-Buffering: no as response header seems to make the streaming logs work again. So I'll add that header to the Supervisor response to support non-http2 configs.

@agners agners linked a pull request Jan 13, 2025 that will close this issue
14 tasks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

10 participants