Web Socket Error on AmazonEchoControl binding every 65 seconds

Many thanks Jan. It seems to be working for me too.
Chris

This is great news! Even if it is not a perfect, permanent fix, it seems we are in much better shape. Thank you so very much for taking so much of your time to troubleshoot and help come up with this working solution @J-N-K!

I was going to say, even though “LastVoiceCommand” wasn’t working, the data still was there, in the API. If you follow the link (updated of course with your own, local IP address and account key) that was provided in the Preview and Beta version of the Add-In, under the section:
"Advanced Feature Technically Experienced Users" http://openhab:8080/amazonechocontrol/account1/PROXY/api/activities?startTime=&size=50&offset=1

…you will still see your “LastVoiceCommand” data is present there in the API. I am not very proficient with coding, especially this type of coding, but I was thinking maybe Amazon had renamed a variable or changed a header or there was a cookie problem or something and maybe if you look at the API through this link that we could figure out what changed. But now it seems we are in good shape!.

That makes sense. I also checked the user agent but i was not able to see the real outgooing request on the lower level (jetty). Big thanks for the explanation, it helps me to understand. Tomorrow i will do the git pull and try to do the PR. If this webSocket issue didnt burn off your energy, maybe i can ask some more questions :wink:

A big thank you for taking the time and for delivering a binding without the OOM problem. And using your last version, i’m not receiving the INFO every 65 seconds any more. :slight_smile:

Warnings like mentioned eusblh are still there. But looking in older logs, i see them since month.

I just started to make use of the amazonecho binding some days ago. So i cannot say much about features not working.

I had the OOM error too.

After updating the binding on 2.4.0 OH2, I get this error every 60seconds still

] [internal.WebSocketConnection$Listener] - Web Socket error
org.eclipse.jetty.websocket.api.UpgradeException: 0 null
at org.eclipse.jetty.websocket.client.WebSocketUpgradeRequest.onComplete(WebSocketUpgradeRequest.java:522) ~[?:?]
at org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:216) ~[?:?]
at org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:208) ~[?:?]
at org.eclipse.jetty.client.HttpReceiver.terminateResponse(HttpReceiver.java:470) ~[?:?]
at org.eclipse.jetty.client.HttpReceiver.abort(HttpReceiver.java:552) ~[?:?]
at org.eclipse.jetty.client.HttpChannel.abortResponse(HttpChannel.java:156) ~[?:?]
at org.eclipse.jetty.client.HttpChannel.abort(HttpChannel.java:149) ~[?:?]
at org.eclipse.jetty.client.HttpExchange.abort(HttpExchange.java:257) ~[?:?]
at org.eclipse.jetty.client.HttpConversation.abort(HttpConversation.java:141) ~[?:?]
at org.eclipse.jetty.client.HttpRequest.abort(HttpRequest.java:767) ~[?:?]
at org.eclipse.jetty.client.http.HttpConnectionOverHTTP.abort(HttpConnectionOverHTTP.java:204) ~[?:?]
at org.eclipse.jetty.client.http.HttpConnectionOverHTTP.close(HttpConnectionOverHTTP.java:190) ~[?:?]
at org.eclipse.jetty.client.http.HttpConnectionOverHTTP.close(HttpConnectionOverHTTP.java:182) ~[?:?]
at java.util.ArrayList.forEach(ArrayList.java:1257) [?:?]
at org.eclipse.jetty.client.AbstractConnectionPool.close(AbstractConnectionPool.java:209) [71:org.eclipse.jetty.client:9.4.11.v20180605]
at org.eclipse.jetty.client.DuplexConnectionPool.close(DuplexConnectionPool.java:236) [71:org.eclipse.jetty.client:9.4.11.v20180605]
at org.eclipse.jetty.client.HttpDestination.close(HttpDestination.java:386) [71:org.eclipse.jetty.client:9.4.11.v20180605]
at org.eclipse.jetty.client.HttpClient.doStop(HttpClient.java:256) [71:org.eclipse.jetty.client:9.4.11.v20180605]
at org.eclipse.jetty.util.component.AbstractLifeCycle.stop(AbstractLifeCycle.java:89) [87:org.eclipse.jetty.util:9.4.11.v20180605]
at org.eclipse.jetty.util.component.ContainerLifeCycle.stop(ContainerLifeCycle.java:149) [87:org.eclipse.jetty.util:9.4.11.v20180605]
at org.eclipse.jetty.util.component.ContainerLifeCycle.doStop(ContainerLifeCycle.java:170) [87:org.eclipse.jetty.util:9.4.11.v20180605]
at org.eclipse.jetty.websocket.client.WebSocketClient.doStop(WebSocketClient.java:423) [91:org.eclipse.jetty.websocket.client:9.4.11.v20180605]
at org.eclipse.jetty.util.component.AbstractLifeCycle.stop(AbstractLifeCycle.java:89) [87:org.eclipse.jetty.util:9.4.11.v20180605]
at org.openhab.binding.amazonechocontrol.internal.WebSocketConnection.close(WebSocketConnection.java:171) [288:org.openhab.binding.amazonechocontrol:2.5.6.202006141340]
at org.openhab.binding.amazonechocontrol.internal.WebSocketConnection$2.run(WebSocketConnection.java:200) [288:org.openhab.binding.amazonechocontrol:2.5.6.202006141340]
at java.util.TimerThread.mainLoop(Timer.java:555) [?:?]
at java.util.TimerThread.run(Timer.java:505) [?:?]

I have loaded the 2.5.6-fix-leaks-fix-connection.jar file and I seem to be in much better shape! LastVoiceCommand is working again! However, none of my Alexa/Echo “Smart Home Devices” are working any longer - I’m assuming this is because this updated .jar was for the regular Add-On and is not for the Preview and Beta version of the add-on, right? Is there any way we can fix the connectivity issue in the Beta version as well? I can try to review the above posts describing what the issue was and how the add-on was fixed and see if I can copy these changes into the Beta version as well.

I’m getting the following error over and over, but I think I always get that anyway/I’m just going to ignore it for now:

20│2020-06-15 17:59:50.262 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.handleCommand()' on 'org.openhab.binding.amazonechocontrol.internal.handler.EchoHandler@57c87c': POST url │
20│'https://alexa.amazon.com/api/behaviors/preview' failed: Too Many Requests                                                                                                                                                              │
20│org.openhab.binding.amazonechocontrol.internal.HttpException: POST url 'https://alexa.amazon.com/api/behaviors/preview' failed: Too Many Requests                                                                                       │
20│        at org.openhab.binding.amazonechocontrol.internal.Connection.makeRequest(Connection.java:644) ~[?:?]                                                                                                                            │
20│        at org.openhab.binding.amazonechocontrol.internal.Connection.executeSequenceNode(Connection.java:1186) ~[?:?]                                                                                                                   │
20│        at org.openhab.binding.amazonechocontrol.internal.Connection.executeSequenceCommand(Connection.java:1171) ~[?:?]                                                                                                                │
20│        at org.openhab.binding.amazonechocontrol.internal.Connection.executeSequenceCommandWithVolume(Connection.java:1162) ~[?:?]                                                                                                      │
20│        at org.openhab.binding.amazonechocontrol.internal.Connection.sendAnnouncement(Connection.java:1133) ~[?:?]                                                                                                                      │
20│        at org.openhab.binding.amazonechocontrol.internal.handler.EchoHandler.startTextToSpeech(EchoHandler.java:722) ~[?:?]                                                                                                            │
20│        at org.openhab.binding.amazonechocontrol.internal.handler.EchoHandler.handleCommand(EchoHandler.java:577) ~[?:?]                                                                                                                │
20│        at sun.reflect.GeneratedMethodAccessor114.invoke(Unknown Source) ~[?:?]                                                                                                                                                         │
20│        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_252]                                                                                                                         │
20│        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_252]                                                                                                                                                              │
20│        at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]                                                                                         │
20│        at org.eclipse.smarthome.core.internal.common.InvocationHandlerSync.invoke(InvocationHandlerSync.java:59) [bundleFile:?]                                                                                                        │
20│        at com.sun.proxy.$Proxy521.handleCommand(Unknown Source) [?:?]                                                                                                                                                                  │
20│        at org.eclipse.smarthome.core.thing.internal.profiles.ProfileCallbackImpl.handleCommand(ProfileCallbackImpl.java:74) [bundleFile:?]                                                                                             │
20│        at org.eclipse.smarthome.core.thing.internal.profiles.SystemDefaultProfile.onCommandFromItem(SystemDefaultProfile.java:48) [bundleFile:?]                                                                                       │
20│        at sun.reflect.GeneratedMethodAccessor113.invoke(Unknown Source) ~[?:?]                                                                                                                                                         │
20│        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_252]                                                                                                                         │
20│        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_252]                                                                                                                                                              │
20│        at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]                                                                                         │
20│        at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]                                                                                                                                │
20│        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_252]                                                                                                                                                       │
20│        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_252]                                                                                                                                │
20│        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_252]                                                                                                                                │
20│        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252]

My log is filled with this too. Can someone link to the solution so I don’t have to read 200 posts?

2020-06-15 19:17:33.013 [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]

try the connection fixed jar, stop openhab, clean cache and tmp folder and put in this fixed jar seems to have stopped websocket error for amazon echo. Uninstalled the binding in paper ui first if you have installed before doing all this.

Thank you for the fix J-N-K

Uninstalled the old binding, put the new fix binding in, cleared cache and rebooted. Same issue

mine has been up 42 minutes and no more websocket error which i had every minute in the log.
cleaned tmp folder also?

Certainly did!

sudo /etc/init.d/openhab2 stop
sudo rm -rf /var/lib/openhab2/cache/*
sudo rm -rf /var/lib/openhab2/tmp/*
sudo /etc/init.d/openhab2 start

I see, the only things i did to fix this websocket error.

I removed the binding through Paper UI.
I’m running openhabian 2.5 headless so i just VNC into my pi3 b+ and manually cleaned the folder tmp and cache and dropped the jar in the addon folder and starting and stopping openhab in the terminal.

Fair enough, im using 2.4.0 but I doubt its different!

I’m running the latest fix version from today - 2.5.6-fix-leaks-fix-connection.jar - provided above. I cleaned my cache, restarted openHAB and my system several times and I am still seeing some sort of Web Socket Error, though it is not every 65 seconds but much less frequent:

2020-06-15 19:07:03.547 [WARN ] [trol.internal.handler.AccountHandler] - handling of websockets fails                                                                                                                                   │
20│org.openhab.binding.amazonechocontrol.internal.HttpException: GET url 'https://alexa.amazon.com/api/activities?startTime=1592266023415&size=10&offset=1' failed: Bad Request                                                            │
20│        at org.openhab.binding.amazonechocontrol.internal.Connection.makeRequest(Connection.java:644) ~[bundleFile:?]                                                                                                                   │
20│        at org.openhab.binding.amazonechocontrol.internal.Connection.makeRequestAndReturnString(Connection.java:499) ~[bundleFile:?]                                                                                                    │
20│        at org.openhab.binding.amazonechocontrol.internal.Connection.makeRequestAndReturnString(Connection.java:494) ~[bundleFile:?]                                                                                                    │
20│        at org.openhab.binding.amazonechocontrol.internal.Connection.getActivities(Connection.java:938) ~[bundleFile:?]                                                                                                                 │
20│        at org.openhab.binding.amazonechocontrol.internal.handler.AccountHandler.handlePushActivity(AccountHandler.java:773) ~[bundleFile:?]                                                                                            │
20│        at org.openhab.binding.amazonechocontrol.internal.handler.AccountHandler.handleWebsocketCommand(AccountHandler.java:718) ~[bundleFile:?]                                                                                        │
20│        at org.openhab.binding.amazonechocontrol.internal.handler.AccountHandler.webSocketCommandReceived(AccountHandler.java:706) [bundleFile:?]                                                                                       │
20│        at org.openhab.binding.amazonechocontrol.internal.WebSocketConnection$AmazonEchoControlWebSocket.onWebSocketBinary(WebSocketConnection.java:417) [bundleFile:?]                                                                 │
20│        at sun.reflect.GeneratedMethodAccessor93.invoke(Unknown Source) ~[?:?]                                                                                                                                                          │
20│        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_252]                                                                                                                         │
20│        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_252]                                                                                                                                                              │
20│        at org.eclipse.jetty.websocket.common.events.annotated.CallableMethod.call(CallableMethod.java:70) [bundleFile:9.4.20.v20190813]                                                                                                │
20│        at org.eclipse.jetty.websocket.common.events.annotated.OptionalSessionCallableMethod.call(OptionalSessionCallableMethod.java:72) [bundleFile:9.4.20.v20190813]                                                                  │
20│        at org.eclipse.jetty.websocket.common.events.JettyAnnotatedEventDriver.onBinaryMessage(JettyAnnotatedEventDriver.java:133) [bundleFile:9.4.20.v20190813]                                                                        │
20│        at org.eclipse.jetty.websocket.common.message.SimpleBinaryMessage.messageComplete(SimpleBinaryMessage.java:68) [bundleFile:9.4.20.v20190813]                                                                                    │
20│        at org.eclipse.jetty.websocket.common.events.AbstractEventDriver.appendMessage(AbstractEventDriver.java:65) [bundleFile:9.4.20.v20190813]                                                                                       │
20│        at org.eclipse.jetty.websocket.common.events.JettyAnnotatedEventDriver.onBinaryFrame(JettyAnnotatedEventDriver.java:125) [bundleFile:9.4.20.v20190813]                                                                          │
20│        at org.eclipse.jetty.websocket.common.events.AbstractEventDriver.incomingFrame(AbstractEventDriver.java:145) [bundleFile:9.4.20.v20190813]                                                                                      │
20│        at org.eclipse.jetty.websocket.common.WebSocketSession.incomingFrame(WebSocketSession.java:321) [bundleFile:9.4.20.v20190813]                                                                                                   │
20│        at org.eclipse.jetty.websocket.common.extensions.ExtensionStack.incomingFrame(ExtensionStack.java:202) [bundleFile:9.4.20.v20190813]                                                                                            │
20│        at org.eclipse.jetty.websocket.common.Parser.notifyFrame(Parser.java:226) [bundleFile:9.4.20.v20190813]                                                                                                                         │
20│        at org.eclipse.jetty.websocket.common.Parser.parseSingleFrame(Parser.java:262) [bundleFile:9.4.20.v20190813]                                                                                                                    │
20│        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.readParse(AbstractWebSocketConnection.java:582) [bundleFile:9.4.20.v20190813]                                                                              │
20│        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:441) [bundleFile:9.4.20.v20190813]                                                                             │
20│        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:428) [bundleFile:9.4.20.v20190813]                                                                             │
20│        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [bundleFile:9.4.20.v20190813]                                                                                                    │
20│        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) [bundleFile:9.4.20.v20190813]                                                                                                                              │
20│        at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:426) [bundleFile:9.4.20.v20190813]                                                                                                    │
20│        at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:320) [bundleFile:9.4.20.v20190813]                                                                                                                      │
20│        at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:158) [bundleFile:9.4.20.v20190813]                                                                                                                     │
20│        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) [bundleFile:9.4.20.v20190813]                                                                                                                              │
00│        at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117) [bundleFile:9.4.20.v20190813]                                                                                                                           │55
  │        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) [bundleFile:9.4.20.v20190813]                                                                                                         │
  │        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) [bundleFile:9.4.20.v20190813]                                                                                                       │
  │        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) [bundleFile:9.4.20.v20190813]                                                                                                      │
  │        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) [bundleFile:9.4.20.v20190813]                                                                                                             │
  │        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:367) [bundleFile:9.4.20.v20190813]                                                                                       │
  │        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:782) [bundleFile:9.4.20.v20190813]                                                                                                               │
  │        at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:918) [bundleFile:9.4.20.v20190813]                                                                                                           │
  │        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252]                                                                                

Additionally, none of my Alexa “Smart Home Devices” are working/I can’t turn the lights on/of in about half my of home, which is rather frustrating :disappointed:

Hopefully OH developers etc can repair whatever has occured with michi so we can get him onboard to help out - he’s the expert with this!

It would be super helpful if someone could link to where this new JAR file can be found…

Here is a link to the post above, by @J-N-K, where they posted the new jar file earlier today.

And here is a direct link to the jar file, provided in the aforementioned post. Note: this is for the Release Candidate version and not for the Preview/Beta (there is no support for the Alexa “Smart Home Devices” functionality that exists in the Beta version of the AmazonEchoControl binding).

1 Like

Thanks guys. That did the trick. Echo control is working and my logs aren’t exploding.