Web Socket Error on AmazonEchoControl binding every 65 seconds

Austris_V · September 5, 2020, 9:03pm

I have a weird behavior I can’t explain Got the same famous Web Socket error a while ago. Found this thread, dropped .jar in addons and all was good.
But since the last restart (trying to make ipcamera binding work), the log is full of it again

Checked the version - looks legit (and also tried stoping openhab, remove jar, clearing cache, starting openhab - verifying PaperUI does not show it installed - and putting jar in addons). I’m on openHAB 2.5.0 Release Build atm - if it changes anything.

openhab> bundle:list | grep mazon
291 x Active x  80 x 2.5.6.202008310258      x openHAB Add-ons :: Bundles :: Amazon Echo Control Binding

But the log goes like this. Any ideas appreciated on what I could have done wrong or how to debug. Thank You so much!

UPDATE: I left it like that last night…checking the logs in the morning - have these errors for about an hour, then they disappear. Fine with that for time being; still wondering what to do/if it comes back.

UPDATE2: did another restarte and the error was there, again. I decided it’s time for update:) Cleared cache, upgraded openhab to 2.5.9, installed amazonecho from PaperUI, so far so good. Must have been something wrong at my side

2020-09-05 23:57:15.018 [INFO ] [control.internal.WebSocketConnection] - Web Socket error

java.nio.channels.AsynchronousCloseException: null

	at org.eclipse.jetty.client.http.HttpConnectionOverHTTP.close(HttpConnectionOverHTTP.java:181) ~[?:?]

	at java.util.ArrayList.forEach(ArrayList.java:1257) [?:1.8.0_222]

	at org.eclipse.jetty.client.AbstractConnectionPool.close(AbstractConnectionPool.java:208) [bundleFile:9.4.20.v20190813]

	at org.eclipse.jetty.client.DuplexConnectionPool.close(DuplexConnectionPool.java:237) [bundleFile:9.4.20.v20190813]

	at org.eclipse.jetty.client.HttpDestination.close(HttpDestination.java:385) [bundleFile:9.4.20.v20190813]

	at org.eclipse.jetty.client.HttpClient.doStop(HttpClient.java:260) [bundleFile:9.4.20.v20190813]

	at org.eclipse.jetty.util.component.AbstractLifeCycle.stop(AbstractLifeCycle.java:93) [bundleFile:9.4.20.v20190813]

	at org.eclipse.jetty.util.component.ContainerLifeCycle.stop(ContainerLifeCycle.java:180) [bundleFile:9.4.20.v20190813]

	at org.eclipse.jetty.util.component.ContainerLifeCycle.doStop(ContainerLifeCycle.java:201) [bundleFile:9.4.20.v20190813]

	at org.eclipse.jetty.websocket.client.WebSocketClient.doStop(WebSocketClient.java:371) [bundleFile:9.4.20.v20190813]

	at org.eclipse.jetty.util.component.AbstractLifeCycle.stop(AbstractLifeCycle.java:93) [bundleFile:9.4.20.v20190813]

	at org.openhab.binding.amazonechocontrol.internal.WebSocketConnection.close(WebSocketConnection.java:159) [bundleFile:?]

	at org.openhab.binding.amazonechocontrol.internal.WebSocketConnection$2.run(WebSocketConnection.java:184) [bundleFile:?]

	at java.util.TimerThread.mainLoop(Timer.java:555) [?:1.8.0_222]

	at java.util.TimerThread.run(Timer.java:505) [?:1.8.0_222]

2020-09-05 23:58:25.431 [INFO ] [control.internal.WebSocketConnection] - Web Socket error

java.nio.channels.AsynchronousCloseException: null

	at org.eclipse.jetty.client.http.HttpConnectionOverHTTP.close(HttpConnectionOverHTTP.java:181) ~[?:?]

	at java.util.ArrayList.forEach(ArrayList.java:1257) [?:1.8.0_222]

	at org.eclipse.jetty.client.AbstractConnectionPool.close(AbstractConnectionPool.java:208) [bundleFile:9.4.20.v20190813]

	at org.eclipse.jetty.client.DuplexConnectionPool.close(DuplexConnectionPool.java:237) [bundleFile:9.4.20.v20190813]

	at org.eclipse.jetty.client.HttpDestination.close(HttpDestination.java:385) [bundleFile:9.4.20.v20190813]

	at org.eclipse.jetty.client.HttpClient.doStop(HttpClient.java:260) [bundleFile:9.4.20.v20190813]

	at org.eclipse.jetty.util.component.AbstractLifeCycle.stop(AbstractLifeCycle.java:93) [bundleFile:9.4.20.v20190813]

	at org.eclipse.jetty.util.component.ContainerLifeCycle.stop(ContainerLifeCycle.java:180) [bundleFile:9.4.20.v20190813]

	at org.eclipse.jetty.util.component.ContainerLifeCycle.doStop(ContainerLifeCycle.java:201) [bundleFile:9.4.20.v20190813]

	at org.eclipse.jetty.websocket.client.WebSocketClient.doStop(WebSocketClient.java:371) [bundleFile:9.4.20.v20190813]

	at org.eclipse.jetty.util.component.AbstractLifeCycle.stop(AbstractLifeCycle.java:93) [bundleFile:9.4.20.v20190813]

	at org.openhab.binding.amazonechocontrol.internal.WebSocketConnection.close(WebSocketConnection.java:159) [bundleFile:?]

	at org.openhab.binding.amazonechocontrol.internal.WebSocketConnection$2.run(WebSocketConnection.java:184) [bundleFile:?]

	at java.util.TimerThread.mainLoop(Timer.java:555) [?:1.8.0_222]

	at java.util.TimerThread.run(Timer.java:505) [?:1.8.0_222]

bf8392 · October 12, 2020, 7:53pm

I’ve also installed the amazon echo control binding, and experienced the java heap out of memory issue…I’m running in docker and tried this vriable: EXTRA_JAVA_OPTS="-Xms400m -Xmx512m"
but leads to not starting the container…any ideas or is there another solution? I love the echo control binding!

Wolfgang_S · October 13, 2020, 6:42pm

Do you use the latest version of the AmazonEchoControl binding ?

bf8392 · October 13, 2020, 6:43pm

Yes

Wikibear · September 29, 2021, 6:00pm

It seems that this issue is back again…

The gap between 52 and 57 sold the result of stopping amazon binding.

J-N-K · September 29, 2021, 6:03pm

It‘s probably a different issue and on Amazon‘s side. The same issue has also been reported for another solution that is using similar code (but a different language).

We‘ll have to wait if Amazon fixes it or investigate if the Alexa App uses a different approach now.

ggg · September 29, 2021, 6:48pm

Yes, have these log entries, but no Out of Memory issues. I guess the exception handling was fixed in the binding?

martin1338 · September 29, 2021, 7:04pm

I have the
2021-09-29 21:02:43.856 [INFO ] [control.internal.WebSocketConnection] - Web Socket close 1005. Reason: null
messages as well since today. My lastVoiceCommand channel of the echo devices is not updating any more. TTS is working on echo devices

ThomasOH · September 29, 2021, 7:13pm

I see the same thing as @martin1338 (Websocket close 1005 and broken lastVoiceCommand). But TTS works, which is a relief.

Thomas

J-N-K · September 29, 2021, 7:42pm

Yes, that‘s expected. The lastVoiceCommand is reported via the websocket connection.

NCO · October 1, 2021, 5:06am

Same error here…

NCO · October 1, 2021, 6:33am

Good news:
I just recognized, that it’s back to normal:

2021-10-01 08:04:03.100 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Alexa_LastVCom' changed from schalt die kaffeemaschine an to stelle ein timer auf zwanzig minuten

Wikibear · October 1, 2021, 10:30am

Seems that it is working now.

jwiseman · October 1, 2021, 11:01am

Mine is working again in the US.

Best, Jay

funcat · October 1, 2021, 12:10pm

Hi all,
Same problem here (France, last stable OH) for a dozen of hours.
At this time, still have “Web Socket close 1005. Reason: null” every 1-2 min, and so no “lastVoiceCommand” update.
For those who have the problem resolved, did you restart the bundle ? Or openhab ?
Thanks

ThomasOH · October 1, 2021, 3:11pm

@funcat Woke up this morning and found that the problem resolved all by itself. Did not restart anything, no magic dust needed. USA, OH2.4.

Thomas

richaardvark · October 1, 2021, 3:38pm

Mine was working fine yesterday but now within the last hour I’m getting the web socket error. I have restarted openHAB a bunch of times, cleared the cache, logged out and back into my Amazon account, removed and reinstalled the binding but nothing seems to fix it. I’m on OH 3.1 in the US.

funcat · October 1, 2021, 4:08pm

Just an update : at 17:52 today (UTC+2) the problem solves by itself, no more “web socket close”.
No restart (bundle nor OH), no action.

J-N-K · October 1, 2021, 4:12pm

It seems that Amazon fixed it (their own Alexa in Webbrowser had the same problem), but apparently they don‘t roll it out for everybody at the same time.

vguna · October 10, 2021, 8:45am

FYI: Just happened to me this morning (Germany). Already restarted OH. So let’s wait if it fixes itself…