Massive stream of websockets log errors when I woke up, unsure how to debug

Configuration
1

So I woke up this morning to an enormous amount of websockets errors in my log. They all look like this:

2020-04-20 11:59:52 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection.2755931280] Client exceeded max pending messages [2]: 512
2020-04-20 11:59:52 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection.2755931280] Client exceeded max pending messages [2]: 512
2020-04-20 11:59:52 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection.2755931280] Client exceeded max pending messages [2]: 512

You can see with the timestamps how fast they were coming and this had been happening for hours, it started in the middle of the night. That’s literaly all the info I have on them, it didn’t say anything else in the log other then that there was an error.

My first thought was Node RED since I know that add-on opens a websockets connection to HA. But that appeared to be working fine. Everything still working and no unusual messages in the Node RED logs at all. So pretty confident that isn’t it.

When I opened up Portainer to see the logs there i found an enormous amount of messages that looked like this:

/usr/local/lib/python3.7/site-packages/zeroconf/__init__.py:1580: DeprecationWarning: ServiceInfo.address is deprecated, use addresses instead
  warnings.warn("ServiceInfo.address is deprecated, use addresses instead", DeprecationWarning)
/usr/local/lib/python3.7/site-packages/zeroconf/__init__.py:1580: DeprecationWarning: ServiceInfo.address is deprecated, use addresses instead
  warnings.warn("ServiceInfo.address is deprecated, use addresses instead", DeprecationWarning)
/usr/local/lib/python3.7/site-packages/zeroconf/__init__.py:1580: DeprecationWarning: ServiceInfo.address is deprecated, use addresses instead
  warnings.warn("ServiceInfo.address is deprecated, use addresses instead", DeprecationWarning)

There’s no timestamps on these but you’ll have to trust me that they were firing right alongside the first set. Intermixed with those sporadically were some very odd logs that looked like these:

  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100   155  100   155    0     0  25833      0 --:--:-- --:--:-- --:--:-- 31000
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100    67  100    67    0     0  13400      0 --:--:-- --:--:-- --:--:-- 13400
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100   351  100   351    0     0  50142      0 --:--:-- --:--:-- --:--:-- 50142

I didn’t really know what to make of these.

I tried to restart and turn on debug logging for homeassistant.components.websocket_api.http.connection but that didn’t work. HA just immediately starts pumping out a massive stream of logs for all the websockets messages being flung around. And on top of that after I restarted the error seems to have disappeared entirely.

Does anyone know what this might be? Is this zeroconf or is zeroconf a red herring here? And does anyone know what I can do to debug this in the future if it happens again?

I didn’t report a bug on this since I don’t really have enough info to say much about what’s going on and it appears I can’t reproduce it. Really just hoping this jumps out at someone or someone has some future debugging strategies I can use next time.

2

I had a similar odd issue, later found it had to do with a webpage being open for multiple hours. Seemed like something was being called but eventually timed out and started throwing multiple errors per second making a very large log file.

I’m not sure if it was something in the lovelace config or a custom component/card causing the issue.

3

Ugh, you’re probably right. I had that before as well. I actually reported a bug on that last time it happened to me here. But as you can see there, last time it happened to me it was much clearer from the logs what was going on. This time the logs had really no useful info so I didn’t make the connection.

It is clear whatever is doing this is repeatedly trying to make connections without proper auth so that is somewhat similar. And I always have a tab pinned and opened for HA so effectively it is always left open. Usually at least one tab if not multiple on both my phone and mac.

I don’t understand why something would continue to try to make connections once it is clear it can’t authorize. Whether its the UI or something else shouldn’t a 401 response (or in this case the websockets equivalent of that) cause whatever it is to immediately stop trying to connect with the same info? What reason could it have for continuing to try to connect after that, especially this frequently for hours?

4

Add your info here…

5

I’ve been having these same errors for a few months now off and on. I tried to get help in discord but that went completely nowhere.

Hopefully the issue gets resolved.