commands being sent but not being recieved

[digiltd]

As far as the skill is concerned everything is fine, i ask it to update video library and she says "updating video library" I ask to play my video playlist cartoons and she says "Playing the video playlist Cartoons" but kodi just sat there doing nothing. Sometimes if i repeated the command a few times it would eventually work, but usually by then I have picked up the remote :)

I changed line 310

timeout = (10, 0.01)

to

timeout = (10, 1)

Which appears to have sorted it. Though when I reverted back to 0.01 again so I could test and be sure, that was now appearing to be working fine (commands sent were actually being received by kodi).

I will keep an eye on it at the new (10, 1).

It may not even be related to the timeout, but it was definitely behaving as described for some reason.

[jingai]

The first timeout is the connect/send timeout. In this case, that's all we care about, since we don't need to see the response (the skill will do the same thing no matter the response).

The second timeout is the read timeout. This one won't trigger at all until the outgoing packets have been transmitted and ACK'ed. For fire-and-forget commands such as starting playback, we actually want this timeout to trigger as soon as possible to reduce lag.

Not doubting that you saw a problem, but I don't think the timeouts are the cause -- it was probably just coincidence.

If you see it happen again, make sure to grab the log and we can see exactly what is happening.

[jingai]

Hmm.. was the screen saver active? Because Kodi won't start playback if it is.

edit: it won't start certain things, but apparently will do others.. will need to look into it further.

[digiltd]

Here is the log from a time when it happened

2017-08-23T11:25:53.754Z Playing a random episode of the Simpsons

2017-08-23T11:25:53.754Z Searching for show "the Simpsons"

2017-08-23T11:25:53.754Z Sending request to https://yadayada.yada/subyada/jsonrpc from device amzn1.ask.device.YADA

2017-08-23T11:25:53.755Z [DEBUG]    2017-08-23T11:25:53.755Z    d2dc7607-87f5-11e7-9d35-251af3db3d22    Starting new HTTPS connection (1): yadayada.yada

2017-08-23T11:25:55.333Z [DEBUG]    2017-08-23T11:25:55.333Z    d2dc7607-87f5-11e7-9d35-251af3db3d22    https://yadayada.yada:1234 "POST /subyada/jsonrpc HTTP/1.1" 200 2423

2017-08-23T11:25:55.335Z Trying to match: the simpsons

2017-08-23T11:25:55.335Z Simple match on direct comparison

2017-08-23T11:25:55.335Z   BEST MATCH: "The Simpsons"

2017-08-23T11:25:55.335Z Sending request to https://yadayada.yada/subyada/jsonrpc from device amzn1.ask.device.YADA

2017-08-23T11:25:55.336Z [DEBUG]    2017-08-23T11:25:55.336Z    d2dc7607-87f5-11e7-9d35-251af3db3d22    Starting new HTTPS connection (1): yadayada.yada

2017-08-23T11:25:55.604Z [DEBUG]    2017-08-23T11:25:55.604Z    d2dc7607-87f5-11e7-9d35-251af3db3d22    https://yadayada.yada:1234 "POST /subyada/jsonrpc HTTP/1.1" 200 74

2017-08-23T11:25:55.605Z Sending request to https://yadayada.yada/subyada/jsonrpc from device amzn1.ask.device.YADA

2017-08-23T11:25:55.606Z [DEBUG]    2017-08-23T11:25:55.606Z    d2dc7607-87f5-11e7-9d35-251af3db3d22    Starting new HTTPS connection (1): yadayada.yada

2017-08-23T11:25:55.994Z [DEBUG]    2017-08-23T11:25:55.994Z    d2dc7607-87f5-11e7-9d35-251af3db3d22    https://yadayada.yada:1234 "POST /subyada/jsonrpc HTTP/1.1" 200 35288

2017-08-23T11:25:56.004Z Sending request to https://yadayada.yada/subyada/jsonrpc from device amzn1.ask.device.YADA

2017-08-23T11:25:56.009Z [DEBUG]    2017-08-23T11:25:56.9Z  d2dc7607-87f5-11e7-9d35-251af3db3d22    Starting new HTTPS connection (1): yadayada.yada

2017-08-23T11:25:56.314Z [DEBUG]    2017-08-23T11:25:56.314Z    d2dc7607-87f5-11e7-9d35-251af3db3d22    https://yadayada.yada:1234 "POST /subyada/jsonrpc HTTP/1.1" 200 187

2017-08-23T11:25:56.316Z Sending request to https://yadayada.yada/subyada/jsonrpc from device amzn1.ask.device.YADA

2017-08-23T11:25:56.316Z [DEBUG]    2017-08-23T11:25:56.316Z    d2dc7607-87f5-11e7-9d35-251af3db3d22    Starting new HTTPS connection (1): yadayada.yada

2017-08-23T11:25:56.891Z [INFO] 2017-08-23T11:25:56.891Z    d2dc7607-87f5-11e7-9d35-251af3db3d22    54.240.197.10 - - [23/Aug/2017:11:25:56 +0000] "POST / HTTP/1.1" 200 316 "" "Apache-HttpClient/4.5.x (Java/1.8.0_131)" 0/3602.214

2017-08-23T11:25:56.892Z END RequestId: d2dc7607-87f5-11e7-9d35-251af3db3d22

2017-08-23T11:25:56.892Z REPORT RequestId: d2dc7607-87f5-11e7-9d35-251af3db3d22 Duration: 3609.87 ms    Billed Duration: 3700 ms    Memory Size: 512 MB Max Memory Used: 49 MB  

As you can see as far as the Skill is concerned it is all working fine, it requests the data several times, it is just the final "play" bit that was not working reliably, and this was true when asking it to pause, stop, update library etc all commands with wait_resp set to False i.e. the fire-and-forget commands.

Maybe it is a thing to do with https or that I am using Nginx as a reverse proxy. I haven't used Kodi that much in the past couple of days but when I have it has worked fine (commands are being received).

I wouldn't worry about it for now, but I will let you know if things change.

[jingai]

Hmm the proxy could be the issue if it doesn't forward the packets to Kodi before the skill closes the connection.

[jingai]

I'll make an option to disable async IO. But, if I were you I'd look into your proxy server a bit more and see if you can't solve it there, since it will increase latency.

[jingai]

Added a config option no_async_io so you can disable it.

[jingai]

Replaced the no_async_io option by exposing both of the read timeouts as read_timeout and read_timeout_async. Otherwise calls that really do need to be non-blocking (such as clean/update library) would almost always result in an error message from Alexa.

Let me know if this works for you.

[jingai]

Going to release a new Kodi-Voice version soon. Should I include this?

edit: released with 0.9.9. Let us know if it doesn't solve your problem.

[digiltd]

sorry didn't see all this activity

it has been fine since i changed the timeout mentioned in the first post, maybe a coincidence, im not sure. But without it failing I can't tell you if your fix works.

I did try the new version and disabled async. This was sending (and kodi was receiving) commands fine (though remember it was sending/receiving commands fine without it).

It did stop giving me feedback though. So whilst "alexa, play my video playlist, cartoons" did work, I wasn't getting the "playing the video playlist, cartoons" response.

I doubt the proxy is causing any significant lag, it is just nginx running locally on a pi. If it happens again I will reopen, but it might be better to not have it as a config option as the lack of responses might cause more confusion.

[jingai]

The option to disable async requests was removed in favor of making the timeout configurable. This should mask the problem for you, at the expense of a bit more lag (whatever you set the timeout too, or if Kodi sends the whole response first).

To be clear, I was not suggesting the proxy was "adding lag" -- it will, but probably not much and is not the cause of your problem here.

The problem is that the skill is dropping the connection (because it's done) before the proxy has passed the data completely to Kodi and your proxy appears to be closing both sides because its client disappeared.

There's probably a config option in NGINX you can utilize to get around this, but in the event that you can't, I made the timeouts adjustable for you so you can work around it.

[digiltd]

cool, so perhaps my initial timeout tweak was not just coincidental

thanks for looking into it

[jingai]

No, I suspect it wasn't, though if you're going to use a proxy it should probably (if possible) be configured to wait until all data has been transmitted before closing the connection.

Or, you can just live with a bit of extra latency if you don't feel like looking into it :)