Supervisor Logs Extremely Slow to Open

Veldkornet · October 6, 2021, 9:09am

For the last month or 2/3, looking at any of the logs in Supervisor or the containers take EXTREMELY long, where they used to be instant.

Anyone lese have this problem?

System Health

version	core-2021.9.7
installation_type	Home Assistant OS
dev	false
hassio	true
docker	true
user	root
virtualenv	false
python_version	3.9.7
os_name	Linux
os_version	5.10.17-v8
arch	aarch64
timezone	Europe/Amsterdam

Home Assistant Community Store

GitHub API	ok
Github API Calls Remaining	4675
Installed Version	1.15.2
Stage	running
Available Repositories	898
Installed Repositories	36

Home Assistant Cloud

logged_in	true
subscription_expiration	20 October 2021, 2:00
relayer_connected	true
remote_enabled	true
remote_connected	true
alexa_enabled	false
google_enabled	false
can_reach_cert_server	ok
can_reach_cloud_auth	ok
can_reach_cloud	ok

Home Assistant Supervisor

host_os	Home Assistant OS 6.4
update_channel	stable
supervisor_version	supervisor-2021.09.6
docker_version	20.10.7
disk_total	228.5 GB
disk_used	12.2 GB
healthy	true
supported	true
board	rpi4-64
supervisor_api	ok
version_api	ok
installed_addons	Samba share (9.5.1), Node-RED (10.0.1), Log Viewer (0.12.0), SSH & Web Terminal (9.0.1), Portainer (2.0.0), Visual Studio Code (3.6.2), InfluxDB (4.2.1), Grafana (7.2.0), Syncthing (1.18.3), ESPHome (2021.9.2), Glances (0.13.0), chrony (2.2.0), Mosquitto broker (6.0.1), File editor (5.3.3), Duck DNS (1.14.0), ArgonOne Active Cooling (24.1), Vaultwarden (Bitwarden) (0.13.0), AdGuard Home (4.1.9), Z-Wave JS (0.1.45)

Lovelace

dashboards	2
resources	17
views	12
mode	storage

Spotify

api_endpoint_reachable	ok

You can see here below that it took 1.2 minutes before the logs showed:

I do see some of these error messages in the console, unclear if it’s related:

entrypoint.b658878e.js:16479 Uncaught (in promise) {code: 'unknown_error', message: ''}

Full message:

content.js:4 [Deprecation] chrome.loadTimes() is deprecated, instead use standardized API: nextHopProtocol in Navigation Timing 2. https://www.chromestatus.com/features/5637885046816768.
(anonymous) @ content.js:4
content.js:5 [Deprecation] chrome.loadTimes() is deprecated, instead use standardized API: nextHopProtocol in Navigation Timing 2. https://www.chromestatus.com/features/5637885046816768.
(anonymous) @ content.js:5
app.f08a72d3.js:5264 The main 'lit-element' module entrypoint is deprecated. Please update your imports to use the 'lit' package: 'lit' and 'lit/decorators.ts' or import from 'lit-element/lit-element.ts'.
55704 @ app.f08a72d3.js:5264
s @ app.f08a72d3.js:30632
53918 @ app.f08a72d3.js:1290
s @ app.f08a72d3.js:30632
(anonymous) @ app.f08a72d3.js:30632
(anonymous) @ app.f08a72d3.js:36741
(anonymous) @ app.f08a72d3.js:36741
entrypoint.b658878e.js:38000 The main 'lit-element' module entrypoint is deprecated. Please update your imports to use the 'lit' package: 'lit' and 'lit/decorators.ts' or import from 'lit-element/lit-element.ts'.
5704 @ entrypoint.b658878e.js:38000
s @ entrypoint.b658878e.js:73826
4552 @ entrypoint.b658878e.js:65175
s @ entrypoint.b658878e.js:73826
1625 @ entrypoint.b658878e.js:72024
s @ entrypoint.b658878e.js:73826
7714 @ entrypoint.b658878e.js:6216
s @ entrypoint.b658878e.js:73826
(anonymous) @ entrypoint.b658878e.js:73826
(anonymous) @ entrypoint.b658878e.js:73826
entrypoint.b658878e.js:16479 Uncaught (in promise) {code: 'unknown_error', message: ''}
value @ entrypoint.b658878e.js:16479
async function (async)
value @ entrypoint.b658878e.js:16479
value @ entrypoint.b658878e.js:16479
_$AE @ entrypoint.b658878e.js:21033
performUpdate @ entrypoint.b658878e.js:21033
_$EC @ entrypoint.b658878e.js:21033
async function (async)
_$EC @ entrypoint.b658878e.js:21033
requestUpdate @ entrypoint.b658878e.js:21033
o @ entrypoint.b658878e.js:21033
b @ entrypoint.b658878e.js:21033
p @ entrypoint.b658878e.js:38000
F @ entrypoint.b658878e.js:16233
p @ entrypoint.b658878e.js:38000
T @ entrypoint.b658878e.js:38000
_$AI @ entrypoint.b658878e.js:38000
I @ entrypoint.b658878e.js:38000
update @ entrypoint.b658878e.js:38000
performUpdate @ entrypoint.b658878e.js:21033
_$EC @ entrypoint.b658878e.js:21033
async function (async)
_$EC @ entrypoint.b658878e.js:21033
requestUpdate @ entrypoint.b658878e.js:21033
o @ entrypoint.b658878e.js:21033
b @ entrypoint.b658878e.js:21033
p @ entrypoint.b658878e.js:38000
F @ entrypoint.b658878e.js:16971
value @ entrypoint.b658878e.js:72201
value @ entrypoint.b658878e.js:72201
value @ entrypoint.b658878e.js:72201
performUpdate @ entrypoint.b658878e.js:21033
_$EC @ entrypoint.b658878e.js:21033
async function (async)
_$EC @ entrypoint.b658878e.js:21033
requestUpdate @ entrypoint.b658878e.js:21033
o @ entrypoint.b658878e.js:21033
b @ entrypoint.b658878e.js:21033
r @ entrypoint.b658878e.js:72201
F @ entrypoint.b658878e.js:17118
p @ entrypoint.b658878e.js:38000
T @ entrypoint.b658878e.js:38000
_$AI @ entrypoint.b658878e.js:38000
I @ entrypoint.b658878e.js:38000
update @ entrypoint.b658878e.js:38000
performUpdate @ entrypoint.b658878e.js:21033
_$EC @ entrypoint.b658878e.js:21033
async function (async)
_$EC @ entrypoint.b658878e.js:21033
requestUpdate @ entrypoint.b658878e.js:21033
set @ entrypoint.b658878e.js:21033
value @ entrypoint.b658878e.js:17351
value @ entrypoint.b658878e.js:72201
performUpdate @ entrypoint.b658878e.js:21033
_$EC @ entrypoint.b658878e.js:21033
async function (async)
_$EC @ entrypoint.b658878e.js:21033
requestUpdate @ entrypoint.b658878e.js:21033
set @ entrypoint.b658878e.js:21033
P @ entrypoint.b658878e.js:38000
_$AI @ entrypoint.b658878e.js:38000
m @ entrypoint.b658878e.js:38000
T @ entrypoint.b658878e.js:38000
_$AI @ entrypoint.b658878e.js:38000
I @ entrypoint.b658878e.js:38000
update @ entrypoint.b658878e.js:38000
performUpdate @ entrypoint.b658878e.js:21033
_$EC @ entrypoint.b658878e.js:21033
async function (async)
_$EC @ entrypoint.b658878e.js:21033
requestUpdate @ entrypoint.b658878e.js:21033
set @ entrypoint.b658878e.js:21033
value @ entrypoint.b658878e.js:17351
(anonymous) @ entrypoint.b658878e.js:17351
r @ entrypoint.b658878e.js:38000
(anonymous) @ entrypoint.b658878e.js:38000
Promise.then (async)
l @ entrypoint.b658878e.js:38000
c @ entrypoint.b658878e.js:38000
subscribe @ entrypoint.b658878e.js:38000
value @ entrypoint.b658878e.js:17351
value @ entrypoint.b658878e.js:17351
_$AE @ entrypoint.b658878e.js:21033
performUpdate @ entrypoint.b658878e.js:21033
_$EC @ entrypoint.b658878e.js:21033
async function (async)
_$EC @ entrypoint.b658878e.js:21033
requestUpdate @ entrypoint.b658878e.js:21033
o @ entrypoint.b658878e.js:21033
b @ entrypoint.b658878e.js:21033
p @ entrypoint.b658878e.js:38000
(anonymous) @ entrypoint.b658878e.js:17351
ws @ entrypoint.b658878e.js:17351
r @ entrypoint.b658878e.js:17351
r @ entrypoint.b658878e.js:17351
finisher @ entrypoint.b658878e.js:21033
runClassFinishers @ entrypoint.b658878e.js:17351
(anonymous) @ entrypoint.b658878e.js:17351
7714 @ entrypoint.b658878e.js:17351
s @ entrypoint.b658878e.js:73826
(anonymous) @ entrypoint.b658878e.js:73826
(anonymous) @ entrypoint.b658878e.js:73826
entrypoint.b658878e.js:15543 Uncaught (in promise) {code: 'unknown_error', message: ''}
value @ entrypoint.b658878e.js:15543
async function (async)
value @ entrypoint.b658878e.js:15543
value @ entrypoint.b658878e.js:15543
_$AE @ entrypoint.b658878e.js:21033
performUpdate @ entrypoint.b658878e.js:21033
_$EC @ entrypoint.b658878e.js:21033
async function (async)
_$EC @ entrypoint.b658878e.js:21033
requestUpdate @ entrypoint.b658878e.js:21033
o @ entrypoint.b658878e.js:21033
b @ entrypoint.b658878e.js:21033
p @ entrypoint.b658878e.js:38000
F @ entrypoint.b658878e.js:15386
p @ entrypoint.b658878e.js:38000
T @ entrypoint.b658878e.js:38000
_$AI @ entrypoint.b658878e.js:38000
I @ entrypoint.b658878e.js:38000
update @ entrypoint.b658878e.js:38000
performUpdate @ entrypoint.b658878e.js:21033
_$EC @ entrypoint.b658878e.js:21033
async function (async)
_$EC @ entrypoint.b658878e.js:21033
requestUpdate @ entrypoint.b658878e.js:21033
o @ entrypoint.b658878e.js:21033
b @ entrypoint.b658878e.js:21033
p @ entrypoint.b658878e.js:38000
F @ entrypoint.b658878e.js:16971
value @ entrypoint.b658878e.js:72201
value @ entrypoint.b658878e.js:72201
value @ entrypoint.b658878e.js:72201
performUpdate @ entrypoint.b658878e.js:21033
_$EC @ entrypoint.b658878e.js:21033
async function (async)
_$EC @ entrypoint.b658878e.js:21033
requestUpdate @ entrypoint.b658878e.js:21033
o @ entrypoint.b658878e.js:21033
b @ entrypoint.b658878e.js:21033
r @ entrypoint.b658878e.js:72201
F @ entrypoint.b658878e.js:17118
p @ entrypoint.b658878e.js:38000
T @ entrypoint.b658878e.js:38000
_$AI @ entrypoint.b658878e.js:38000
I @ entrypoint.b658878e.js:38000
update @ entrypoint.b658878e.js:38000
performUpdate @ entrypoint.b658878e.js:21033
_$EC @ entrypoint.b658878e.js:21033
async function (async)
_$EC @ entrypoint.b658878e.js:21033
requestUpdate @ entrypoint.b658878e.js:21033
set @ entrypoint.b658878e.js:21033
value @ entrypoint.b658878e.js:17351
value @ entrypoint.b658878e.js:72201
performUpdate @ entrypoint.b658878e.js:21033
_$EC @ entrypoint.b658878e.js:21033
async function (async)
_$EC @ entrypoint.b658878e.js:21033
requestUpdate @ entrypoint.b658878e.js:21033
set @ entrypoint.b658878e.js:21033
P @ entrypoint.b658878e.js:38000
_$AI @ entrypoint.b658878e.js:38000
m @ entrypoint.b658878e.js:38000
T @ entrypoint.b658878e.js:38000
_$AI @ entrypoint.b658878e.js:38000
I @ entrypoint.b658878e.js:38000
update @ entrypoint.b658878e.js:38000
performUpdate @ entrypoint.b658878e.js:21033
_$EC @ entrypoint.b658878e.js:21033
async function (async)
_$EC @ entrypoint.b658878e.js:21033
requestUpdate @ entrypoint.b658878e.js:21033
set @ entrypoint.b658878e.js:21033
value @ entrypoint.b658878e.js:17351
(anonymous) @ entrypoint.b658878e.js:17351
r @ entrypoint.b658878e.js:38000
(anonymous) @ entrypoint.b658878e.js:38000
Promise.then (async)
l @ entrypoint.b658878e.js:38000
c @ entrypoint.b658878e.js:38000
subscribe @ entrypoint.b658878e.js:38000
value @ entrypoint.b658878e.js:17351
value @ entrypoint.b658878e.js:17351
_$AE @ entrypoint.b658878e.js:21033
performUpdate @ entrypoint.b658878e.js:21033
_$EC @ entrypoint.b658878e.js:21033
async function (async)
_$EC @ entrypoint.b658878e.js:21033
requestUpdate @ entrypoint.b658878e.js:21033
o @ entrypoint.b658878e.js:21033
b @ entrypoint.b658878e.js:21033
p @ entrypoint.b658878e.js:38000
(anonymous) @ entrypoint.b658878e.js:17351
ws @ entrypoint.b658878e.js:17351
r @ entrypoint.b658878e.js:17351
r @ entrypoint.b658878e.js:17351
finisher @ entrypoint.b658878e.js:21033
runClassFinishers @ entrypoint.b658878e.js:17351
(anonymous) @ entrypoint.b658878e.js:17351
7714 @ entrypoint.b658878e.js:17351
s @ entrypoint.b658878e.js:73826
(anonymous) @ entrypoint.b658878e.js:73826
(anonymous) @ entrypoint.b658878e.js:73826

francisp · October 6, 2021, 9:12am

Running HA OS or HA Supervised ?

Veldkornet · October 6, 2021, 9:14am

I’m running HA OS

francisp · October 6, 2021, 9:15am

So it is on issue on both HA OS and HA Supervised.

Veldkornet · October 6, 2021, 9:22am

I did find Supervisor issues 3014 and 3076 on Github

MaxW · October 6, 2021, 12:06pm

developing some addon currently and this drives me insane! Luckily i am not the only one…

Routout · October 9, 2021, 5:56pm

Same problem here. Also Android app UI is extremely laggy.

MaxW · October 13, 2021, 1:11pm

I switched from hassio to debian 11 and it is fast as new
Backup / Restore works great and took me nearly no work.

https://community.home-assistant.io/t/installing-home-assistant-supervised-on-a-raspberry-pi-with-debian-11/

MaxW · October 19, 2021, 10:55am

After one week it is slow and unuseable again.

johnboiles · November 3, 2021, 6:53pm

I’ve seen the same things since earlier this year on HASSOS. Here’s some example request timings when loading the logs:

endpoint	time
`/api/hassio/addons/core_check_config/logs`	24.75s
`/api/hassio/supervisor/logs`	8.758s
`/api/hassio/addons/a0d7b954_zwavejs2mqtt/logs`	25.777s

I’m on a Pi4 + USB3 SSD. In the past, logs would load in no more than a couple seconds (not enough to notice or think about). My HA instance is generally snappy and responsive.

MaxW · November 9, 2021, 1:33pm

so, this drove me absolutely nuts, but i guess I found a solution this time!

After some reading I found that my USB3 SATA Adapter was not the one I thought I bought. Seems like Amazon.de send out different on the same name.

I bought this: Amazon.de
And it seems to exist as 174c:55aa and (like mine): 174c:235c

hdparm showed me extremely low values. After disabling UAS I now get this:

root@homeassistant:/usr/share/hassio/share# hdparm -t /dev/sda

/dev/sda:
 Timing buffered disk reads: 542 MB in  3.00 seconds = 180.64 MB/sec

And for a pretty cheap SSD with a full running system, this is totally fine.

Logs are fast as desired now <3

This helped me: STICKY: If you have a Raspberry Pi 4 and are getting bad speeds transferring data to/from USB3.0 SSDs, read this - Raspberry Pi Forums

Veldkornet · November 9, 2021, 8:30pm

I also have an SSD, and I checked the speeds with hdparm -t /dev/sda, I have not disabled UAS and I get the below:

Timing buffered disk reads:  637 MB in 3.15 seconds = 206.753 MB/s

My logs are all still extremely slow…

MaxW · November 9, 2021, 9:49pm

give disabling UAS a try?

habitoti · November 15, 2021, 9:02am

This might be a total silly question, but it seems I don’t have hdparm at all on my installation (Raspberry 4).
Also, I don’t have e.g. apt-get to install it. How can I install hdparm?

Veldkornet · November 15, 2021, 9:49am

I ran it by doing an SSH into the OS itself (port 22222).
Normal SSH goes into the HomeAssistant container.

Assuming you’re running HassOS…

habitoti · November 15, 2021, 2:05pm

This seems not to be possible on a Raspbian installation, at least remote. Might have to find an HDMI cable and boot it with keyboard & screen attached…

habitoti · November 15, 2021, 6:01pm

So booting with a screen & keyboard attached, I could run hdparm on the Raspberry installation. It says it read 716MB in 3 Seconds, which is ~250 MB/s. This should be more than sufficient, but as @Veldkornet wrote, it still feels much slower and less snappy than it did earlier…

alengwenus · November 16, 2021, 7:42pm

Disabling UAS as @MaxW mentioned solved the issue with the logs for me. Also restarting the core and loading of the history is much faster, now.

Veldkornet · November 16, 2021, 8:30pm

You’re right, the logs are fast again. Weird that my speeds didn’t seem to change though:

Timing buffered disk reads:  636 MB in 3.00 seconds = 217.004 MB/s

FYI, I have an Argon One M.2 with a Samsung M.2 SATA SSD and my cmdline.txt ended up looking like the below:

usb-storage.quirks=174c:55aa:u dwc_otg.lpm_enable=0 console=tty1

MaxW · November 17, 2021, 9:19pm

I might be wrong with the speed thing as proof, but I can recommend everyone with issues to try the UAS disabling thing.