Core: Permanent error: Client exceeded max pending messages [2]: 512

[Spirituss]

Home Assistant release with the issue:

HA 0.98.5

Last working Home Assistant release (if known):
HA 0.91 (0.92.0?)

Operating environment (Hass.io/Docker/Windows/etc.):

HASS.io/Docker/Raspbian Buster

Component/platform:

homeassistant.components.websocket_api.http.connection

Description of problem:
I have to reopen the issue (https://github.com/home-assistant/home-assistant/issues/23938) since it was unreasonably closed (some people have the same problem but in different environment).
To be more exact, no use of Node-Red and no HA automation restarts but issue is till on.

Problem-relevant configuration.yaml entries and (fill out even if it seems unimportant):

Tons of errors in error log with no any clear reason. I can have more than 15.000 such errors a day.

Traceback (if applicable):

ERROR (MainThread) [homeassistant.components.websocket_api.http.connection.xxxx] Client exceeded max pending messages [2]: 512

Additional information:

[stainlessray]

I have the same stupid issue. Hass is unusable. As stated in op there is no clear reason for this error. Examples by other posts indicate the cause is completely unknowable at this time.

Maybe try NOT closing the issue again all? You're decentralizing the attempts to troubleshoot with no possible gain in doing so.

[arnonel]

Getting same error

[Spirituss]

Updated to 101.2 - HA becomes unusable at all. I have hundreds of such errors every minutes. All server CPU wastes to error log write.

[stainlessray]

Updated to 101.2 - HA becomes unusable at all. I have hundreds of such errors every minutes. All server CPU wastes to error log write.

I updated, same result. I'm leaning toward starting from scratch. Such a hassle.

[rainisto]

I'm getting same error from fresh hass.io HA 101.3 install. Also tested plain 101.3 HA venv install without hass.io and that one works without generating errors to log, so my guess is that problem is related to hass.io docker container permissions/routing.

[mfl76]

Same issue with 0.100.2.

[browetd]

Same error with 0.101.3 (in a virtual environment)... I started to track that in the logs ... Here is the last extract from the logs (HA seems to work fine despite this recurring error message):

2019-11-12 11:13:21 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=switch.chauffage_salle_de_bain_bas, old_state=<stat$
2019-11-12 11:13:21 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=switch.atlantic_salle_de_bain_haut, old_state=<stat$
2019-11-12 11:13:21 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=automation.get_smappee_c_m, old_state=<state automa$
2019-11-12 11:13:23 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_usage_c, old_state=<state sensor.sma$
2019-11-12 11:13:23 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_injected, old_state=<state sensor.sm$
2019-11-12 11:13:23 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_solar_c, old_state=<state sensor.sma$
2019-11-12 11:13:23 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_injected, old_state=<state sensor.sm$
2019-11-12 11:13:23 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_usage_m, old_state=<state sensor.sma$
2019-11-12 11:13:41 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=automation.get_smappee_c_m, old_state=<state automa$
2019-11-12 11:13:45 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_solar_c, old_state=<state sensor.sma$
2019-11-12 11:13:45 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_injected, old_state=<state sensor.sm$
2019-11-12 11:13:45 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_usage_m, old_state=<state sensor.sma$
2019-11-12 11:13:45 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_usage_c, old_state=<state sensor.sma$
2019-11-12 11:13:45 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_injected, old_state=<state sensor.sm$
2019-11-12 11:13:52 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=switch.chauffe_eau_cuisine, old_state=<state switch$
2019-11-12 11:13:52 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=switch.chauffage_salle_de_bain_bas, old_state=<stat$
2019-11-12 11:13:52 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=switch.atlantic_salle_de_bain_haut, old_state=<stat$
2019-11-12 11:14:00 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.time, old_state=<state sensor.time=11:13; fr$
2019-11-12 11:14:00 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.date_time, old_state=<state sensor.date_time$
2019-11-12 11:14:01 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=automation.get_smappee_c_m, old_state=<state automa$
2019-11-12 11:14:07 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_solar_c, old_state=<state sensor.sma$
2019-11-12 11:14:07 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_injected, old_state=<state sensor.sm$
2019-11-12 11:14:07 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_usage_m, old_state=<state sensor.sma$
2019-11-12 11:14:07 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_usage_c, old_state=<state sensor.sma$
2019-11-12 11:14:07 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_injected, old_state=<state sensor.sm$
2019-11-12 11:14:17 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.hall_d_entree_io_9605662_2, old_state=<state$
2019-11-12 11:14:17 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.chambre_thomas_io_4977817_2, old_state=<stat$
2019-11-12 11:14:21 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=climate.hall_d_entree_i2g_actuator, old_state=<stat$
2019-11-12 11:14:21 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=climate.chambre_thomas_i2g_actuator, old_state=<sta$
2019-11-12 11:14:21 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=automation.get_smappee_c_m, old_state=<state automa$
2019-11-12 11:14:23 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=switch.chauffage_salle_de_bain_bas, old_state=<stat$
2019-11-12 11:14:23 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=switch.chauffe_eau_cuisine, old_state=<state switch$
2019-11-12 11:14:23 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=switch.atlantic_salle_de_bain_haut, old_state=<stat$
2019-11-12 11:14:29 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_usage_c, old_state=<state sensor.sma$
2019-11-12 11:14:29 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_injected, old_state=<state sensor.sm$
2019-11-12 11:14:29 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_usage_m, old_state=<state sensor.sma$
2019-11-12 11:14:29 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_solar_c, old_state=<state sensor.sma$
2019-11-12 11:14:29 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=sensor.smappee_injected, old_state=<state sensor.sm$
2019-11-12 11:14:41 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Sending {'id': 2, 'type': 'event', 'event': <Event state_changed[L]: entity_id=automation.get_smappee_c_m, old_state=<state automa$
2019-11-12 11:26:09 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal read error on socket transport
Traceback (most recent call last):
  File "/usr/lib/python3.7/asyncio/selector_events.py", line 801, in _read_ready__data_received
    data = self._sock.recv(self.max_size)
TimeoutError: [Errno 110] Connection timed out
2019-11-12 11:26:09 INFO (MainThread) [homeassistant.components.websocket_api.http.connection.2614778736] Connection closed by client
2019-11-12 11:26:09 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2614778736] Disconnected
2019-11-12 11:32:21 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Client exceeded max pending messages [2]: 512
2019-11-12 11:32:21 INFO (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Connection closed by client
2019-11-12 11:32:21 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.2612512176] Disconnected

[electrofloat]

Same here:

Dec  4 08:57:40 localhost hass[18209]: 2019-12-04 08:57:40 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection.140515727017040] Client exceeded max pending messages [2]: 512
Dec  4 08:57:40 localhost hass[18209]: message repeated 2 times: [ 2019-12-04 08:57:40 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection.140515727017040] Client exceeded max pending messages [2]: 512]

It seems to be happening sometime after I'm connecting to HA from the Android webapp.

[tomlut]

Found what was causing these errors for me and can reproduce 100%

1. Open and edit a Lovelace card in Firefox (have not tested Chrome yet).
2. Close the card edit and exit UI edit mode, do not refresh the browser.
3. Navigate to another view or sidebar menu a few times.
4. Sooner rather than later Firefox starts throwing up rapidly repeating “Refresh Lovelace” toast notifications in the lower left corner. This may eventually cause the screen to show a blank page with a useless “Refresh Lovelace” button in the centre. This causes thousands of errors in a very short time.

Standard browser refresh clears the error loop.

So I guess I just have to remember to refresh my browser after editing a card.

Possibly a polymer/frontend issue with how HA attempts to refresh Firefox.

[Spirituss]

I still have this error message in 0.103.5, but more rarely yet.

[andriej]

Issue in frontend part: https://github.com/home-assistant/frontend/issues/5328

[Spirituss]

On 107.7 HA is very unstable. Interface periodically becomes unavailable and CPU usage of HA server increases from 5% to more than 40%. During such a period I see a tons of errors: ERROR (MainThread) [homeassistant.components.websocket_api.http.connection.140484979526352] Client exceeded max pending messages [2]: 512

[browetd]

The problem is still there in 0.108.2... After a request from lovelace (via a button) or through the development tools to reload automations, 102 message in the same second "2020-04-11 05:49:36 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection.2614746480] Client exceeded max pending messages [2]: 512" ...

[cratermaddie]

I'm seeing this issue as well. I noticed that removing every card that used card-templater seemed to resolve the issue for me but that's obviously not an ideal resolution...

[fraschizzato]

Same in 0.108.8 - Happens randomly, have to restart home assistant to get it work again.
I never used card-templater, only card-tools.

Solved the continuous errors, here the steps from my post in community.home-assistant.io:

After many tries I've found that the "problem" is hacs and/or card-tools... I have to find if directly related to that integrations or if a sum of other issues... Let me explain:

• Removed all lovelace resource from gui
• Removed all hacs integration and hacs itself
• Commented out entities that uses other custom_components
• Cleaned manually all the folders from custom components and resource
• Removed (after 2 restart as mentioned in the hacs removal guide) the hacs files in .stored folder

During the clean i've found a lot of unused old stuff and some js that where initially installed manually and then via hacs... So probably the issue is from that confusion beside the custom_components itself...
Now, in these days, i will re-add progressively all the appdaemon,components and entities I've removed or commented out to see if the problem re-appears...
One thing is sure, until the steps described above, the issue was still there.

Sometimes the issue re-happen, Hass get's stuck for some minutes and then runs correctly.
As by observation I've seen that can be related to the sleep mode of a win10 pc client. If that client has a chrome tab open with Hass, when it goes in sleep mode the error starts

[balloob]

109 includes a fix to allow websocket API clients to catch up for 5 seconds if they fall behind on consuming messages.

[fraschizzato]

I think is related to chrome tabs that remains open for long time. More details below:

• I've tried with and without: hacs - appdaemon - custom_components - custom_cards and (except for custom_cards) I didn't find a direct correlation. For custom_card there are 2 different causes: UI not correctly reloaded (most common - use CTRL+F5 in chrome to reload) and duplication/overlap of cards/integration for who now uses hacs but before added them manually (a lot more buggy - double check if all customization are removed before using hacs to add them)
  
  
  
  • I've found that one automation was not triggered during the ERROR so I've made an mqtt watchdog timer to exactly see when the problem occurs:
  
  
  • Initially I've found that (with my config) it happens about twice a day, Hass is not responsive during the error BUT 3 out of 4 times it self-restored - after some times (variable between 30sec and 8min) Hass works as if nothing happened before. So many times the error is not appreciable, It causes problem to the user if he tries to use the UI during the error.
  
  
  • But, MOST IMPORTANT, I've found that the error happens ONLY if there is a client (phone or pc - chrome or home assistant companion) with the ui open for long time. Now, that i'm closing always any Home Assistant tab after use, the error is gone (for now 12h without any error and keep going)
  
  
  • It seems, but not sure about this, that it's related to the fact that the pc/phone with the tab open goes on sleep mode or there are (like in my case) wifi/network jumps
  
  

Probably Hass and Frontend does not manage correctly the socket disconnection-reconnection. Hass must stop sending data through websocket after first pending messages and meanwhile Frontend must attempt a reconnection (like when hass is restarted but ui is keeped open)

Hope it helps

[andriej]

I fully agree with your part of analysis saying, that it's always caused by clients having UI open for long time.
In my case client is generating so much traffic over time (jncreasing) that HA becomes more and more unresponsive (delays with lights) because of amount of logs probably.

[SnowViet]

I have a similar issue.
It happens when I keep open my browser for a long time (Chrome 81.0.4044.129).
HA keep logging:

ERROR (MainThread) [homeassistant.components.websocket_api.http.connection.140484979526352] Client exceeded max pending messages [2]: 512

It's getting frozen, my automation are really slow, etc.
But when I close the borwser (or just the HA page), it works again.

[andriej]

Check your logs size, it's getting frozen beacuse of gigabytes it has to write to disk ;-)

[SnowViet]

I don't think so, the logfile is "only" 100MB, with more than 550'000 error lines (and it's working for the time being).
It's frozen because of high CPU usage ? I don't know, it's running inside docker on my NAS, and it's CPU limited, I will check the I/O, CPU, RAM usage next time it gets frozen.

[fraschizzato]

With more than 800 entity... can You imagine the traffic on the socket... For me everything starts happening last week, I've updated hass but didn't remember previous version (last working). No more entities added, the only update was to home assistant...

Another fact is that with the number in logs I can't identify which device causes the issue, maybe in the error message a client identifier (much more detailed) can be usefull...

[fraschizzato]

Just found that the client is causing all is appdaemon.... Didn't know if itself or specific app

Update: AppDaemon is the client that shows up on logs, isn't clear if is the cause or a symptom

[cgarwood]

I've also been seeing this occasionally on 0.108 and 0.109 - Does seem to affect appdaemon, as my appdaemon automations all stopped working. However, I still saw the errors in the logs continuing after I stopped AppDaemon. Some combination of closing HA tabs in my browser and an HA restart finally cleared it up (for now).

[fraschizzato]

Also in 109.1, with appdaemon 4.0.3

2020-05-01 21:52:31 ERROR (MainThread) [backoff] Giving up get_ratelimit(...) after 5 tries (concurrent.futures._base.TimeoutError)
2020-05-01 21:52:39 ERROR (MainThread) [homeassistant.core] Error doing job: Exception in callback WebSocketResponse._send_heartbeat()
2020-05-01 22:00:08 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
2020-05-01 22:13:11 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection.140167701502664] Client unable to keep up with pending messages. Stayed over 512 for 5 seconds
2020-05-01 22:13:11 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection.140167705232104] Client unable to keep up with pending messages. Stayed over 512 for 5 seconds
2020-05-01 22:18:23 ERROR (MainThread) [homeassistant.core] Error doing job: Exception in callback WebSocketResponse._send_heartbeat()
2020-05-01 22:18:23 ERROR (MainThread) [homeassistant.core] Error doing job: Exception in callback WebSocketResponse._send_heartbeat()
2020-05-01 22:18:23 ERROR (MainThread) [homeassistant.core] Error doing job: Exception in callback WebSocketResponse._send_heartbeat()

At 22:10 I've received the message from the watchdog... Hass was unresponsive and doesn't make any automation (as the watchdog is based on automated mqtt from hass)

logs from appdaemon:

2020-05-01 22:09:34.040928 INFO revert_back: automation.autostoppannellocamera on
2020-05-01 22:09:34.043889 INFO revert_back: automation.watchdog_spa on
2020-05-01 22:09:53.057904 WARNING HASS: Disconnected from Home Assistant, retrying in 5 seconds
2020-05-01 22:10:58.075173 WARNING HASS: Disconnected from Home Assistant, retrying in 5 seconds
2020-05-01 22:10:58.107157 INFO revert_back: automation.cloro_e_ph off
2020-05-01 22:10:58.110539 INFO revert_back: automation.luci_natale_on off

didn't know how to do at this point

[Botr16]

Same problem here. I noticed it started happening when editing the lovelace interface and i had just started using layout-card and card-mod with button-card. As of 0.109 the issues got worse: I dont get the "Connection Lost" popup anymore but the interface is slow, sluggish, sometimes fails to load and the page i was working on is now broken:

Running 0.108 this page was fine, but the socket was overloaded everytime i made more than 1 change to the interface without reloading the page. I have a phone always on and showing hassio but this wasnt an issue in the last few months.
I'm not very experienced so forgive me if I missed something, feel free to ask me anything

[RezzZ]

happens in 0.110.2 as well (docker amd64)

[u8915055]

I will add that im on 110.4 and had the problem on 110.3 and 110.4 .. however I closed my chrome browser tab with HA and the problem immediately stopped.. I opened up a tab again and loaded HA and it is VERY responsive now and no errors. Going to continue to watch it.

[RezzZ]

yeah, probably related to the fact that I have at least one active pc with HA pinned as permanent tab in chrome.
No apparent unresponsiveness on my side though.

[truglodite]

Just wanted to report I'm having the same issues on my pi4 hassos system. It also is correlated to Chrome browser being left open on the HA gui for a long time. In most cases, it is caused by me forgetting to close the browser app before locking my phone. Like others, the result is lots of logs and occasionally a skipped automation. Of course, closing the browser seems like a workaround that should be needed. I would help with a PR if I was more skilled with python, but instead I have to sit on the sidelines since all I have to offer is testing.

Not sure if it helps at all, but I recall some scripts I was using on my router (asus merlin fw) had a similar issue with handling the way certain browsers would exit. IIRC, chrome on android doesn't gracefully close connections when the device enters sleep mode. The scripts had to be adjusted to handle this abrupt behavior without causing excess logs and related issues. Understanding how this all works is above my skill level, but I'm willing to test PR's.

[RezzZ]

if an open browser is really the issue, then how do we use a dedicated tablet with HA constantly open?

[dpositive]

I have the same issue:
Client unable to keep up with pending messages. Stayed over 512 for 5 seconds

[pkishino]

same here, hassio running on mac mini proxmox, cpu usage low.
Client unable to keep up with pending messages. Stayed over 512 for 5 seconds

[JamieP83]

same issue here too

[gerard33]

If I understood correctly this change in 0.112 should prevent this from happening -> https://www.home-assistant.io/blog/2020/07/01/release-112/#automatically-disconnect-if-a-tab-has-been-hidden-for-5-minutes

Not installed 0.112 on my production system yet, so can't verify it yet.

[RezzZ]

they renamed the error a bit I think:
Client unable to keep up with pending messages. Stayed over 512 for 5 seconds
I still see a few of these errors in the log. Not as frequent as before though, and as you suggest @gerard33 it's probably due to the 5 minute disconnect feature.

[Spirituss]

@balloob @gerard33 Unfortunately this issue from 0.112 again becomes a headache. I have thousands of errors every day, but the message text is a bit different:

Client exceeded max pending messages [2]: 2024

And often I see the next message too:

ERROR (MainThread) [homeassistant.core] Error doing job: Unclosed client session

[tomlut]

Yep still seeing this on 0.112.4

[to4ko]

same in 113

[christopherdopp]

I noticed these messages in my log file today with 0.113.3

[MrUserY]

ogger: homeassistant.components.websocket_api.http.connection.2733050392
Source: components/websocket_api/http.py:138
Integration: Home Assistant WebSocket API (documentation, issues)
First occurred: 8:37:04 AM (1 occurrences)
Last logged: 8:37:04 AM

Client unable to keep up with pending messages. Stayed over 512 for 5 seconds

Happens like everyday. I don't have a browser open. Using 2 old iPhones on the walls with latest iOS app. iPad4 with latest iOS app that works on an iPad4 and also an Android with the latest HA app. All running 24/7.
Oh and me and my girlfriend also use the iOS app on our iPhones. So we have 6 clients running to the RaspberryPi4b

[pierre2113]

I see a few of this error in 0.116.2, not allot but enough for me to investigate about it.

[tomlut]

The only time I see this now is when I background the iOS app on my iPad.

[bdraco]

https://github.com/aio-libs/aiohttp/pull/4993 should help this

[MrUserY]

I see this a lot. Dunnow what it means, which client it is en why it happens.

Op 13 okt. 2020 om 15:56 heeft tomlut [e-mail] het volgende geschreven:


The only time I see this now is when I background the iOS app on my iPad.

—
You are receiving this because you commented.
Reply to this email directly, view it on GitHub, or unsubscribe.

[JIOB]

This error has crippled my set-up once I launch my Docker container (Home Assistant 116.4) I'm at 10%+ CPU which continues to climb until it grinds to a halt. I have tried disabling/switching off everything I think could be causing this (iOS, TileBoard, NodeRED) but it has not helped.

[bdraco]

It likely means some integration is generating so many state changed events that the system gets overwhelmed

Turn on debug logging for homeassistant.core

[JIOB]

It likely means some integration is generating so many state changed events that the system gets overwhelmed

Turn on debug logging for homeassistant.core

Thanks for the tip bdraco, just done that and it looks like my cause is ZWave, possibly the worst integration for me to have problems with. I have constant "node.node_id XXX not in node_id [XXX]" messages.

[pierre2113]

hi @JIOB just curious are your zwave devices on HA directly via a usb dongle or are you using Vera hub and HA integration to it.

[JIOB]

Hi @pierre2113, I use ZWave USB in HA integration, however, it wasn't my ZWave integration after all. I think I have managed to track my issue down to a script which I use to control one of my wall tablets running Fully Kiosk. I am now in the process of working out why it is causing this especially since it is identical to three others doing the same thing.

[bdraco]

Turn on debug logging for homeassistant.components.websocket_api. You'll be able to see all the websocket messages.

aiohttp 3.7.x is in 0.118 so this should help improve the delivery rate

[RobBie1221]

It likely means some integration is generating so many state changed events that the system gets overwhelmed

Turn on debug logging for homeassistant.core

@bdraco What would you approximate for "so many" to get a system overwhelmed? See #42950, this seems to happens since force_update is set for the integration (this was requested because of people wanting all datapoints in influxdb). I'd estimate the number of events about 30 every 5 seconds.

[bdraco]

Its going to depend on the performance of the system, latency of the connection, and how fast the client can process the messages. On my system, it can easily process 100 state changes event per second. On an RPi3 it will fall over.

30 every 5 seconds is a bit high if they all get delivered at the same time. Most, but not all systems will be able to keep up. I'd expected the lower end hardware will fail at that level. Using force_update should probably be an option for users who have the hardware/setup to handle it.

[RobBie1221]

@bdraco Thanks! This helps a lot. Having it as an option for the integration is also not really ideal, looking at this specific integration only maybe 5 out of the 30 entities are really relevant for force_update, but even that could be very personal. That would mean even people with hardware which cannot handle 30 would perhaps want to have it on a handful. I've also done some work for rfxtrx integration where now force_update is true for sensor and binary sensor entities, but that may also be a bit overkill as some people have 100+ devices in this integration of which all have a battery and rssi entity.

Perhaps maybe somewhere in future this can be added to customization, to allow users to set it entity specific...

[pierre2113]

just wondering if anybody else is finding this issue

"[homeassistant.components.websocket_api.http.connection] [1755060880] Client unable to keep up with pending messages. Stayed over 512 for 5 seconds"

related to automations where you are running update_entity on a sensor.

- service: homeassistant.update_entity
    data:
      entity_id: sensor.blueirisprofile

I had a few, in different automations, in HA .118.3 the error message 512 for 5 seconds is always appearing right after an automation is running. When I comment out update_entity and reload automation the cpu usage has dropped down as well at least 10%.
I still have a few update_entity left, just waiting to see if the "...512 for 5" message follows the remaining automations that still have it before I remove the remaining last 2.