unfoldedcircle / feature-and-bug-tracker

Feature and bug tracker repository for Unfolded Circle products
22 stars 0 forks source link

Client unable to keep up with pending messages[bug] title #301

Open tomlut opened 5 months ago

tomlut commented 5 months ago

Is there an existing issue for this?

Description

The home assistant component regularly generates these errors:

Logger: homeassistant.components.websocket_api.http.connection
Source: components/websocket_api/http.py:240
Integration: Home Assistant WebSocket API (documentation, issues)
First occurred: 12:44:33 (2 occurrences)
Last logged: 13:11:13

[140414894863424] Tom L from 10.1.1.21: Client unable to keep up with pending messages. Stayed over 1024 for 5 seconds. The system's load is too high or an integration is misbehaving; Last message was: {"type":"event","event":{"event_type":"state_changed","data":{"entity_id":"media_player.cinema_zone","old_state":{"entity_id":"media_player.cinema_zone","state":"playing","attributes":{"source_list":"airplay, hdmi1","sound_mode_list":["munich","vienna","chamber","cellar_club","roxy_theatre","bottom_line","sports","action_game","roleplaying_game","music_video","standard","spectacle","sci-fi","adventure","drama","mono_movie","2ch_stereo","7ch_stereo","surr_decoder","straight"],"group_members":["media_player.cinema_zone"],"volume_level":0.422360248447205,"is_volume_muted":false,"media_content_type":"music","media_duration":427,"media_position":41,"media_position_updated_at":"2024-01-31T01:44:32.600010+00:00","media_title":"Flying","media_artist":"Death In Vegas","media_album_name":"The Contino Sessions","source":"AirPlay","sound_mode":"7ch_stereo","shuffle":false,"repeat":"off","entity_picture":"/api/media_player_proxy/media_player.cinema_zone?token=13b60ccfc23bc75d15c9188a4ae9a56cd1880c024fd8cae30fa872d4971b963c&cache=699863d26b383f60","icon":"mdi:speaker","friendly_name":"Cinema Zone","supported_features":1040317},"last_changed":"2024-01-31T01:35:55.019717+00:00","last_updated":"2024-01-31T01:44:32.600848+00:00","context":{"id":"01HNEK0WJRP80FN68W9F1VMSA3","parent_id":null,"user_id":null}},"new_state":{"entity_id":"media_player.cinema_zone","state":"playing","attributes":{"source_list":"airplay, hdmi1","sound_mode_list":["munich","vienna","chamber","cellar_club","roxy_theatre","bottom_line","sports","action_game","roleplaying_game","music_video","standard","spectacle","sci-fi","adventure","drama","mono_movie","2ch_stereo","7ch_stereo","surr_decoder","straight"],"group_members":["media_player.cinema_zone"],"volume_level":0.422360248447205,"is_volume_muted":false,"media_content_type":"music","media_duration":427,"media_position":42,"media_position_updated_at":"2024-01-31T01:44:33.607467+00:00","media_title":"Flying","media_artist":"Death In Vegas","media_album_name":"The Contino Sessions","source":"AirPlay","sound_mode":"7ch_stereo","shuffle":false,"repeat":"off","entity_picture":"/api/media_player_proxy/media_player.cinema_zone?token=13b60ccfc23bc75d15c9188a4ae9a56cd1880c024fd8cae30fa872d4971b963c&cache=699863d26b383f60","icon":"mdi:speaker","friendly_name":"Cinema Zone","supported_features":1040317},"last_changed":"2024-01-31T01:35:55.019717+00:00","last_updated":"2024-01-31T01:44:33.608292+00:00","context":{"id":"01HNEK0XJ8DRCNBTNR8QGYDHXG","parent_id":null,"user_id":null}}},"origin":"LOCAL","time_fired":"2024-01-31T01:44:33.608292+00:00","context":{"id":"01HNEK0XJ8DRCNBTNR8QGYDHXG","parent_id":null,"user_id":null}},"id":1}
[140412844482624] Tom L from 10.1.1.21: Client unable to keep up with pending messages. Stayed over 1024 for 5 seconds. The system's load is too high or an integration is misbehaving; Last message was: {"type":"event","event":{"event_type":"state_changed","data":{"entity_id":"sensor.lounge_window_dew_point_difference","old_state":{"entity_id":"sensor.lounge_window_dew_point_difference","state":"15.06","attributes":{"state_class":"measurement","unit_of_measurement":"°C","device_class":"temperature","icon":"mdi:thermometer-water","friendly_name":"Lounge Window Dew Point Difference"},"last_changed":"2024-01-31T02:07:05.846901+00:00","last_updated":"2024-01-31T02:07:05.846901+00:00","context":{"id":"01HNEMA63N15JP4RDKVDQA9RW8","parent_id":null,"user_id":null}},"new_state":{"entity_id":"sensor.lounge_window_dew_point_difference","state":"15.16","attributes":{"state_class":"measurement","unit_of_measurement":"°C","device_class":"temperature","icon":"mdi:thermometer-water","friendly_name":"Lounge Window Dew Point Difference"},"last_changed":"2024-01-31T02:11:13.218927+00:00","last_updated":"2024-01-31T02:11:13.218927+00:00","context":{"id":"01HNEMHQP1QH83TSHJ44JJ58WS","parent_id":null,"user_id":null}}},"origin":"LOCAL","time_fired":"2024-01-31T02:11:13.218927+00:00","context":{"id":"01HNEMHQP1QH83TSHJ44JJ58WS","parent_id":null,"user_id":null}},"id":1}

How to Reproduce

This seems to happen when I close an activity that uses the home assistant integration. The activity off sequence does not cause anything to happen so I turn the activity on again and turn it off. Sometimes I have to do this twice before the required actions occur.

Expected behavior

Not to spam Home Assistant and to correctly request the script to run.

System version

v1.6.7

What part of the system affected by the problem?

Integration

Additional context

Screenshot 2024-01-31 at 17-24-03 Remote 2 Web Configurator

This script (`script.cinema_off') works perfectly fine in home assistant and generates no errors.

zehnm commented 4 months ago

The home assistant component regularly generates these errors:

That doesn't look like an error to me :-) When are those log entries in the server created? At the same when you stop the described activity, or do they occur when the remote is in standby? If they relate to the activity, then please provide the Remote Two log file.

Client unable to keep up with pending messages suggests that there are either many entity changes in HA which couldn't be transmitted in a timely matter to the remote, or the remote entered standby and couldn't receive the messages anymore (see linked issue above for disconnecting from HA when in standby. An update will be released soon.).

Not to spam Home Assistant and to correctly request the script to run.

The remote is not spamming HA. Only entity commands are sent and HA reports entity changes. There's no further communication that could be reduced.

tomlut commented 4 months ago

It happens when I pick up the remote, wait a while for the remote to connect then attempt stop an activity. The attempt fails (twice in the example in my 1st post).

(see https://github.com/unfoldedcircle/integration-home-assistant/issues/50 above for disconnecting from HA when in standby. An update will be released soon.).

Yeah that looks like the issue. Thank you for your work on this. 👍