Preview and Beta: Amazon Echo Control

Hi,

thank you for the log information.
Routines are not protected against “too many requests”.
We will take a look into.

br

1 Like

Does this “limit=2000” mean that there are too many users starting routines at the same time?

I noticed that it seems to work when I change my cron times to more “unusual” times (06:09:30 a.m. instead of 06:10:00 a.m. for example).

No,

the “limit” is an url-parameter. But too many requests doesn’t depend on this parameter or on any other user or the daytime. Amaz+n reject your request because of too many requests in a short period of time. (the amount of requests is not equal to the amount of sendCommand for example, there are much more hidden and parallel requests)

Edit: I think you can simply reproduce it by running sendCommand to a routine multiple times until the exception appears. (Routine is not protected agains the tmr-issue at the moment, only tts and act)

1 Like

Many thanks for the explanation.
I am using the rules to start the routines since several months without problems, that’s why I was wondering what suddenly happened.

That worked for me. Thanks

Could it be that this verison is not compatible with JAVA 11?
I’m using the following binding: org.openhab.binding.amazonechocontrol-2.5.7-SNAPSHOT.jar
When I switch to JAVA 11 (with openhabian-config), i’m getting the following errors:

2020-07-17 20:24:13.926 [WARN ] [mazonechocontrol.internal.Connection] - Request to url 'https://alexa.amazon.de/api/bootstrap' fails with unknown error
javax.net.ssl.SSLException: Unexpected error: java.security.InvalidAlgorithmParameterException: the trustAnchors parameter must be non-empty
	at sun.security.ssl.Alert.createSSLException(Alert.java:133) ~[?:?]
	at sun.security.ssl.TransportContext.fatal(TransportContext.java:326) ~[?:?]
	at sun.security.ssl.TransportContext.fatal(TransportContext.java:269) ~[?:?]
	at sun.security.ssl.TransportContext.fatal(TransportContext.java:264) ~[?:?]
	at sun.security.ssl.SSLSocketImpl.handleException(SSLSocketImpl.java:1310) ~[?:?]
	at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:403) ~[?:?]
	at sun.net.www.protocol.https.HttpsClient.afterConnect(HttpsClient.java:567) ~[?:?]
	at sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.connect(AbstractDelegateHttpsURLConnection.java:185) ~[?:?]
	at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1587) ~[?:?]
	at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1515) ~[?:?]
	at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:527) ~[?:?]
	at sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:334) ~[?:?]
	at org.openhab.binding.amazonechocontrol.internal.Connection.makeRequest(Connection.java:614) [bundleFile:?]
	at org.openhab.binding.amazonechocontrol.internal.Connection.tryGetBootstrap(Connection.java:465) [bundleFile:?]
	at org.openhab.binding.amazonechocontrol.internal.Connection.verifyLogin(Connection.java:882) [bundleFile:?]
	at org.openhab.binding.amazonechocontrol.internal.Connection.tryRestoreLogin(Connection.java:357) [bundleFile:?]
	at org.openhab.binding.amazonechocontrol.internal.handler.AccountHandler.checkLogin(AccountHandler.java:385) [bundleFile:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:834) [?:?]
Caused by: java.lang.RuntimeException: Unexpected error: java.security.InvalidAlgorithmParameterException: the trustAnchors parameter must be non-empty
	at sun.security.validator.PKIXValidator.<init>(PKIXValidator.java:102) ~[?:?]
	at sun.security.validator.Validator.getInstance(Validator.java:181) ~[?:?]
	at sun.security.ssl.X509TrustManagerImpl.getValidator(X509TrustManagerImpl.java:300) ~[?:?]
	at sun.security.ssl.X509TrustManagerImpl.checkTrustedInit(X509TrustManagerImpl.java:176) ~[?:?]
	at sun.security.ssl.X509TrustManagerImpl.checkTrusted(X509TrustManagerImpl.java:189) ~[?:?]
	at sun.security.ssl.X509TrustManagerImpl.checkServerTrusted(X509TrustManagerImpl.java:129) ~[?:?]
	at sun.security.ssl.CertificateMessage$T12CertificateConsumer.checkServerCerts(CertificateMessage.java:629) ~[?:?]
	at sun.security.ssl.CertificateStatus$CertificateStatusConsumer.consume(CertificateStatus.java:295) ~[?:?]
	at sun.security.ssl.SSLHandshake.consume(SSLHandshake.java:392) ~[?:?]
	at sun.security.ssl.HandshakeContext.dispatch(HandshakeContext.java:444) ~[?:?]
	at sun.security.ssl.HandshakeContext.dispatch(HandshakeContext.java:422) ~[?:?]
	at sun.security.ssl.TransportContext.dispatch(TransportContext.java:183) ~[?:?]
	at sun.security.ssl.SSLTransport.decode(SSLTransport.java:168) ~[?:?]
	at sun.security.ssl.SSLSocketImpl.decode(SSLSocketImpl.java:1148) ~[?:?]
	at sun.security.ssl.SSLSocketImpl.readHandshakeRecord(SSLSocketImpl.java:1057) ~[?:?]
	at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:395) ~[?:?]
	... 17 more
Caused by: java.security.InvalidAlgorithmParameterException: the trustAnchors parameter must be non-empty
	at java.security.cert.PKIXParameters.setTrustAnchors(PKIXParameters.java:200) ~[?:?]
	at java.security.cert.PKIXParameters.<init>(PKIXParameters.java:120) ~[?:?]
	at java.security.cert.PKIXBuilderParameters.<init>(PKIXBuilderParameters.java:104) ~[?:?]
	at sun.security.validator.PKIXValidator.<init>(PKIXValidator.java:99) ~[?:?]
	at sun.security.validator.Validator.getInstance(Validator.java:181) ~[?:?]
	at sun.security.ssl.X509TrustManagerImpl.getValidator(X509TrustManagerImpl.java:300) ~[?:?]
	at sun.security.ssl.X509TrustManagerImpl.checkTrustedInit(X509TrustManagerImpl.java:176) ~[?:?]
	at sun.security.ssl.X509TrustManagerImpl.checkTrusted(X509TrustManagerImpl.java:189) ~[?:?]
	at sun.security.ssl.X509TrustManagerImpl.checkServerTrusted(X509TrustManagerImpl.java:129) ~[?:?]
	at sun.security.ssl.CertificateMessage$T12CertificateConsumer.checkServerCerts(CertificateMessage.java:629) ~[?:?]
	at sun.security.ssl.CertificateStatus$CertificateStatusConsumer.consume(CertificateStatus.java:295) ~[?:?]
	at sun.security.ssl.SSLHandshake.consume(SSLHandshake.java:392) ~[?:?]
	at sun.security.ssl.HandshakeContext.dispatch(HandshakeContext.java:444) ~[?:?]
	at sun.security.ssl.HandshakeContext.dispatch(HandshakeContext.java:422) ~[?:?]
	at sun.security.ssl.TransportContext.dispatch(TransportContext.java:183) ~[?:?]
	at sun.security.ssl.SSLTransport.decode(SSLTransport.java:168) ~[?:?]
	at sun.security.ssl.SSLSocketImpl.decode(SSLSocketImpl.java:1148) ~[?:?]
	at sun.security.ssl.SSLSocketImpl.readHandshakeRecord(SSLSocketImpl.java:1057) ~[?:?]
	at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:395) ~[?:?]
	... 17 more

When switching back to JAVA 8, the binding works without issues.

I don’t know if it is of any use for you.
I followed @richaardvark’s idea and changed the jar after login back to the latest 2.5.6- SNAPSHOT.
Today all my routines were running without the tmr error or any other errors or warnings and the LastVoiceCommand is working normal again, without any delays.

1 Like

No, I’m using Java 11 (Zulu).

1 Like

Hi,

could you please test the following jar.

Link removed.

Test cases are:

  • Is there still a delay on lastVoiceCommand
  • Is there still a delay on tts or act
  • Is there any too many request error in log
  • Does group tts or group act work
  • Does same tts outputs or act outputs in a short period of time work (example send tts with “blub” to device1, send tts with “blub” to device2 and send tts with “blub” to device 3)
  • Does different tts outputs or act outputs in a short period of time work (example send tts with “blub” and after it a tts with “blab” and a act with “blib”
  • Does ttsVolume work (example set ttsVolume one time to 50, set volume to 30, send tts, act, group tts or group act)

Big thanks for testing!

br

Hi. I tried that… and it worked the first couple of tests!
But while playing around, I had a significant delay like 30secs between saying something and the response of her saying something back using TTS. The log changed instantly, I was just “hearing” her response much later. It is replicable:

I edit rule-file.


Then I say something:

than no response…

until 22:25:10 - nothing in the logs, but alexa starts with that chime and starts talking “ding dong”…

So I didn’t change the file… and asked her the same thing again, quick response. then I ask her again, quick response. Then I ask her again, 2min break before the response.

I know that behavior from the past, like a spam-blocker, because I ask her the same thing multiple times…Like there is a “only 5 TTS per minute or so”…

I have trace-logs enabled, no entry of “many”(requests).

Thank you very much to test the jar, it helps a lot to improve the binding.
I will take your rule and try to reproduce the “issue”. It will take some time for sure but i will report as soon as possible.

Edit: I fired 10 tts without any problem but not triggered via lastVoiceCommand. So it seems there is no limit per minute.

Edit: To reproduce it the best way i need to know if you set a ttsVolume or use the echo volume (never set the ttsVolume)?

Br

As I wrote I installed the 2.5.6 SNAPSHOT again after logging in with 2.5.7 and everything is working fine.

So I am wondering if all the changes are really necessary.
Wouldn’t it be enough to change the login process only?

Hi,

it depends on your configuration,

So maybe for you it isnt but for other like me it is.
How many echos do you use at the same time?
I fire commands up to 6 echos parallel multiple times. So lets say 3 sentences to 6 echos are 18 Requests in less then 3 Seconds.
If you do so, you will reach the TMR very fast.

Edit: And there are other fixes like to use ssml sound for tts, parallel tts, aso

If you do not use the features u are fine without any changes :slight_smile:

Br

1 Like

Hi,

I think it was my fault. Probably i fixed the issue and provided a new jar.
It is recommended to switch to the new jar and reboot or restart OpenHAB.

I tested your case in a rule loop for over 1 and a half hour with the new jar without any problem, so it seems fixed.

Same link as before:

Hi Trinitus,
that made it worse. Now, the delay is everytime.
If I say klingel mal, she will responde about 10-20 sec later.

And I see

2020-07-21 21:11:59.968 [vent.ItemStateChangedEvent] - Livingroom_AmazonEcho_LastVoiceCommand changed from <speak>

                <audio src="soundbank://soundlibrary/home/amzn_sfx_doorbell_chime_01"/>

                <say-as interpret-as="interjection">ding dong</say-as>

                <break time="100ms"/> 

                <say-as interpret-as="interjection">dang</say-as>

                <break time="100ms"/> 

                Jemand ist an der T?re.

               </speak> to 

2020-07-21 21:11:59.968 [vent.ItemStateChangedEvent] - Livingroom_AmazonEcho_LastVoiceCommand changed from  to klingel mal

2020-07-21 21:11:59.980 [ome.event.ItemCommandEvent] - Item 'Livingroom_AmazonEcho_LastVoiceCommand' received command <speak>

                <audio src="soundbank://soundlibrary/home/amzn_sfx_doorbell_chime_01"/>

                <say-as interpret-as="interjection">ding dong</say-as>

                <break time="100ms"/> 

                <say-as interpret-as="interjection">dang</say-as>

                <break time="100ms"/> 

                Jemand ist an der T?re.

               </speak>

2020-07-21 21:11:59.990 [ome.event.ItemCommandEvent] - Item 'Livingroom_AmazonEcho_LastVoiceCommand' received command <speak>

                <audio src="soundbank://soundlibrary/home/amzn_sfx_doorbell_chime_01"/>

                <say-as interpret-as="interjection">ding dong</say-as>

                <break time="100ms"/> 

                <say-as interpret-as="interjection">dang</say-as>

                <break time="100ms"/> 

                Jemand ist an der T?re.

               </speak>

2020-07-21 21:11:59.992 [nt.ItemStatePredictedEvent] - Livingroom_AmazonEcho_LastVoiceCommand predicted to become <speak>

                <audio src="soundbank://soundlibrary/home/amzn_sfx_doorbell_chime_01"/>

                <say-as interpret-as="interjection">ding dong</say-as>

                <break time="100ms"/> 

                <say-as interpret-as="interjection">dang</say-as>

                <break time="100ms"/> 

                Jemand ist an der T?re.

               </speak>

2020-07-21 21:12:00.018 [nt.ItemStatePredictedEvent] - Livingroom_AmazonEcho_LastVoiceCommand predicted to become <speak>

                <audio src="soundbank://soundlibrary/home/amzn_sfx_doorbell_chime_01"/>

                <say-as interpret-as="interjection">ding dong</say-as>

                <break time="100ms"/> 

                <say-as interpret-as="interjection">dang</say-as>

                <break time="100ms"/> 

                Jemand ist an der T?re.

               </speak>

2020-07-21 21:12:00.021 [vent.ItemStateChangedEvent] - Livingroom_AmazonEcho_LastVoiceCommand changed from klingel mal to <speak>

                <audio src="soundbank://soundlibrary/home/amzn_sfx_doorbell_chime_01"/>

                <say-as interpret-as="interjection">ding dong</say-as>

                <break time="100ms"/> 

                <say-as interpret-as="interjection">dang</say-as>

                <break time="100ms"/> 

                Jemand ist an der T?re.

               </speak>

The logs are doubled? It is only talking once, but the logs show 2 entries each.

How can I help? I have trace logs, and I have team viewer :slight_smile:

Played around a little by myself.
I switched from a test routine triggered by voice to a test routine triggered by a switch.
Delay is still there.
And if I do something like:
voice trigger the test routine (my living_room_echo should talk)
switch trigger a different test routine (my living room echo should talk as well)
there is 20sec pause… then talk… then 20sec pause again… then talk

Hi,

can you give me some very necessary information.

Do you set the ttsVolume? If so, can you set the ttsVolume to 0 and check the delay again?

Tts is queued so if you send to device one and after it to device two they the output will appear in a sequence. Only devices in a group will output parallel.

But your testcase is very interesting, i will check if it is possible to only queue outputs for the same device.

Br

The double output should not depend on the binding. There is no code change. Sometime i also have double logs. In this case i reload the page and it shows only one after refresh.

I found the reason for your massive delay, its because of the ssml.
Example: Send “this is a test” to a device and immediately send “and this is another test”.
The second sentence would interrupt the first one. I use the length of the text to wait for the first sentence is spoken. But i did not thought about ssml. So you send a long string as command but the text itself is short.

Please try the same test without ssml.

I can fix this, but for the sound it wont be that easy because i dont know how much time the sound will consume.

Your testcases helps a lot, big thanks!

Br

So… the delay is that long because you wait “on purpose” because you think the command I had just send before is still running because it contained so many “characters”?

I remember that I asked months ago if a queue can be implemented, haha, and now I stumpled over it.
Because SSML is used, you cannot determine the length. It is possible to stream mp3s now (something I will definately use). I guess, you could parse the command and if SSML is / has been used, you skip the queue ?