Web Socket Error on AmazonEchoControl binding every 65 seconds

[nephrotranz (Michael Elbers)]

Raspberry Pi 3b+ and OpenHABian 2.5.5.-1
Changed nothing in my configuration, absolutely no idea why I don’t have those memory leaks.
I never used LastVoiceCommand, don’t know if that could be a part of the solution.

[Tomy (Tom Ackermann)]

ah ok… thanks for your reply…

[Tomy (Tom Ackermann)]

Hi… can you give me more details about installing the new jar, maybe a “how to”??
I am new in the world of linux and i need a little bit support…

THX
Tom

[Flip]

Hi Tom,

you can login to the console with:

openhab-cli console

Then simply folow the Jan’s documentitaion here:

Web Socket Error on AmazonEchoControl binding every 65 seconds

Thanks for that hint. That helped a lot. What happens is: binding tries connect and immediately schedules a pong timeout after successfull connect, the pong is acknowledged and a ping is scheduled when the ping is send, a new pong timeout is scheduled (and acknowleged after the response is received) when pong times out, the connection is closed (this fails, if no connection was established) the binding tried to reconnect and we start from the beginning The problem is that - at least for me -…

Regards,
Flip

[nephrotranz (Michael Elbers)]

No idea why, I am on openHABian 2.5.5-1 on a Raspberry Pi 3B+
I just set the log level for the binding to INFO again, but I do not get any error messages.

The problem is that I do not have any idea about Linux or Java, so if I can help in any way, just let me know…

I am only getting an error message from the Amazon server (too many requests), when TTS is starting, but I got them already after installing the binding (that was the reason why I set the log level to ERROR).

[binderth (Thomas Binder)]

Running openHABian with openHAB 2.5.5-1 (Release Build) on a Raspberry PI4 / 4GB RAM.
Just after restarting:

##    Memory = Free: 3.00GB (78%), Used: 0.85GB (22%), Total: 3.86GB
##      Swap = Free: 0.09GB (100%), Used: 0.00GB (0%), Total: 0.09GB

I just updated to your Fix

openhab> bundle:list | grep Amazon
222 x Active   x  80 x 2.5.5                   x openHAB Add-ons :: Bundles :: Amazon Dash Button Binding
223 x Resolved x  80 x 2.5.5                   x openHAB Add-ons :: Bundles :: Amazon Echo Control Binding
openhab> bundle:update 223 https://janessa.me/esh/org.openhab.binding.amazonechocontrol-2.5.6-fixleaks.jar
openhab> bundle:list | grep Amazon
222 x Active   x  80 x 2.5.5                   x openHAB Add-ons :: Bundles :: Amazon Dash Button Binding
223 x Resolved x  80 x 2.5.6.202006141340      x openHAB Add-ons :: Bundles :: Amazon Echo Control Binding
openhab> bundle:start 223

Just to be clear, the log entry below will still occur, but OH 2.5.5. shouldn’t OOM anymore?

2020-06-15 10:03:19.958 [INFO ] [nternal.WebSocketConnection$Listener] - 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:171) [bundleFile:?]
	at org.openhab.binding.amazonechocontrol.internal.WebSocketConnection$2.run(WebSocketConnection.java:200) [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]

I’ll report what’s going on. Had a OOM-crash every day now since friday - and didn’t change a thing in OH-config in the last three weeks or so.

[Tomy (Tom Ackermann)]

thx Flip… i will try and give a feedback if it works and solved for me.

[David_Gre (David Greiwe)]

If I write “bundle:list | grep -i amazon” in my console, I get the following response:
“-bash: bundle:list: command not found”

[Flip]

Did you login the the openhab console first?

openhab-cli console

[David_Gre (David Greiwe)]

Yes, I think so.

EDIT:
Now it works. First I have to write the command “bundle:list” and then “bundle:list | grep -i amazon”.
Strange. However, now I will try the solution from Jan.

EDIT2:
The Web socket error still appears in the log

[yab (Marino Schwedhelm)]

As stated above from our helpful guys, the log entry is still generated because the problem is still there. What Jan could do is stopping the binding to generate the OutOfMemory (OOM) situation, which requires to restart openhab or the complete system (and might even give you some more headache when running on a raspi).

So the only thing to do ATM is to disable the binding or to live with the logentry (and possibly to miss some functionality) until someone is able to to find out what has been changed on the amzaon side and adjusts the binding code.

Stay patient.

[chimera]

…ah you just beat me to pretty much exactly the same reply

Yes, this post is only 3 days old… so patience until it’s worked out! Although running:

free -h

on Rpi still shows RAM reducing even after applying the workaround. Could possibly be something else though

[Tomy (Tom Ackermann)]

i think you have to login in the karaf console at first (openhab-cli console, then the pw) and after bundle list install the fix…

that works for me, the memory leak is gone, the error message is not into my focus…

thanks nephrotranz, Flip and J-N-K

[Wikibear (Swen)]

If you type anything in Linux case sensitive is important. After Info setting or debug restart Binding to take effect…

[sjheinz (stefan heinz)]

Hi,

i have the web Socket error to in OPENHAB 2.5.5-1 disused in
Java heap space…java.lang.OutOfMemoryError
and
Web Socket error {}

now i was pointed to this post. (I closed the other ones pointing them to this posed to bring everything together!)

The error is still there!
See:

2020-06-15 14:06:04.943 [INFO ] [nternal.WebSocketConnection$Listener] - 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_252]
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:171) [bundleFile:?]
at org.openhab.binding.amazonechocontrol.internal.WebSocketConnection$2.run(WebSocketConnection.java:200) [bundleFile:?]
at java.util.TimerThread.mainLoop(Timer.java:555) [?:1.8.0_252]
at java.util.TimerThread.run(Timer.java:505) [?:1.8.0_252]

The new jar-file did not help!

And there is a new quality in town: after a periode of time: Openhab crashes with another warning:
2020-06-12 22:56:28.026 [WARN ] [org.eclipse.jetty.server.HttpChannel] - /start/index
java.lang.OutOfMemoryError: Java heap space
2020-06-12 22:56:38.624 [WARN ] [org.eclipse.jetty.server.HttpChannel] - /start/index
java.lang.OutOfMemoryError: Java heap space

So there is a new qualitiy in town!! System crash!!!

Please have a look and help!

Thanks
Cheers
Stef

[J-N-K (Jan N. Klug)]

The OOM is from 2020-06-12, so this is clearly from the release version. This is fixed with the version above and will not happen anymore.

As I said before: the bundle above is NOT fixing the root issue (websocket connection fails) but ONLY fixing the erroneous closing of a failed connection which lead to the OOM.

[sjheinz (stefan heinz)]

Fine to hear,

but error is again still there… maybe someone which has build the fix last time have a look to.!!!
And should know that there is a major issue!!

An now - read carefully - there is an other quality in town: SYSTEM CRASH
…
Thank you

[sjheinz (stefan heinz)]

and btw: pleas explain OOM it´s helpfull for everybody to know what you are talking about
Cheers and Thanks
Stef

[J-N-K (Jan N. Klug)]

Maybe you should read my post more closely. The system crash is due to the OOM-exception (your log from 2020-06-12). This is fixed above. The connection error is still there and needs to be fixed independently.

Edit: OOM = Out-Of-Memory.

[sjheinz (stefan heinz)]

And it was a hint in Java heap space…java.lang.OutOfMemoryError from CM6.5 H102Regular which i followed to fix…
…
…
Cheers
Stef