core: Using Voice/Assist causes the websocket to get overloaded leading to HAOS stability issues

The problem

Hi,

Running HAOS (2023.5.0b4) on RPi4 4Gb on 500GB SSD (usb boot) and using HA in Chrome (Windows 10 computer) to use Assist.

Working with @bdraco, what we did:

The profiler service was started, and then the Assist dialogue box was opened and I voiced my command by pressing the microphone key “Turn on the Kitchen Light”, it responded and then replied back did the action, then I said “Turn off the kitchen light” and likewise it responded and did the action. Both commands were successful. Shown here:

image

However, the logs would indicate otherwise. During this time, errors were logged in the thousands (over a few minutes) during the above dialogue:

Logger: homeassistant.components.websocket_api.http.connection
Source: components/websocket_api/connection.py:125
Integration: Home Assistant WebSocket API (documentation, issues)
First occurred: 10:16:00 AM (4291 occurrences)
Last logged: 1:27:51 PM

[547285121440] Received binary message for non-existing handler 8
[547285121440] Received binary message for non-existing handler 9
[547285121440] Received binary message for non-existing handler 10
[547297052992] Received binary message for non-existing handler 1
[547297052992] Received binary message for non-existing handler 2

My voice assistant settings are:

simple_voice_command_settings

And the callgrind files here:

callgrind.out.1682882817681.txt profile.1682882817681262.cprof.txt

Reveal some issues:

image

Where “20% of the event loop time is logging 1000x of the messages”

   index = handler_id - 1
        if (
            index < 0
            or index >= len(self.binary_handlers)
            or (handler := self.binary_handlers[index]) is None
        ):
            self.logger.error(
                "Received binary message for non-existing handler %s", handler_id
            )
            return

During this time, memory usage increased and CPU usage spiked (see the end of the traces):

image image

In other separate callgrinds, similar issues are also seen:

image image

This may also be related to this issue.

What version of Home Assistant Core has the issue?

2023.5.0b4

What was the last working version of Home Assistant Core?

not sure

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Assist

Link to integration documentation on our website

No response

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

About this issue

  • Original URL
  • State: open
  • Created a year ago
  • Reactions: 6
  • Comments: 21 (3 by maintainers)

Most upvoted comments

For me, running this project (https://github.com/synesthesiam/homeassistant-satellite) triggers a constant stream of these in the logs:

ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [139694421748928] Received binary message for non-existing handler 1

HASS v2023.10.2

Keeping this alive in 2024!

Logger: homeassistant.components.websocket_api.http.connection
Source: components/websocket_api/connection.py:167
Integration: Home Assistant WebSocket API (documentation, issues)
First occurred: 1:45:30 AM (4232 occurrences)
Last logged: 10:03:00 AM

[547681309888] Received binary message for non-existing handler 1
[547681309888] Received binary message for non-existing handler 2
[547681309888] Received binary message for non-existing handler 3
[545834808128] Received binary message for non-existing handler 1

Same experience on Home Assistant 2023.5.1, Voice Assist works properly (on Nabu Casa Cloud from phone) but logged some 260 Received binary message for non-existing handler... after 3 queries to voice. By the way the voice worked amazingly! Can’t say it caused any hit in HA stability - I’m running in VM (2 cores - 4GB ram - 32 GB disk) in proxmox on an i5 6500T (16GB ram - 128gb NVME).