ebaauw / homebridge-hue

Homebridge plugin for Philips Hue
Apache License 2.0
897 stars 91 forks source link

Warning GET / sensors #1109

Closed waterchill closed 1 year ago

waterchill commented 1 year ago

Good day,

I get every day a lot of this warnings. I have on deconz 3 aqara switches and 3 aqara temperature sensors. Setting the timeout to 30s doesn't help. Sometimes there is also a GET / lights warning.

Log Messages

[14/09/2022, 09:58:46] [Hue] rpi_hue: request 2884: timeout after 5 seconds [14/09/2022, 09:58:51] [Hue] rpi_hue: request 2885: GET /sensors [14/09/2022, 09:58:51] [Hue] rpi_hue: request 2885: timeout after 5 seconds [14/09/2022, 10:01:11] [Hue] rpi_hue: request 2940: GET /sensors [14/09/2022, 10:01:11] [Hue] rpi_hue: request 2940: timeout after 5 seconds [14/09/2022, 10:01:16] [Hue] rpi_hue: request 2941: GET /sensors [14/09/2022, 10:01:16] [Hue] rpi_hue: request 2941: timeout after 5 seconds [14/09/2022, 10:01:21] [Hue] rpi_hue: request 2942: GET /sensors [14/09/2022, 10:01:21] [Hue] rpi_hue: request 2942: timeout after 5 seconds [14/09/2022, 10:01:26] [Hue] rpi_hue: request 2943: GET /sensors [14/09/2022, 10:01:26] [Hue] rpi_hue: request 2943: timeout after 5 seconds [14/09/2022, 10:01:31] [Hue] rpi_hue: request 2944: GET /sensors [14/09/2022, 10:01:31] [Hue] rpi_hue: request 2944: timeout after 5 seconds [14/09/2022, 10:11:36] [Hue] rpi_hue: request 3185: GET /sensors [14/09/2022, 10:11:36] [Hue] rpi_hue: request 3185: timeout after 5 seconds [14/09/2022, 10:15:11] [Hue] rpi_hue: request 3270: GET /sensors [14/09/2022, 10:15:11] [Hue] rpi_hue: request 3270: timeout after 5 seconds [14/09/2022, 10:15:16] [Hue] rpi_hue: request 3271: GET /sensors [14/09/2022, 10:15:16] [Hue] rpi_hue: request 3271: timeout after 5 seconds [14/09/2022, 10:16:26] [Hue] rpi_hue: request 3298: GET /sensors [14/09/2022, 10:16:26] [Hue] rpi_hue: request 3298: timeout after 5 seconds [14/09/2022, 10:24:36] [Hue] rpi_hue: request 3493: GET /sensors [14/09/2022, 10:24:36] [Hue] rpi_hue: request 3493: timeout after 5 seconds [14/09/2022, 10:31:01] [Hue] rpi_hue: request 3646: GET /sensors [14/09/2022, 10:31:01] [Hue] rpi_hue: request 3646: timeout after 5 seconds [14/09/2022, 10:31:06] [Hue] rpi_hue: request 3647: GET /sensors [14/09/2022, 10:31:06] [Hue] rpi_hue: request 3647: timeout after 5 seconds [14/09/2022, 10:31:11] [Hue] rpi_hue: request 3648: GET /sensors [14/09/2022, 10:31:11] [Hue] rpi_hue: request 3648: timeout after 5 seconds [14/09/2022, 10:33:26] [Hue] rpi_hue: request 3701: GET /sensors [14/09/2022, 10:33:26] [Hue] rpi_hue: request 3701: timeout after 5 seconds [14/09/2022, 10:33:31] [Hue] rpi_hue: request 3702: GET /sensors [14/09/2022, 10:33:31] [Hue] rpi_hue: request 3702: timeout after 5 seconds [14/09/2022, 10:33:36] [Hue] rpi_hue: request 3703: GET /sensors [14/09/2022, 10:33:36] [Hue] rpi_hue: request 3703: timeout after 5 seconds [14/09/2022, 10:35:51] [Hue] rpi_hue: request 3756: GET /sensors [14/09/2022, 10:35:51] [Hue] rpi_hue: request 3756: timeout after 5 seconds [14/09/2022, 10:35:56] [Hue] rpi_hue: request 3757: GET /sensors [14/09/2022, 10:35:56] [Hue] rpi_hue: request 3757: timeout after 5 seconds [14/09/2022, 10:37:06] [Hue] rpi_hue: request 3784: GET /sensors [14/09/2022, 10:37:06] [Hue] rpi_hue: request 3784: timeout after 5 seconds [14/09/2022, 10:37:11] [Hue] rpi_hue: request 3785: GET /sensors [14/09/2022, 10:37:11] [Hue] rpi_hue: request 3785: timeout after 5 seconds [14/09/2022, 10:38:21] [Hue] rpi_hue: request 3812: GET /sensors [14/09/2022, 10:38:21] [Hue] rpi_hue: request 3812: timeout after 5 seconds [14/09/2022, 10:48:36] [Hue] rpi_hue: request 4057: GET /sensors [14/09/2022, 10:48:36] [Hue] rpi_hue: request 4057: timeout after 5 seconds [14/09/2022, 10:51:56] [Hue] rpi_hue: request 4136: GET /sensors [14/09/2022, 10:51:56] [Hue] rpi_hue: request 4136: timeout after 5 seconds [14/09/2022, 10:52:01] [Hue] rpi_hue: request 4137: GET /sensors [14/09/2022, 10:52:01] [Hue] rpi_hue: request 4137: timeout after 5 seconds [14/09/2022, 10:55:21] [Hue] rpi_hue: request 4216: GET /sensors [14/09/2022, 10:55:21] [Hue] rpi_hue: request 4216: timeout after 5 seconds [14/09/2022, 10:56:31] [Hue] rpi_hue: request 4243: GET /sensors [14/09/2022, 10:56:31] [Hue] rpi_hue: request 4243: timeout after 5 seconds [14/09/2022, 10:56:36] [Hue] rpi_hue: request 4244: GET /sensors [14/09/2022, 10:56:36] [Hue] rpi_hue: request 4244: timeout after 5 seconds [14/09/2022, 10:56:41] [Hue] rpi_hue: request 4245: GET /sensors [14/09/2022, 10:56:41] [Hue] rpi_hue: request 4245: timeout after 5 seconds [14/09/2022, 10:59:16] [Hue] rpi_hue: request 4306: GET /sensors [14/09/2022, 10:59:16] [Hue] rpi_hue: request 4306: timeout after 5 seconds [14/09/2022, 10:59:21] [Hue] rpi_hue: request 4307: GET /sensors [14/09/2022, 10:59:21] [Hue] rpi_hue: request 4307: timeout after 5 seconds [14/09/2022, 10:59:26] [Hue] rpi_hue: request 4308: GET /sensors [14/09/2022, 10:59:26] [Hue] rpi_hue: request 4308: timeout after 5 seconds [14/09/2022, 10:59:31] [Hue] rpi_hue: request 4309: GET /sensors [14/09/2022, 10:59:31] [Hue] rpi_hue: request 4309: timeout after 5 seconds [14/09/2022, 10:59:36] [Hue] rpi_hue: request 4310: GET /sensors [14/09/2022, 10:59:36] [Hue] rpi_hue: request 4310: timeout after 5 seconds [14/09/2022, 10:59:41] [Hue] rpi_hue: request 4311: GET /sensors [14/09/2022, 10:59:41] [Hue] rpi_hue: request 4311: timeout after 5 seconds [14/09/2022, 10:59:46] [Hue] rpi_hue: request 4312: GET /sensors [14/09/2022, 10:59:46] [Hue] rpi_hue: request 4312: timeout after 5 seconds [14/09/2022, 10:59:51] [Hue] rpi_hue: request 4313: GET /sensors [14/09/2022, 10:59:51] [Hue] rpi_hue: request 4313: timeout after 5 seconds [14/09/2022, 10:59:56] [Hue] rpi_hue: request 4314: GET /sensors [14/09/2022, 10:59:56] [Hue] rpi_hue: request 4314: timeout after 5 seconds [14/09/2022, 11:00:01] [Hue] rpi_hue: request 4315: GET /sensors [14/09/2022, 11:00:01] [Hue] rpi_hue: request 4315: timeout after 5 seconds [14/09/2022, 11:02:16] [Hue] rpi_hue: request 4368: GET /sensors [14/09/2022, 11:02:16] [Hue] rpi_hue: request 4368: timeout after 5 seconds [14/09/2022, 11:02:21] [Hue] rpi_hue: request 4369: GET /sensors [14/09/2022, 11:02:21] [Hue] rpi_hue: request 4369: timeout after 5 seconds [14/09/2022, 11:05:46] [Hue] rpi_hue: request 4450: GET /sensors [14/09/2022, 11:05:46] [Hue] rpi_hue: request 4450: timeout after 5 seconds [14/09/2022, 11:05:51] [Hue] rpi_hue: request 4451: GET /sensors [14/09/2022, 11:05:51] [Hue] rpi_hue: request 4451: timeout after 5 seconds [14/09/2022, 11:08:26] [Hue] rpi_hue: request 4512: GET /sensors [14/09/2022, 11:08:26] [Hue] rpi_hue: request 4512: timeout after 5 seconds [14/09/2022, 11:08:31] [Hue] rpi_hue: request 4513: GET /sensors [14/09/2022, 11:08:31] [Hue] rpi_hue: request 4513: timeout after 5 seconds [14/09/2022, 11:11:26] [Hue] rpi_hue: request 4582: GET /sensors [14/09/2022, 11:11:26] [Hue] rpi_hue: request 4582: timeout after 5 seconds [14/09/2022, 11:17:21] [Hue] rpi_hue: request 4723: GET /sensors [14/09/2022, 11:17:21] [Hue] rpi_hue: request 4723: timeout after 5 seconds [14/09/2022, 11:20:21] [Hue] rpi_hue: request 4794: GET /sensors [14/09/2022, 11:20:21] [Hue] rpi_hue: request 4794: timeout after 5 seconds [14/09/2022, 11:20:26] [Hue] rpi_hue: request 4795: GET /sensors [14/09/2022, 11:20:26] [Hue] rpi_hue: request 4795: timeout after 5 seconds [14/09/2022, 11:20:31] [Hue] rpi_hue: request 4796: GET /sensors [14/09/2022, 11:20:31] [Hue] rpi_hue: request 4796: timeout after 5 seconds [14/09/2022, 11:21:41] [Hue] rpi_hue: request 4823: GET /sensors [14/09/2022, 11:21:41] [Hue] rpi_hue: request 4823: timeout after 5 seconds [14/09/2022, 11:26:16] [Hue] rpi_hue: request 4932: GET /sensors [14/09/2022, 11:26:16] [Hue] rpi_hue: request 4932: timeout after 5 seconds [14/09/2022, 11:26:21] [Hue] rpi_hue: request 4933: GET /sensors [14/09/2022, 11:26:21] [Hue] rpi_hue: request 4933: timeout after 5 seconds [14/09/2022, 11:30:56] [Hue] rpi_hue: request 5042: GET /sensors [14/09/2022, 11:30:56] [Hue] rpi_hue: request 5042: timeout after 5 seconds [14/09/2022, 11:31:01] [Hue] rpi_hue: request 5043: GET /sensors [14/09/2022, 11:31:01] [Hue] rpi_hue: request 5043: timeout after 5 seconds [14/09/2022, 11:31:06] [Hue] rpi_hue: request 5044: GET /sensors [14/09/2022, 11:31:06] [Hue] rpi_hue: request 5044: timeout after 5 seconds [14/09/2022, 11:31:41] [Hue] rpi_hue: request 5057: GET /sensors [14/09/2022, 11:31:41] [Hue] rpi_hue: request 5057: timeout after 5 seconds [14/09/2022, 11:31:46] [Hue] rpi_hue: request 5058: GET /sensors [14/09/2022, 11:31:46] [Hue] rpi_hue: request 5058: timeout after 5 seconds [14/09/2022, 11:33:21] [Hue] rpi_hue: request 5095: GET /sensors [14/09/2022, 11:33:21] [Hue] rpi_hue: request 5095: timeout after 5 seconds [14/09/2022, 11:33:26] [Hue] rpi_hue: request 5096: GET /sensors [14/09/2022, 11:33:26] [Hue] rpi_hue: request 5096: timeout after 5 seconds [14/09/2022, 11:35:41] [Hue] rpi_hue: request 5149: GET /sensors [14/09/2022, 11:35:41] [Hue] rpi_hue: request 5149: timeout after 5 seconds [14/09/2022, 11:35:46] [Hue] rpi_hue: request 5150: GET /sensors [14/09/2022, 11:35:46] [Hue] rpi_hue: request 5150: timeout after 5 seconds [14/09/2022, 11:35:51] [Hue] rpi_hue: request 5151: GET /sensors [14/09/2022, 11:35:51] [Hue] rpi_hue: request 5151: timeout after 5 seconds [14/09/2022, 11:37:01] [Hue] rpi_hue: request 5178: GET /sensors [14/09/2022, 11:37:01] [Hue] rpi_hue: request 5178: timeout after 5 seconds [14/09/2022, 11:37:06] [Hue] rpi_hue: request 5179: GET /sensors [14/09/2022, 11:37:06] [Hue] rpi_hue: request 5179: timeout after 5 seconds [14/09/2022, 11:37:11] [Hue] rpi_hue: request 5180: GET /sensors [14/09/2022, 11:37:11] [Hue] rpi_hue: request 5180: timeout after 5 seconds

How can I solve this? Thank you

ebaauw commented 1 year ago

Setting the timeout to 30s doesn't help.

Did see a “timeout after 30s” warning?

Sometimes there is also a GET / lights warning.

When polling deCONZ, Homebridge Hue first GETs the /sensors and then the /lights. If the GET /sensors fails, it won’t GET /lights until the next poll.

How can I solve this?

Homebridge Hue makes an API call to deCONZ, but doesn’t get a timely response. As this also happens with a 30s timeout, I don’t think this is related to the load on deCONZ, but rather on the connectivity between Homebridge Hue and deCONZ. Preferably, run them on the same server, eliminating your network altogether. If that’s not feasible, make sure both servers are connected by wire instead of over WiFi.

Additionally, you might change the heartrate to poll less frequently. Homebridge Hue should be using deCONZ’ websocket notifications, and the polling is mostly there as fallback. However, this probably is addressing the symptom more than the problem.

waterchill commented 1 year ago

deCONZ and homebridge are running on same server Raspberry 4 with 8GB with a fast 64GB SD card. So I changed the timeout to 30s and the heartrate to 20. Let's see tomorrow what happens 😊 Thanks for fast response.

ebaauw commented 1 year ago

deCONZ and homebridge are running on same server Raspberry 4 with 8GB with a fast 64GB SD card.

That shouldn’t cause timeouts, even with 5s. I would double-check:

waterchill commented 1 year ago

Thanks. I have 3 fast sd cards from Adata about 230mb/s reading and I'm rotating all these 3. Problem is always same. Actually I have updated to 64 bit and started from scratch. Before I had 32bit and also same issues. On the Pi there is a lot of other stuff running like iobroker, influxdb and so on. CPU usage is about 6%-10% and about 48°C cpu temp. No undervoltage or underclocking. Actually 1,8Ghz and 0,94V.

pi@raspberry:~ $ vcgencmd measure_volts volt=0.9360V pi@raspberry:~ $ vcgencmd measure_clock arm frequency(48)=1800457088

With "free" I can see how much swap i sused. It looks like it isn't used actually, because there is zero.

pi@raspberry:~ $ free total used free shared buff/cache available Mem: 7999912 1977420 4911508 1104 1110984 5896728 Swap: 2199544 0 2199544

Then we have your last point the deconz log. Is this the right way to produce a log?

https://forum.phoscon.de/t/how-to-get-logs/533

In few days I will try to upgrade the RPi to a mSATA drive. Maybe this will help.

waterchill commented 1 year ago

So far there are no more warnings with timeout 30s and heartrate 20s. I will reduce daily by 5 or 10 seconds, to find out where the sweetspot is.

waterchill commented 1 year ago

I have updated my raspi to ssd on friday and set the timeout und heartrate to default settings. So far till today no more warnings in the log. So it looks like it doesn't matter how fast or good the sd card, the access time are more important.

Hacki1111 commented 1 year ago

I had the same problem after the last deconz update. Sensor updates worked as intended but I´ve got the same warning message every 5 seconds. Now I have downgraded deconz to 2.17.01 (the last stable version before the new stable release) and the problem is gone. Something changed between both releases that causes this bug.