Preview and Beta: Amazon Echo Control

J-N-K · June 23, 2020, 7:53pm

I have prepared https://janessa.me/esh/org.openhab.binding.amazonechocontrol-2.5.6-f4.jar, IMO this has code issues fixed and is ready for review.

Andrew_Pawelski · June 24, 2020, 1:54am

what is f4 addressing?

J-N-K · June 24, 2020, 6:25am

Several issues that could result in exceptions (probably not as catastrophic as the OOM we experienced earlier). In most cases These are related to wrong or corrupted responses from the server that could result in null-objects.

fanavity · June 24, 2020, 7:13am

@J-N-K YOU ARE AWESOME! Thank you very much!!

Andrew_Pawelski · June 25, 2020, 1:11pm

f4 working fine for me!

ThomasOH · June 25, 2020, 4:13pm

I’ve been using org.openhab.binding.amazonechocontrol-2.5.6-SNAPSHOT.jar with good success. But I can’t get amazonechocontrol-2.5.6-f4.jar to work.

Some info:
1.I’m running openHAB 2.4.0 (build #1412) on a RaspberryPi. It was using the amazonechocontrol_2.5.0.Beta_07_Preview_1, but recently updated to amazonechocontrol-2.5.6-SNAPSHOT.

To install the F4 binding I used the instructions posted here to : Web Socket Error on AmazonEchoControl binding every 65 seconds
The amazonechocontrol web page is not populated with devices.
Although Gson 2.8.5 library is installed, the new binding seems to be complaining that he library is unresolved. Here is the log:
2020-06-24 14:20:21.340 [WARN ] [org.apache.felix.fileinstall ] - Error while starting bundle: file:/usr/share/openhab2/addons/org.openhab.binding.amazonechocontrol.jar
org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.amazonechocontrol [137]
Unresolved requirement: Import-Package: com.google.gson; version="[2.8.0,3.0.0)"
at org.eclipse.osgi.container.Module.start(Module.java:444) ~[?:?]
at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) ~[?:?]
at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1260) [10:org.apache.felix.fileinstall:3.6.4]
at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1233) [10:org.apache.felix.fileinstall:3.6.4]
at org.apache.felix.fileinstall.internal.DirectoryWatcher.startAllBundles(DirectoryWatcher.java:1221) [10:org.apache.felix.fileinstall:3.6.4]
at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:515) [10:org.apache.felix.fileinstall:3.6.4]
at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:365) [10:org.apache.felix.fileinstall:3.6.4]
at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:316) [10:org.apache.felix.fileinstall:3.6.4]
Before the F4 installation I had checked the Gson (list | grep -i gson) and it reported this:
21 x Active x 80 x 2.7.0.v20170129-0911 x Gson: Google Json Library for Java
234 x Resolved x 80 x 2.8.5 x Gson
Reverting back to amazonechocontrol-2.5.6-SNAPSHOT required a full system restore from an archive. That is to say, reinstalling the previous working jar did not go well (Openhab did not run and no log file was generated).

Thomas

J-N-K · June 25, 2020, 4:19pm

Sorry, I can’t and will not provide support for OH 2.4. Please update to 2.5 and check if it works there. Mixing bundle versions often results in problems.

ThomasOH · June 25, 2020, 4:37pm

Understood. Updating to OH2.5 will have to wait until I have more time to deal with any issues that may arise.

Thomas

Giga522 · June 26, 2020, 10:20pm

Im not sure how to proceed with this error now:
[ERROR] [rnal.common.AbstractInvocationHandler] - An error occurred while calling method ‘ThingHandler.handleCommand()’ on ‘org.openhab.binding.amazonechocontrol.internal.handler.EchoHandler@c2a038’: POST url ‘https://alexa.amazon.de/api/behaviors/preview’ failed: Too Many Requests

How can i fix this. There are not too many requests but it still triggers me. Will this log be fixed or how can i disable these messages. i coud not solve it with:
log:set OFF control.internal.handler.AccountHandler

Thanks in advance!

Andrew_Rowe · June 26, 2020, 11:26pm

this is a know issue being worked on and I think otherwise harmless

RalphSester · June 30, 2020, 5:55am

Hi @michi,

since a few days, the LastVoiceCommand-Channel is not triggered anymore when talking to the devices. Are there changes in the api from amazon or other changes?

Can you confirm this?

Thanks!
Ralph

kamikatze13 · July 2, 2020, 5:31pm

I wouldn’t call it harmless because on my end it leads to commands fizzle and fail, e.g.:

EchoPlus_Routine.sendCommand("mach sauber") doesn’t trigger the appropriate routine, all i get is

2020-07-02 19:17:34.086 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.handleCommand()' on 'org.openhab.binding.amazonechocontrol.internal.handler.EchoHandler@1884e3c': GET url 'https://alexa.amazon.de/api/behaviors/automations?limit=2000' failed: Too Many Requests

org.openhab.binding.amazonechocontrol.internal.HttpException: GET url 'https://alexa.amazon.de/api/behaviors/automations?limit=2000' failed: Too Many Requests

at org.openhab.binding.amazonechocontrol.internal.Connection.makeRequest([Connection.java:649](http://connection.java:649/)) ~[?:?]

at org.openhab.binding.amazonechocontrol.internal.Connection.makeRequestAndReturnString([Connection.java:505](http://connection.java:505/)) ~[?:?]

at org.openhab.binding.amazonechocontrol.internal.Connection.makeRequestAndReturnString([Connection.java:500](http://connection.java:500/)) ~[?:?]

at org.openhab.binding.amazonechocontrol.internal.Connection.getRoutines([Connection.java:1458](http://connection.java:1458/)) ~[?:?]

at org.openhab.binding.amazonechocontrol.internal.Connection.startRoutine([Connection.java:1387](http://connection.java:1387/)) ~[?:?]

at org.openhab.binding.amazonechocontrol.internal.handler.EchoHandler.handleCommand([EchoHandler.java:644](http://echohandler.java:644/)) ~[?:?]

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_252]

at sun.reflect.NativeMethodAccessorImpl.invoke([NativeMethodAccessorImpl.java:62](http://nativemethodaccessorimpl.java:62/)) ~[?:1.8.0_252]

at sun.reflect.DelegatingMethodAccessorImpl.invoke([DelegatingMethodAccessorImpl.java:43](http://delegatingmethodaccessorimpl.java:43/)) ~[?:1.8.0_252]

at java.lang.reflect.Method.invoke([Method.java:498](http://method.java:498/)) ~[?:1.8.0_252]

at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect([AbstractInvocationHandler.java:152](http://abstractinvocationhandler.java:152/)) [bundleFile:?]

at org.eclipse.smarthome.core.internal.common.InvocationHandlerSync.invoke([InvocationHandlerSync.java:59](http://invocationhandlersync.java:59/)) [bundleFile:?]

at com.sun.proxy.$Proxy417.handleCommand(Unknown Source) [?:?]

at org.eclipse.smarthome.core.thing.internal.profiles.ProfileCallbackImpl.handleCommand([ProfileCallbackImpl.java:74](http://profilecallbackimpl.java:74/)) [bundleFile:?]

at org.eclipse.smarthome.core.thing.internal.profiles.SystemDefaultProfile.onCommandFromItem([SystemDefaultProfile.java:48](http://systemdefaultprofile.java:48/)) [bundleFile:?]

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_252]

at sun.reflect.NativeMethodAccessorImpl.invoke([NativeMethodAccessorImpl.java:62](http://nativemethodaccessorimpl.java:62/)) ~[?:1.8.0_252]

at sun.reflect.DelegatingMethodAccessorImpl.invoke([DelegatingMethodAccessorImpl.java:43](http://delegatingmethodaccessorimpl.java:43/)) ~[?:1.8.0_252]

at java.lang.reflect.Method.invoke([Method.java:498](http://method.java:498/)) ~[?:1.8.0_252]

at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect([AbstractInvocationHandler.java:152](http://abstractinvocationhandler.java:152/)) [bundleFile:?]

at org.eclipse.smarthome.core.internal.common.Invocation.call([Invocation.java:52](http://invocation.java:52/)) [bundleFile:?]

at [java.util.concurrent.FutureTask.run](http://java.util.concurrent.futuretask.run/)([FutureTask.java:266](http://futuretask.java:266/)) [?:1.8.0_252]

at java.util.concurrent.ThreadPoolExecutor.runWorker([ThreadPoolExecutor.java:1149](http://threadpoolexecutor.java:1149/)) [?:1.8.0_252]

at java.util.concurrent.ThreadPoolExecutor$[Worker.run](http://worker.run/)([ThreadPoolExecutor.java:624](http://threadpoolexecutor.java:624/)) [?:1.8.0_252]

at [java.lang.Thread.run](http://java.lang.thread.run/)([Thread.java:748](http://thread.java:748/)) [?:1.8.0_252]

i used to be able to solve it on the RC version of the binding by using a timer since there’s a tts just before the command, but this workaround doesn’t cut it now for some reason.

great binding otherwise, finally getting the access to echo hub-connected devices

Andrew_Rowe · July 2, 2020, 7:42pm

No, you are right, the command fails, and that is certainly not harmless. What I meant to say really is that it does not cause a system failure like the oom issue. As stated, the developers are aware of the issue and working on the best solution. I also tried a timer to delay the calls but as you say, it didn’t help

kamikatze13 · July 3, 2020, 9:55am

what i found out with my workaround of using three nested timers is that the first command almost always fails - the second and third almost always succeed.

i.e. previeously i had the timer set up for 10 seconds after the tts command, and it worked fine on the RC binding version. after moving to the beta, i saw the comand fail and increased the timer to 30s - which did not allevieate the issue
i then moved on to repeating the command three times with 10s intervalls each - and have a feeling the second and third always go through (i can hear the RVC beep a confirmation sound) and the first almost always fails

so it’s not just about command-to-command “cooldown” as i had first thought

Trinitus01 · July 3, 2020, 1:57pm

Please stay patient, a version to fix the too many requests issue is in testing state.

To explain the issue, not only a single command produces a request. After a command sends a request, the binding can receive a websocket call which again can produce a request. The binding also sends requests from time to time. So a timer between comands is only a “looks like a fix”. And for cammands to multible devices a timer would produce a echo by echo effect. Also there is an overlap for different commands to the same echo. Dont waste your time to try to fix it with workarounds in a rule.

Br

J-N-K · July 7, 2020, 9:27pm

Finally all the changes (except those from @Trinitus01 for the „Too many requests“ issue) have been merged and will be available in openHAB‘s next snapshot and in 2.5.7 (after it has been released). Thanks too everyone who contributed (with code or testing, which is a valuable help).

I‘ll work together with @Trinitus01 to get his fixes incorporated as soon as possible. Stay tuned!

J-N-K · July 11, 2020, 5:58pm

https://janessa.me/esh/org.openhab.binding.amazonechocontrol-2.5.7-SNAPSHOT.jar

is a test jar to fix the “Too many requests” issue based on https://github.com/openhab/openhab-addons/pull/8090. I would especially like to hear from those that use the smartdevice features if we did break something or if it is still all running. Thanks.

mstormi · July 11, 2020, 8:53pm

I’ve hit a mean error testing this but frankly I don’t know if it’s caused by the binding.
I haven’t been trying this binding for long but I had it working a couple of days ago.

Problem is the Amaz*n account thing is “offline - configuration pending” and when I try to log into the Alexa account via <openhabip>/amazonechocontrol, it’s not working, Amaz*n always keeps telling me

There was a problem
Enter a valid email or mobile number

although the binding log below suggests it has worked ?

2020-07-11 22:42:05.093 [DEBUG] [mazonechocontrol.internal.Connection] - Make request to https://www.amazon.com/ap/signin/146-999999-1056131
2020-07-11 22:42:05.098 [DEBUG] [mazonechocontrol.internal.Connection] - POST: openid.return_to=ape%3aR0cHM6Ly93d3cuYW1hem9uLmNvbS9hcC9tYXBsYW5kaW5n&prevRID=ape%3AUUUjc0UkRZQ0hDUTNJIR1E%3D&metadata1=ECdITeCs%3ALztbg5yFkI8f%2Fv8Y8701dIUljnvpd80faBgpywcKIJ0VThyF9olvkkoNfocDUD8qLFlslvD2Gfdx%2BLLNq7iKPES%2F4in6LqKoRDHuQKx1GEsvDqku1yjUebnRXvOaypKlxNzFB1Gca%2B2HsaiHuZxmlZuR3vD%2BbF4kw14LUBGLdCYGF8k6VCRDBLa9lJWmIpc8nMzeiQPFQSSX6va3xtVMJGa5esry0KW8DczMf7O9N0PAvF9ReuNMhs%2BN5MunsxiSn6d3dtcHEGwhWrVlsaTqEmJi97I5ZUAnkWZSwxWzLC7DzegvgGBSINtxzfmnqLkGz3mmW%2FDdEhCFc8yoyJzgaSxC0u%2B7EPYAEyjNWXfKZJRCguunWlLI0Nuwn%2FBqPf8Iz27EKrfSef%2FHuC7sWseKBT800zOyt7s7VnmXW6FpGdRiMntHgt2bYSkO8p2hyUISaVFs6Krz%2AkqXRxRIPAXsCLQV1DbIAaEsRQ5xkpUIXOrvrV5aeGGVqi5QaDqjTMCeZ0LHpYHJm0ivShv5wo0cSWatcM0m0t4aYry3fq6tW0JQG%2FfNDG7upQJwErX1ZH9rLvMa4u4WAv9vbJ%2B892UNotHXyq4ceV2BRXI47RUQl2ZK5ixOZB2z%2BBpqDKWJGmwOngVrjr9kF7FvE2xZw0RzjcN5BA944sKEVKN&appActionToken=bxj2FmSOD0YYRxpRpcj2FMzcKRcCWQj3D&workflowState=eyJ6aXAiOiJERUYiLCJlbmMiOiJBMjU2R0NNIiwiYWxnIjoiQTI1NktXIn0.MAiBc8NxP1O6xwgTTFF0R7hvmBdh8KK4qxqxSdn9kGD_9shlsQ8qw.dspN0xjP5pmkteTb.nHzjDMcPqaYoCanQiFIBEGma10FCiFhb8EyUthqGGR6F_isQJ9iQ7W_-WESyWgkVfQxxtVIrHdg73IEOX2_OjOhzebfhbxs4VixXZ8D-DfoNvWpdSxuHufhO1NqaGEjskMD5rSr1gKvSQ96uzrKvHcUzF8jgmQI874ifLrBVAfmC1SIP_QFOxOpwmg4NNaXh2ZVQyAqVcjlowkVNNI83PZo8800GbJkIWFiwJvT9hnZV0PW6WhAr7mNUOY05Nnmshl6c0cccyj1llbBoCOoqGZS97OStzs0ch_kw9T5ybSMBmfHTYfKx4fZtH28Sw5dUPUuNk5tfgBxcnbu5QY9vu61eqCOvag1913CH6XnqgDXhT7p7MhDCy6BnmeOch9Ou_YrKf9iNZBXf-h51SB9wv6MbozllAC0U1V1JzeDhp4B41YfHjguFgGhgxG_e5oTNz1DvGZbxjYWfOke3eu9OCKwfGDkBzq7c7kYgdfkwYSfy-lEN4zgFPGCr3zBg4gCe5pCfLugiJg.R4jYqmSSi_f7kUBxXDuoTA&appAction=SIGNIN&encryptedPwd=AYAAFHRAKC6qLGYNBMsCZQHmLw0AAAABAAZzaTptZDUAIDU2ZDE0ZWRjZThlMmNiNmM2ODQyYzU5ZGRhZWU0MjZlAQAFjKEZ0PXC68v%2FiF91rF%2FeropBJ1hVYBdxCc9w7j8Jnc65rkUeQjl3Gk5bJ0zg5oihUfJ09o3SbIrXbEf4xVriltibjhwMtK3nLHWxKWPIXsSabBmKrsyD9rBSP7bGoLbkDEJPPe0bL83Th3vFnvYd48uuEKFTVGCcFusVGvIGQ45ed6XsPlsIQj1HDRlbRWd1xsqmtLJWVLUvZ9JpJOHpd02o0g7d0tfiLPssdZ8KsebTFzlj6bNvzTUJzbPOFqKGZs6zvFdWCgU2Nj8edA4Ddu%2Ba86nae9PffQkQysAl7eWgdbwipG20KJj7KBfS0Ma4qp3pijzfwhLksbAgAAAAAMAAAADAAAAAAAAAAAAAAAAJ5kACswTxd4VG5UP1uYABf%2F%2F%2F%2F%2FAAAAAQAAAAAAAAAAAAAAAQAAAAuXvTsWLBTvmZx61EeJ%2BY15kLgmAIjNMQDyb5M%3D&showPasswordChecked=false&email=john%40doe.org&encryptedPasswordExpected=
2020-07-11 22:42:06.265 [DEBUG] [amazonechocontrol.internal.Connection] - Call to https://www.amazon.com/ap/signin/146-999999-1056131 succeeded

Loggin’ in directly works meanwhile so it isn’t a principal issue with the account.
I also noticed the log output below, followed by a large dump of an Amaz*n web page with lots of JS

2020-07-11 22:41:44.283 [DEBUG] [nechocontrol.internal.AccountServlet] - doGet /
2020-07-11 22:41:44.286 [DEBUG] [mazonechocontrol.internal.Connection] - Start Login to https://alexa.amazon.com
2020-07-11 22:41:44.290 [DEBUG] [mazonechocontrol.internal.Connection] - Make request to https://www.amazon.com/ap/signin?openid.return_to=https://www.amazon.com/ap/maplanding&openid.assoc_handle=amzn_dp_project_dee_ios&openid.identity=http://specs.openid.net/auth/2.0/identifier_select&pageId=amzn_dp_project_dee_ios&accountStatusPolicy=P1&openid.claimed_id=http://specs.openid.net/auth/2.0/identifier_select&openid.mode=checkid_setup&openid.ns.oa2=http://www.amazon.com/ap/ext/oauth/2&openid.oa2.client_id=device:486674855102726337530440445246810355650135167622600456254077041323413249564c5635564d32573831&openid.ns.pape=http://specs.openid.net/extensions/pape/1.0&openid.oa2.response_type=token&openid.ns=http://specs.openid.net/auth/2.0&openid.pape.max_auth_age=0&openid.oa2.scope=device_auth_access
2020-07-11 22:41:44.834 [DEBUG] [mazonechocontrol.internal.Connection] - Call to https://www.amazon.com/ap/signin?openid.return_to=https://www.amazon.com/ap/maplanding&openid.assoc_handle=amzn_dp_project_dee_ios&openid.identity=http://specs.openid.net/auth/2.0/identifier_select&pageId=amzn_dp_project_dee_ios&accountStatusPolicy=P1&openid.claimed_id=http://specs.openid.net/auth/2.0/identifier_select&openid.mode=checkid_setup&openid.ns.oa2=http://www.amazon.com/ap/ext/oauth/2&openid.oa2.client_id=device:486674855102726337530440445246810355650135167622600456254077041323413249564c5635564d32573831&openid.ns.pape=http://specs.openid.net/extensions/pape/1.0&openid.oa2.response_type=token&openid.ns=http://specs.openid.net/auth/2.0&openid.pape.max_auth_age=0&openid.oa2.scope=device_auth_access succeeded
2020-07-11 22:41:44.870 [DEBUG] [mazonechocontrol.internal.Connection] - Result of GET https://www.amazon.com/ap/signin?openid.return_to=https://www.amazon.com/ap/maplanding&openid.assoc_handle=amzn_dp_project_dee_ios&openid.identity=http://specs.openid.net/auth/2.0/identifier_select&pageId=amzn_dp_project_dee_ios&accountStatusPolicy=P1&openid.claimed_id=http://specs.openid.net/auth/2.0/identifier_select&openid.mode=checkid_setup&openid.ns.oa2=http://www.amazon.com/ap/ext/oauth/2&openid.oa2.client_id=device:486674510272633753044044524681050135167622600454077041323413249564c5635564d32573831&openid.ns.pape=http://specs.openid.net/extensions/pape/1.0&openid.oa2.response_type=token&openid.ns=http://specs.openid.net/auth/2.0&openid.pape.max_auth_age=0&openid.oa2.scope=device_auth_access:

J-N-K · July 11, 2020, 9:03pm

That‘s not a problem of the recent changes. It‘s not working with the older one either.

mstormi · July 11, 2020, 9:04pm

It worked a couple of days ago. And doesn’t it need to work for the whole binding to work ?