Preview and Beta: Amazon Echo Control

richaardvark · June 20, 2020, 8:00pm

I tried to restore a .zip backup and it said everything had been successfully restored, but nothing is running still. It’s just dead, lol. I may just purge openHAB and then restore my backup and try again, and not update the gson if it’s not a good idea.

I’m not sure exactly which version it installed, but I’ll stick with 8. I’m on a 64-bit machine, but I think openHAB wants the 32-bit java for some reason, so I’ll try that and then install your latest .jar binding.

These are the java versions available in openHABian:
│ [ ] 63 | Zulu 8 OpenJDK 32-bit Install Zulu 8 32-bit OpenJDK as primary Java provider │
│ [ ] | Zulu 8 OpenJDK 64-bit Install Zulu 8 64-bit OpenJDK as primary Java provider │
│ [ ] | Zulu 11 OpenJDK 32-bit Install Zulu 11 32-bit OpenJDK as primary Java provider (beta) │
│ [ ] | Zulu 11 OpenJDK 64-bit Install Zulu 11 64-bit OpenJDK as primary Java provider (beta) │
│ [ ] | AdoptOpenJDK 11 Install AdoptOpenJDK 11 as primary Java provider (beta) │

Andrew_Rowe · June 20, 2020, 8:01pm

I think it does, which as you say, may not be a good idea

J-N-K · June 20, 2020, 8:02pm

I have never used 32-bit. OTOH, I don’t know about openhabian, so there may be issues with 64bit that I’m not aware of.

The 2.8.5 is only needed on pre-OH 2.5 systems, which provide GSON 2.7 by default.

richaardvark · June 20, 2020, 8:14pm

I’m kind of totally baffled at this point… I completely purged openHAB from my system. Started fresh from scratch using openHABian and installed a clean-install, java reinstalled and everything. Rebooted. And still, it’s totally stuck/won’t start and shows the same weird error:

richard@HomeServer:~
$ ohstat
● openhab2.service - openHAB 2 - empowering the smart home
   Loaded: loaded (/lib/systemd/system/openhab2.service; enabled; vendor preset: enabled)
  Drop-In: /etc/systemd/system/openhab2.service.d
           └─override.conf
   Active: activating (start-post) (Result: exit-code) since Sat 2020-06-20 15:09:17 CDT; 1min 4s ago
     Docs: https://www.openhab.org/docs/
           https://community.openhab.org
  Process: 18842 ExecStartPre=/bin/bash -c /usr/bin/find ${OPENHAB_CONF} -name "*.rules" -exec /usr/bin/rename.ul .rules .x {} \; (code=exited, status=0/SUCCESS)
  Process: 18845 ExecStart=/usr/share/openhab2/runtime/bin/karaf ${OPENHAB_STARTMODE} (code=exited, status=127)
 Main PID: 18845 (code=exited, status=127); Control PID: 18846 (sleep)
    Tasks: 1 (limit: 4290)
   Memory: 3.2M
   CGroup: /system.slice/openhab2.service
           └─18846 /bin/sleep 120

Jun 20 15:09:17 HomeServer systemd[1]: Starting openHAB 2 - empowering the smart home...
Jun 20 15:09:17 HomeServer karaf[18845]: /usr/share/openhab2/runtime/bin/karaf: 247: [: Illegal number:
Jun 20 15:09:17 HomeServer karaf[18845]: /usr/share/openhab2/runtime/bin/karaf: 247: [: Illegal number:
Jun 20 15:09:17 HomeServer karaf[18845]: /usr/share/openhab2/runtime/bin/karaf: 95: [: Illegal number:
Jun 20 15:09:17 HomeServer karaf[18845]: /usr/share/openhab2/runtime/bin/karaf: 296: [: Illegal number:
Jun 20 15:09:17 HomeServer karaf[18845]: /usr/bin/java: error while loading shared libraries: libjli.so: cannot open shared object file: No such file or directory
Jun 20 15:09:17 HomeServer systemd[1]: openhab2.service: Main process exited, code=exited, status=127/n/a

There must be some directories somewhere that will need to be manually deleted to truly purge the system of openHAB. I used the command “sudo apt-get purge openhab2 openhab2-addons openhab2-addons-legacy” but apparently this is not enough.

J-N-K · June 20, 2020, 8:23pm

Are you sure you reverted to java8? There are three directories: /etc/openhab2, /var/lib/openhab2 and /usr/share/openhab2

The first contains user configuration, the second cache, dynamic configuration etc. and the last files needed to boot openHAB.

richaardvark · June 20, 2020, 8:50pm

Yes, I manually selected java8. Java would be in different directories though, right?

spends a moment Googling Java/error codes

I think I have found the problem. Apparently I currently somehow have 10 different versions of Java installed:

* 0            /usr/lib/jvm/zulu-14-amd64/bin/java                           1142800   auto mode
  1            /opt/jdk/zulu8.46.0.19-ca-fx-jre8.0.252-linux_i686/bin/java   1000000   manual mode
  2            /usr/lib/jvm/zulu-10-amd64/bin/java                           1100300   manual mode
  3            /usr/lib/jvm/zulu-11-amd64/bin/java                           1113900   manual mode
  4            /usr/lib/jvm/zulu-12-amd64/bin/java                           1120300   manual mode
  5            /usr/lib/jvm/zulu-13-amd64/bin/java                           1133100   manual mode
  6            /usr/lib/jvm/zulu-14-amd64/bin/java                           1142800   manual mode
  7            /usr/lib/jvm/zulu-6-amd64/bin/java                            1062200   manual mode
  8            /usr/lib/jvm/zulu-7-amd64/jre/bin/java                        1073800   manual mode
  9            /usr/lib/jvm/zulu-8-amd64/jre/bin/java                        1084600   manual mode
  10           /usr/lib/jvm/zulu-9-amd64/bin/java                            1090007   manual mode

I’m going to purge all java and reinstall, go from there…

J-N-K · June 20, 2020, 8:54pm

sudo update-alternatives --config java and selecting the zulu-8 should be enough.

richaardvark · June 20, 2020, 10:11pm

I got it running again and restored a backup. Then I used your updated Beta .jar from the link above. Cleaned the cache, restarted X3, rebooted. At one point the Echo “Smart Home Devices” were working again!! But when they were working, the “LastVoiceCommand” wasn’t working Though, LVC was working earlier today when I installed your original Beta .jar. I then decided to try clearing the cache once again, restarting/rebooting again. And now neither the “LastVoiceCommand” nor the Echo devices are working Just says “NULL” for everything.

Should I try updating the gson again?

Andrew_Rowe · June 20, 2020, 11:14pm

I’m sorry, I didn’t catch what version of OH you are on but that was done by an individual who was running 2.4 I think

richaardvark · June 21, 2020, 12:27am

I am currently running 2.5.5 Release Build.

Right now, my Echo devices (Echo Dots) are showing as online, but no Smart Home Devices work. All say “NULL” / have no data. And now the “LastVoiceCommand” are no longer working as well. The original .jar before you updated it earlier today did have the LastVoiceCommand feature working again. I’m not showing any errors whatsoever in any logs :-/

Edit: I removed the “Amazon Account” thing and tried to add it back but now it’s just stuck as “uninitialized.” It’s not asking me to log in to the Amazon account like it normally does, just says “uninitialized.” When I go to the http://localhost:8080/amazonechocontrol/ URL, it says “No Account thing created” but I do have one created.

Edit 2: After a reboot, I was able to get my Amazon account to log back in. Many of my “Smart Home Devices” are now showing as “ONLINE” in the log/PaperUI! But none of them are actually turning on or off when a command is sent. And the “LastVoiceCommand” feature is still not working. I’ve logged out and back into my Amazon account at the setup URL but nothing changes. No errors showing in the log either.

Edit 3 (lol sorry!): All of a sudden - boom! - everything suddenly appeared! Seeing if it is working now…

It’s doing strange things… All of my devices have loaded, but they each show up as “Unknown Device”.. The Amazon Account Thing shows as “Online” and even some of the Smart Home Devices/Groups show as “Online,” but the items all say “Unknown Device” and nothing works. I’ll try logging out of Amazon again, adding it back, rebooting again…

Edit 4: I’ve tried so many things but am giving up for tonight. The Amazon devices all appear in the inbox in PaperUI as soon as the account is signed in, but they all say “Unknown Device.” The first binding you shared earlier @J-N-K seemed to work better but the update you made seems to have resulted in our being in worse shape than we originally were with your first Beta binding jar file. I didn’t save a local copy of that first version on my machine and wish I had…

I’ll try again tomorrow… thank you again for you help!

J-N-K · June 21, 2020, 8:29am

I don’t think there are any changes that should affect the functionality between both versions. I added some debug logging and updated the .jar. Please makes sure you have TRACE logging enabled for org.openhab.binding.amazonechocontrol.

richaardvark · June 21, 2020, 2:05pm

Thank you - I wasn’t familiar with TRACE logging - what a very neat/helpful feature! I enabled the logging as you instructed.

I am running your latest Beta .jar binding. I have openHAB online, and my Echo Dots are identified and are online. It seems the “SmartHomeDevices” are once again working! However, the “LastVoiceCommand” feature is not working.

There are many many many logs now that TRACE logging is enabled. I’d hate to paste all of that data here, unless you think that is best? I’m trying to go through it, looking for anything odd. I was getting more of the Web Socket Errors at first, but they seem to have stopped. If I can just get the LastVoiceCommand feature working again, I’m in good shape.

The TRACE logging is showing that HTTP Requests are going back and fourth to Amazon servers, every few seconds, re-querying over and over again every little variable.

J-N-K · June 21, 2020, 2:09pm

You can revert to DEBUG to make it less verbose. So everything except the lastVoiceCommand works as expected? That‘s very good news.

Edit: if it‘s only lastVoiceCommand, I‘ll provide a special jar to debug that.

richaardvark · June 21, 2020, 2:20pm

I set the logging to DEBUG but the log is still flying through so fast I can’t hardly capture anything. I do see what appears to be the classic Web Socket Error, but when I try to grab it super quickly into my clipboard, it flies away because these are happinging over and over:

2020-06-21 09:11:33.208 [DEBUG] [trol.internal.handler.AccountHandler] - refresh data amazonechocontrol:account:20e3dd5f finished
2020-06-21 09:11:33.210 [DEBUG] [trol.internal.handler.AccountHandler] - checkData amazonechocontrol:account:20e3dd5f finished
2020-06-21 09:11:39.811 [DEBUG] [trol.internal.handler.AccountHandler] - updateSmartHomeState started
2020-06-21 09:11:49.812 [DEBUG] [trol.internal.handler.AccountHandler] - updateSmartHomeState started
2020-06-21 09:11:59.813 [DEBUG] [trol.internal.handler.AccountHandler] - updateSmartHomeState started

And then every time those run, there is a HTTP Request response in blue text, that has every little Amazon variable ever. I might need to disable the logging altogether for a moment.

Yes!! My lights/devices are pulling in properly from Amazon and I am able to control them with openHAB. (For example, I can use a URL such as this / send a command with a rule and the Alexa device responds as it should )

Edit / Discovered Something Else:

I went to turn off the logging and ran the l"og:get" command in the cli console and it shows a lot of errors but also very strangely it shows the AmazonEchoControl binding listed twice, with two different logging levels currently activated, except one of the EchoControl bindings has the name chopped off. Is this normal, or perhaps why things are wonky?

openhab> log:get
Logger                                             │ Level
───────────────────────────────────────────────────┼──────
ROOT                                               │ WARN
javax.jmdns                                        │ ERROR
org.apache.karaf.jaas.modules.audit                │ INFO
org.apache.karaf.kar.internal.KarServiceImpl       │ ERROR
org.apache.karaf.shell.support                     │ OFF
org.eclipse.lsp4j                                  │ OFF
org.eclipse.smarthome                              │ INFO
org.jupnp                                          │ ERROR
org.openhab                                        │ INFO
org.openhab.binding.amazonechoco                   │ DEBUG
org.openhab.binding.amazonechocontrol              │ TRACE
org.ops4j.pax.url.mvn.internal.AetherBasedResolver │ ERROR
org.ops4j.pax.web.pax-web-runtime                  │ OFF
smarthome.event                                    │ INFO
smarthome.event.InboxUpdatedEvent                  │ ERROR
smarthome.event.ItemAddedEvent                     │ ERROR
smarthome.event.ItemRemovedEvent                   │ ERROR
smarthome.event.ItemStateEvent                     │ ERROR
smarthome.event.ThingAddedEvent                    │ ERROR
smarthome.event.ThingRemovedEvent                  │ ERROR
smarthome.event.ThingStatusInfoEvent               │ ERROR

richaardvark · June 21, 2020, 2:26pm

I’m dumb: that must mean it’s providing a log when there are errors, not that there currently are errors. But should there be two EchoControl bindings?

Never mind… I’m AM an idiot… I caused that duplicate logging level because I made a typo when trying to set echocontrol from TRACE to DEBUG. That’s why I was still seeing so much in the log. All fixed now.

richaardvark · June 21, 2020, 2:36pm

Hooray! I captured the “LastVoiceCommand” error

Whenever I speak to any of my Echo devices, the following error immediately shows in the log:

2020-06-21 09:32:55.105 [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_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: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_252]
	at java.util.TimerThread.run(Timer.java:505) [?:1.8.0_252]
2020-06-21 09:34:13.865 [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_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: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_252]
	at java.util.TimerThread.run(Timer.java:505) [?:1.8.0_252]

Is it just me or does this look somewhat familiar?

Another Edit:

Sorry for yet another reply to you… (Is it best to keep the same reply and just edit it? I’m not sure the forum would properly notify you if I replied by way of editing and reusing my reply post… Sorry, I’m learning a lot here!)

… lol! Nevermind - the forum software answered my own question for me when I tried to reply again just now:

“No more than 3 consecutive replies are allowed. Please edit your previous reply, or wait for someone to reply to you.”

Got it! …

Actual, hopefully helpful error-logging info: I turned TRACE logging back on, quickly asked Alexa what time it is, and then turned it back off. The following error appeared in the log (and must be the real culprit of what is causing the issue/Web Socket Error):

2020-06-21 09:51:35.949 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.handleCommand()' on 'org.openhab.binding.amazonechocontrol.internal.handler.EchoHandler@32bd27cd': POST url 'https://alexa.amazon.com/api/behaviors/preview' failed: Too Many Requests
org.openhab.binding.amazonechocontrol.internal.HttpException: POST url 'https://alexa.amazon.com/api/behaviors/preview' failed: Too Many Requests
	at org.openhab.binding.amazonechocontrol.internal.Connection.makeRequest(Connection.java:654) ~[?:?]
	at org.openhab.binding.amazonechocontrol.internal.Connection.executeSequenceNode(Connection.java:1470) ~[?:?]
	at org.openhab.binding.amazonechocontrol.internal.Connection.executeSequenceNodes(Connection.java:1479) ~[?:?]
	at org.openhab.binding.amazonechocontrol.internal.Connection.executeSequenceCommandWithVolume(Connection.java:1444) ~[?:?]
	at org.openhab.binding.amazonechocontrol.internal.Connection.sendAnnouncement(Connection.java:1417) ~[?:?]
	at org.openhab.binding.amazonechocontrol.internal.handler.EchoHandler.startAnnouncment(EchoHandler.java:762) ~[?:?]
	at org.openhab.binding.amazonechocontrol.internal.channelhandler.ChannelHandlerAnnouncement.tryHandleCommand(ChannelHandlerAnnouncement.java:92) ~[?:?]
	at org.openhab.binding.amazonechocontrol.internal.handler.EchoHandler.handleCommand(EchoHandler.java:276) ~[?:?]
	at sun.reflect.GeneratedMethodAccessor129.invoke(Unknown Source) ~[?:?]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_252]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_252]
	at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
	at org.eclipse.smarthome.core.internal.common.InvocationHandlerSync.invoke(InvocationHandlerSync.java:59) [bundleFile:?]
	at com.sun.proxy.$Proxy627.handleCommand(Unknown Source) [?:?]
	at org.eclipse.smarthome.core.thing.internal.profiles.ProfileCallbackImpl.handleCommand(ProfileCallbackImpl.java:74) [bundleFile:?]
	at org.eclipse.smarthome.core.thing.internal.profiles.SystemDefaultProfile.onCommandFromItem(SystemDefaultProfile.java:48) [bundleFile:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_252]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_252]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_252]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_252]
	at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
	at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_252]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_252]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_252]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252]
2020-06-21 09:51:35.995 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.handleCommand()' on 'org.openhab.binding.amazonechocontrol.internal.handler.EchoHandler@5dee1a1': POST url 'https://alexa.amazon.com/api/behaviors/preview' failed: Too Many Requests
org.openhab.binding.amazonechocontrol.internal.HttpException: POST url 'https://alexa.amazon.com/api/behaviors/preview' failed: Too Many Requests
	at org.openhab.binding.amazonechocontrol.internal.Connection.makeRequest(Connection.java:654) ~[?:?]
	at org.openhab.binding.amazonechocontrol.internal.Connection.executeSequenceNode(Connection.java:1470) ~[?:?]
	at org.openhab.binding.amazonechocontrol.internal.Connection.executeSequenceNodes(Connection.java:1479) ~[?:?]
	at org.openhab.binding.amazonechocontrol.internal.Connection.executeSequenceCommandWithVolume(Connection.java:1444) ~[?:?]
	at org.openhab.binding.amazonechocontrol.internal.Connection.sendAnnouncement(Connection.java:1417) ~[?:?]
	at org.openhab.binding.amazonechocontrol.internal.handler.EchoHandler.startAnnouncment(EchoHandler.java:762) ~[?:?]
	at org.openhab.binding.amazonechocontrol.internal.channelhandler.ChannelHandlerAnnouncement.tryHandleCommand(ChannelHandlerAnnouncement.java:92) ~[?:?]
	at org.openhab.binding.amazonechocontrol.internal.handler.EchoHandler.handleCommand(EchoHandler.java:276) ~[?:?]
	at sun.reflect.GeneratedMethodAccessor129.invoke(Unknown Source) ~[?:?]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_252]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_252]
	at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
	at org.eclipse.smarthome.core.internal.common.InvocationHandlerSync.invoke(InvocationHandlerSync.java:59) [bundleFile:?]
	at com.sun.proxy.$Proxy639.handleCommand(Unknown Source) [?:?]
	at org.eclipse.smarthome.core.thing.internal.profiles.ProfileCallbackImpl.handleCommand(ProfileCallbackImpl.java:74) [bundleFile:?]
	at org.eclipse.smarthome.core.thing.internal.profiles.SystemDefaultProfile.onCommandFromItem(SystemDefaultProfile.java:48) [bundleFile:?]
	at sun.reflect.GeneratedMethodAccessor148.invoke(Unknown Source) ~[?:?]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_252]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_252]
	at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
	at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_252]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_252]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_252]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252]
2020-06-21 09:52:12.987 [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_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: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_252]
	at java.util.TimerThread.run(Timer.java:505) [?:1.8.0_252]
2020-06-21 09:52:55.781 [DEBUG] [trol.internal.handler.AccountHandler] - updateSmartHomeState started
2020-06-21 09:53:05.783 [DEBUG] [trol.internal.handler.AccountHandler] - updateSmartHomeState started
2020-06-21 09:53:15.789 [DEBUG] [trol.internal.handler.AccountHandler] - updateSmartHomeState started
2020-06-21 09:53:25.790 [DEBUG] [trol.internal.handler.AccountHandler] - updateSmartHomeState started
2020-06-21 09:53:29.755 [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_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: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_252]
	at java.util.TimerThread.run(Timer.java:505) [?:1.8.0_252]

Another edit/update for you, @J-N-K: Linux showed several pending updates and so I ran an “apt-get update / upgrade” and noticed there was also an openHAB update that happened. I rebooted my system just to start fresh and now I am no longer able to get the EchoControl “Smart Home Devices” working They aren’t responding, show “NULL.” And now I have a new error displayed in my log:

io.socket.engineio.client.EngineIOException: xhr poll error
	at io.socket.engineio.client.Transport.onError(Transport.java:63) [bundleFile:?]
	at io.socket.engineio.client.transports.PollingXHR.access$100(PollingXHR.java:26) [bundleFile:?]
	at io.socket.engineio.client.transports.PollingXHR$6$1.run(PollingXHR.java:140) [bundleFile:?]
	at io.socket.thread.EventThread$2.run(EventThread.java:80) [bundleFile:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_252]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_252]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252]
Caused by: java.net.SocketTimeoutException: timeout
	at okio.Okio$4.newTimeoutException(Okio.java:230) ~[?:?]
	at okio.AsyncTimeout.exit(AsyncTimeout.java:285) ~[?:?]
	at okio.AsyncTimeout$2.read(AsyncTimeout.java:241) ~[?:?]
	at okio.RealBufferedSource.indexOf(RealBufferedSource.java:345) ~[?:?]
	at okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:217) ~[?:?]
	at okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:211) ~[?:?]
	at okhttp3.internal.http1.Http1Codec.readResponseHeaders(Http1Codec.java:189) ~[?:?]
	at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.java:75) ~[?:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[?:?]
	at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:45) ~[?:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[?:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[?:?]
	at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:93) ~[?:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[?:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[?:?]
	at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93) ~[?:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[?:?]
	at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:120) ~[?:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[?:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[?:?]
	at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:185) ~[?:?]
	at okhttp3.RealCall$AsyncCall.execute(RealCall.java:135) ~[?:?]
	at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32) ~[?:?]
	... 3 more
Caused by: java.net.SocketException: Socket closed
	at java.net.SocketInputStream.read(SocketInputStream.java:204) ~[?:1.8.0_252]
	at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[?:1.8.0_252]
	at sun.security.ssl.InputRecord.readFully(InputRecord.java:465) ~[?:1.8.0_252]
	at sun.security.ssl.InputRecord.read(InputRecord.java:503) ~[?:1.8.0_252]
	at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:990) ~[?:1.8.0_252]
	at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:948) ~[?:1.8.0_252]
	at sun.security.ssl.AppInputStream.read(AppInputStream.java:105) ~[?:1.8.0_252]
	at okio.Okio$2.read(Okio.java:139) ~[?:?]
	at okio.AsyncTimeout$2.read(AsyncTimeout.java:237) ~[?:?]
	at okio.RealBufferedSource.indexOf(RealBufferedSource.java:345) ~[?:?]
	at okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:217) ~[?:?]
	at okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:211) ~[?:?]
	at okhttp3.internal.http1.Http1Codec.readResponseHeaders(Http1Codec.java:189) ~[?:?]
	at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.java:75) ~[?:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[?:?]
	at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:45) ~[?:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[?:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[?:?]
	at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:93) ~[?:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[?:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[?:?]
	at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93) ~[?:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[?:?]
	at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:120) ~[?:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[?:?]
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[?:?]
	at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:185) ~[?:?]
	at okhttp3.RealCall$AsyncCall.execute(RealCall.java:135) ~[?:?]
	at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32) ~[?:?]
	... 3 more

and also:

2020-06-21 15:11:30.685 [WARN ] [okhttp3.OkHttpClient                ] - A connection to https://myopenhab.org/ was leaked. Did you forget to close a response body? To see where this was allocated, set the OkHttpClient logger level to FIN
E: Logger.getLogger(OkHttpClient.class.getName()).setLevel(Level.FINE);
2020-06-21 15:11:30.686 [WARN ] [okhttp3.OkHttpClient                ] - A connection to https://myopenhab.org/ was leaked. Did you forget to close a response body? To see where this was allocated, set the OkHttpClient logger level to FIN
E: Logger.getLogger(OkHttpClient.class.getName()).setLevel(Level.FINE);
2020-06-21 15:11:30.687 [WARN ] [okhttp3.OkHttpClient                ] - A connection to https://myopenhab.org/ was leaked. Did you forget to close a response body? To see where this was allocated, set the OkHttpClient logger level to FIN
E: Logger.getLogger(OkHttpClient.class.getName()).setLevel(Level.FINE);

Andrew_Rowe · June 21, 2020, 3:05pm

Nothing to add but just want to say good on you Richard for working hard to fix your problem and…
@J-N-K
Jan you are truly an asset to this community
Even thou you don’t use this binding, your contribution is appreciated by so many in this community that do. I know some people don’t like using cloud connected devices but if you would like, I would like to offer to buy you an echo device if you would like one to use for development or whatever if you would like one since you mentioned you do not own one. Please feel free to PM an address and it will be on its way! If not, please accept the appreciation of your hard work, maybe I can buy you a beer or coffee. I’m sure many in the community would agree!

richaardvark · June 21, 2020, 3:15pm

This is a very sweet and very fitting gesture! We really are very grateful for your help @J-N-K! I’m happy to contribute toward this as well!! Great idea and very awesome of you to suggest this, @Andrew_Rowe!

roy_liao · June 21, 2020, 9:48pm

Thanks so much to @J-N-K for rebuilding this. I’ve been on the September 2019 version on OH 2.5 for a long while until the recent problems.

I tried this updated JAR last night but couldn’t get it working. After clearing cache and tmp, the binding still errored out saying no account thing existed. I didn’t get to focus on troubleshooting the logs yet, so I’ll try again soon.

For reference, when I updated to the JAR from the mainline thread, it worked ok as a drop in replacement.

mstormi · June 21, 2020, 10:19pm

Does the just released version in 2.5.6 have the issue fixed ? The release notes at least indicate this.