Websocket errors

[Dielee]

I can not reopen my old issue, so I open up a new one.

As described in #160 my log shows websocket errors. If this error occurs, my players gets not updated.
In HA they are furthermore listed as 'playing', but in the alexa app they are stopped.
So there is no playing music anymore, but HA don't now it.
To make it work again, I have to reboot HA.

But everything works as aspected.

WebSocket Error [SSL: BAD_LENGTH] bad length (_ssl.c:1949)

error from callback <bound method WebsocketEchoClient.on_open of <WebsocketEchoClient(Thread-28, started daemon 1751721072)>>: [Errno 32] Broken pipe

WebSocket Error [Errno 104] Connection reset by peer

Component version: 1.2.5
HA Version: 0.92.2
DEBUG LOG:
alexa_media_log.txt

[alandtse]

If you try to control with your voice the players still don't update? The log is indicating it's successfully reconnecting. Controlling the devices doesn't properly update it anymore?

[Dielee]

No, devices not updating.
Neither with my voice nor with HA...
Reboot HA is the only thing what works.

[alandtse]

Does it keep happening or does it only happen sporadically?

[Dielee]

This happens sporadically. Sometime it works a few days without the error, and sometime I get the error twice a day.

[alandtse]

I'll see if there's anything we can do from our side to ensure the old websocket connection is properly closed when we create a new one, but after that I'm not certain what the issue is if the websocket is successfully reconnecting.

[ehendrix23]

Not sure if you use aiohttp, but if you do check if you have the following parameter for TCPConnector call: enable_cleanup_closed=True
I had some issues on certain platforms and that solved it.

[ehendrix23]

Got same issue. Following is in the log file when it started to happen:

2019-05-10 07:00:49 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal read error on socket transport
Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/selector_events.py", line 801, in _read_ready__data_received
    data = self._sock.recv(self.max_size)
TimeoutError: [Errno 60] Operation timed out
2019-05-10 07:01:50 ERROR (MainThread) [snitun.multiplexer.core] Ping fails, no response from peer
2019-05-10 07:03:35 ERROR (Thread-291) [alexapy.alexawebsocket] WebSocket Error [Errno 60] Operation timed out
2019-05-10 07:03:36 ERROR (Thread-525) [websocket] error from callback <bound method WebsocketEchoClient.on_open of <WebsocketEchoClient(Thread-525, started daemon 123145480822784)>>: [Errno 32] Broken pipe
2019-05-10 07:03:36 ERROR (Thread-525) [alexapy.alexawebsocket] WebSocket Error [SSL: BAD_LENGTH] bad length (_ssl.c:2341)
2019-05-10 07:03:38 ERROR (Thread-527) [websocket] error from callback <bound method WebsocketEchoClient.on_open of <WebsocketEchoClient(Thread-527, started daemon 123145507098624)>>: [Errno 32] Broken pipe
2019-05-10 07:03:38 ERROR (Thread-527) [alexapy.alexawebsocket] WebSocket Error [SSL: BAD_LENGTH] bad length (_ssl.c:2341)
2019-05-10 07:03:39 ERROR (Thread-529) [websocket] error from callback <bound method WebsocketEchoClient.on_open of <WebsocketEchoClient(Thread-529, started daemon 123145480822784)>>: [Errno 32] Broken pipe
2019-05-10 07:03:39 ERROR (Thread-529) [alexapy.alexawebsocket] WebSocket Error [SSL: BAD_LENGTH] bad length (_ssl.c:2341)

And from then on errors just keep on repeating, seemingly about 2 error entries / minute. Alexa components are not working then anymore.
Only resolution is a restart of HA.

[alandtse]

@ehendrix23 This is a slightly different issue from the earlier logs in that you're not reconnecting vs @Dielee who's logs were.

However, are you sure you had internet on the HA device? snitun.multiplexer.core is reporting a ping issue immediately before the websocket errors.

[ehendrix23]

I included it as clearly something occurred right then, however after this it was connected to the internet as everything else kept on functioning. A lot of these other components require connection to the internet as well (i.e. August, MyQ). So there might have been a glitch from a networking perspective but it would not have been for long as nothing else reported any issues.