Disaster recovery and virtualisation

[CatmanV2]

Morning, gurus. Hope all is well.

Recently some of my voice activated actions have felt very laggy. Digging into it reveals that it's not the action that's slow, but the response from Alexa, To test I ran a simple speak from Reactor by pressing the 'play' button and there's a 10+ second lag between the command being queued and the voice confirmation in Alexa.

While this is not critical in terms of operation it is making some of my activities with multiple voice feedbacks take enough time to think stuff is broken

Quick log snippet (which I hope is enough shows the lag:

2021-05-28 09:46:43.371   openLuup.server:: POST /data_request HTTP/1.1 tcp{client}: 0x55fc83df7e28
2021-05-28 09:46:43.372   luup.call_action:: 22.urn:bochicchio-com:serviceId:VeraAlexa1.Say 
2021-05-28 09:46:43.373   luup_log:22: VeraAlexa: addToQueue: added to queue for 22
2021-05-28 09:46:43.373   luup_log:22: VeraAlexa(addToQueue@226): addToQueue: before: 0
2021-05-28 09:46:43.373   luup_log:22: VeraAlexa(addToQueue@243): addToQueue: after: 1
2021-05-28 09:46:43.374   luup_log:22: VeraAlexa(checkQueue@200): checkQueue: 22 - 1 in queue
2021-05-28 09:46:43.374   luup_log:22: VeraAlexa(checkQueue@208): checkQueue: 22 - play next
2021-05-28 09:46:43.374   luup_log:22: VeraAlexa(setVar@115): setVar("urn:bochicchio-com:serviceId:VeraAlexa1","OneTimePassCode","",22) old value ""
2021-05-28 09:46:43.374   luup_log:22: VeraAlexa(sayTTS@313): Executing command [TTS]: "-e speak:'<s>Sirens would be firing</s><break time=\"0s\" />' -d \"Everywhere\""
2021-05-28 09:46:54.309   luup_log:22: VeraAlexa(setVar@115): setVar("urn:micasaverde-com:serviceId:HaDevice1","CommFailure","0",22) old value "0"
2021-05-28 09:46:54.309   luup_log:22: VeraAlexa(setVar@115): setVar("urn:bochicchio-com:serviceId:VeraAlexa1","LatestResponse","sending cmd:speak:<s>Sirens would be firing</s><break time=\"0s\" /> to dev:Everywhere type:A3C9PE6TNYLTCH serial:de3b4a21ca844817bc180e826e636425 customerid:A1CVTZEBJIUFJI",22) old value "sending cmd:speak:<s>Sonic Deadline is down</s><break time=\"0s\" /> to dev:Everywhere type:A3C9PE6TNYLTCH serial:de3b4a21ca844817bc180e826e636425 customerid:A1CVTZEBJIUFJI"
2021-05-28 09:46:54.309   luup.variable_set:: 22.urn:bochicchio-com:serviceId:VeraAlexa1.LatestResponse was: sending cmd:speak:<s>Sonic Deadline is down</s><break time="0s" /> to dev:Everywhere type:A3C9PE6TNYLTCH serial:de3... now: sending cmd:speak:<s>Sirens would be firing</s><break time="0s" /> to dev:Everywhere type:A3C9PE6TNYLTCH serial:de3... #hooks:0
2021-05-28 09:46:54.309   luup_log:22: VeraAlexa(nil@270): Response from Alexa.sh: "sending cmd:speak:<s>Sirens would be firing</s><break time=\"0s\" /> to dev:Everywhere type:A3C9PE6TNYLTCH serial:de3b4a21ca844817bc180e826e636425 customerid:A1CVTZEBJIUFJI"
2021-05-28 09:46:54.310   luup_log:22: VeraAlexa(sayTTS@327): Queue will be checked again in "3" secs

Any ideas on cause / troubleshooting / resolution?

TIA

C

[rafale77]

If you haven't changed anything in your setup, I am guessing it is some random lag in the cloud? I don't believe you want me to get on my soap box and recommend my local approach...

[CatmanV2]

@rafale77 said in Alexa TTS is sloooooooow:

If you haven't changed anything in your setup, I am guessing it is some random lag in the cloud? I don't believe you want me to get on my soap box and recommend my local approach...

Nope, that's good :). That was my feeling as well, but to be clear this is NOT Alexa executing commands, that's still real quick. This is only TTS via Alexa. Which makes it a little more confusing.

However, does Google home do local TTS as well?

C

[rafale77]

Google?? Nahh nothing will really be local with Google. It goes against their personal data collection business model. Our data on their cloud is their primary source of revenue. My approach to TTS has been to use the "say" command built in macOS from my desktop and sends it to my sonos speakers. I run a little node.js server which offers an http API which openLuup uses as I wrote a tiny function in the startup lua. It works without the hands (I mean the internet) and is instantaneous.

GitHub - rafale77/node-sonos-http-api: An HTTP API bridge for Sonos easing automation. Hostable on any node.js capable device, like a raspberry pi or similar.

An HTTP API bridge for Sonos easing automation. Hostable on any node.js capable device, like a raspberry pi or similar. - rafale77/node-sonos-http-api

[CatmanV2]

Sure someone had done some analysis. Maybe it was Homekit.....

C

[LibraSun]

@toggledbits , any chance at all that MSR could one day gain a TTS-like facility on board? At least to the point that MP3 files could be stored in /storage/tts awaiting a "Play" command of some sort. I'm sure doing literal TTS locally is too big an ask, but gosh... what wouldn't we all give to gain at least some freedom from the cloud-based likes of Azure, Alexa, etc.

[rafale77]

Actually I somewhat did this for myself watching traffic going through my local DNS (pihole) and firewall. I started doing this because of the recent QNAP ransomware attacks leading me to deploy more drastic DPI and IPS reporting. Boy, Android is nasty... The amount of data and frequency of calling home is amazing. I ended taking down wifi on my oven (which runs android) and my one android tablet (alexa/echo) which was the most unreliable piece of hardware I had. I also notice a similar behavior on iOS devices but unlike Android, you could disable it. Most of the data is about location on iOS. They data packets are much smaller and are much less frequent. Disabling them means disabling some services. Apple uses your data for relative localization: devices scan for one another MAC addresses over BT and wifi and they keep a registry of it on their cloud. This way based on triangulation of what devices one given device sees, it is able to better estimate its location even without GPS as it uses the other device's GPS. I think Google does the same but more frequently and collects a lot more data while preventing you from disabling. Honestly the data was too much for me to figure out what it was for Android.
I also have relatives who work in marketing companies who freaked me out when they told me what data they have access to from Google... Just piecing things together and is a bit of a leap since I don't have any Google home device. I had some nest ones though which moved to very restrictive cloud only API when they got bought by Google and lead me to get rid of them.

Edit: Someone in Ireland has done a much deeper study on the topic than I:

Dan Goodin  /  Mar 30, 2021  /  Tech

Android sends 20x more data to Google than iOS sends to Apple, study says

Google contests the estimate, saying it’s based on flawed methodology.

https://www.scss.tcd.ie/doug.leith/apple_google.pdf

The only thing I would add is that I think the author missed a setting in iOS which I found to completely disable all data sending. Also note the attitude of Google towards the whole thing is pretty comical but at the same time it is all very understandable since it is their business model to collect and sell data since they do not sell their OS and don't make a profit on the devices they sell. They make profit on their true products... our data.

Now Amazon is (was?) different. They are actually selling products and making a profit from them, not so much from the smart devices but more from the echo/eco system to get us to shop on their sites. It is a different business model. How long before it changes? I don't know. At least the example of how they handled the Philips hue API drastically from Google is a sign that they are not as laser focused on forcing a cloud approach.

[therealdb]

@catmanv2 yep, same for me yesterday. Today it seems to be back to normal latency.

[CatmanV2]

@therealdb said in Alexa TTS is sloooooooow:

@catmanv2 yep, same for me yesterday. Today it seems to be back to normal latency.

Mine's been like this for some time. Just checking again and the same 10 second delay somewhere

C

[therealdb]

try to update the .sh script. They released a new version yesterday, and they specifically changed the TTS part. It's working good for me, even if they removed announcements, it's still working with announcements for me

[CatmanV2]

@therealdb said in Alexa TTS is sloooooooow:

try to update the .sh script. They released a new version yesterday, and they specifically changed the TTS part. It's working good for me, even if they removed announcements, it's still working with announcements for me

Do you have a link perchance? I can't find anything newer than Jan..

Cheers

C

[therealdb]

@catmanv2 https://github.com/thorsten-gehrig/alexa-remote-control

[CatmanV2]

@therealdb said in Alexa TTS is sloooooooow:

@catmanv2 https://github.com/thorsten-gehrig/alexa-remote-control

My thanks, as ever

C

[CatmanV2]

Announcements still work fine, but still 10 second delay <shrug>

C

[LibraSun]

And as anticipated, my system remains completely silent. I did update the .SH file just now to v.0.18, but no change.

However, I am noticing some (potential) weirdness in Vera Log which perhaps are not anomalies, but I'm pasting below just in case. I just leave VeraAlexa in 'Debug' mode all the time now. The command I had issued (from MSR) was:

luup.call_action("urn:bochicchio-com:serviceId:VeraAlexa1","RunCommand",{Command="-e textcommand:'tune in wwoz' -d 'Living Room'"}, 366)

Log contained the following, and I'm wondering why, for starters, most (not all) of my Echo devices are listed twice? why the response from .SH is ""? why the setVar/Devices line references a device other than Living Room? why LatestResponse appears empty? etc.:

08	05/29/21 9:40:44.577	JobHandler_LuaUPnP::HandleActionRequest device: 0 service: urn:micasaverde-com:serviceId:HomeAutomationGateway1 action: RunLua <0x70dc2520>
08	05/29/21 9:40:44.577	JobHandler_LuaUPnP::HandleActionRequest argument Code=luup.call_action("urn:bochicchio-com:serviceId:VeraAlexa1","RunCommand",{Command="-e textcommand:'tune in wwoz' -d 'Living Room'"}, 366) <0x70dc2520>
08	05/29/21 9:40:44.577	JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=0 <0x70dc2520>
08	05/29/21 9:40:44.577	JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:micasaverde-com:serviceId:HomeAutomationGateway1 <0x70dc2520>
08	05/29/21 9:40:44.578	JobHandler_LuaUPnP::HandleActionRequest argument action=RunLua <0x70dc2520>
08	05/29/21 9:40:44.578	JobHandler_LuaUPnP::HandleActionRequest argument _r=1622299244559 <0x70dc2520>
08	05/29/21 9:40:44.578	JobHandler_LuaUPnP::HandleActionRequest device: 366 service: urn:bochicchio-com:serviceId:VeraAlexa1 action: RunCommand <0x70dc2520>
08	05/29/21 9:40:44.579	JobHandler_LuaUPnP::HandleActionRequest argument Command=-e textcommand:'tune in wwoz' -d 'Living Room' <0x70dc2520>
50	05/29/21 9:40:44.580	luup_log:366: VeraAlexa[0.97@366](setVar@120):setVar("urn:bochicchio-com:serviceId:VeraAlexa1","OneTimePassCode","",366) old value "" <0x70dc2520>
50	05/29/21 9:40:44.581	luup_log:366: VeraAlexa[0.97@366](runCommand@395):Executing command [runCommand]: "-e textcommand:'tune in wwoz' -d 'Living Room'" <0x70dc2520>
50	05/29/21 9:40:44.601	luup_log:366: VeraAlexa[0.97@366](setVar@120):setVar("urn:micasaverde-com:serviceId:HaDevice1","CommFailure","0",366) old value "0" <0x70dc2520>
50	05/29/21 9:40:44.602	luup_log:366: VeraAlexa[0.97@366](setVar@120):setVar("urn:bochicchio-com:serviceId:VeraAlexa1","LatestResponse","",366) old value "" <0x70dc2520>
50	05/29/21 9:40:44.603	luup_log:366: VeraAlexa[0.97@366](@308):Response from Alexa.sh: "" <0x70dc2520>
50	05/29/21 9:40:44.622	luup_log:366: VeraAlexa[0.97@366](setVar@120):setVar("urn:bochicchio-com:serviceId:VeraAlexa1","Devices","Anne's Alexa Apps, false,2f69293cc2c749f6854ad6c5b41aef43,MSHOP\
Kitchen, true,F00718703203T4,ECHO\
Yoga Room, true,90LF1071750H8V,ECHO\
Hall Bathroom, true,90LF1071750H7N,ECHO\
Everywhere, true,56c846877e416eaa3425d163619011,WHA\
Downstairs, false,095239c8124c46834ded97b5c947b7,THIRD_PARTY_AVS_MEDIA_DISPLAY\
Master Bedroom, true,70RR138143018W,ROOK\
Workshop, true,90LF1071750H4G,ECHO\
Guest Room, false,90U50991541T31,ECHO\
Alexa App for PC, false,0CE90F27F69FFF703570DE6C20E7BA,REAVER\
Fire Tablet, true,W0TC039353F2SX,TABLET\
Libra's Sonos Beam, true,89f9dcc0ab4085bcb59494f81c3726,THIRD_PARTY_AVS_SONOS_BOOTLEG\
Living Room, true,48978706f5459f890ef0ec5aa9fce9,THIRD_PARTY_AVS_MEDIA_DISPLAY\
Libra's Ezlo Voi, false,eea63a85e2419498871004faca7e4d,UNKNOWN\
This Device, true,60b747dc4ce292626be49b7c3d41,VOX\
Libra's Alexa Apps, false,56FEC32487,AMAZONMOBILEMUSIC_ANDROID\
",366) old value "Anne's Alexa Apps, false,69293cc2c749f6854ad6c5b41aef43,MSHOP\
Kitchen, true,F00718703203T4,ECHO\
Yoga Room, true,90LF1071750H8V,ECHO\
Hall Bathroom, true,90LF1071750H7N,ECHO\
Everywhere, true,56c846877e416eaa3425d163619011,WHA\
Downstairs, false,095239c8124c46834ded97b5c947b7,THIRD_PARTY_AVS_MEDIA_DISPLAY\
Master Bedroom, true,70RR138143018W,ROOK\
Workshop, true,90LF1071750H4G,ECHO\
Guest Room, false,90U50991541T31,ECHO\
Alexa App for PC, false,0CE90F27F69FFF703570DE6C20E7BA,REAVER\
Fire Tablet, true,W0TC039353F2SX,TABLET\
Libra's Sonos Beam, true,89f9dcc0ab4085bcb59494f81c3726,THIRD_PARTY_AVS_SONOS_BOOTLEG\
Living Room, true,48978706f5459f890ef0ec5aa9fce9,THIRD_PARTY_AVS_MEDIA_DISPLAY\
Libra's Ezlo Voi, false,eea63ae2419498871004faca7e4d,UNKNOWN\
This Device, true,60b747dc4ce292626be49b7c3d41,VOX\
Libra's Alexa Apps, false,56FEC32487,AMAZONMOBILEMUSIC_ANDROID\
" <0x70dc2520>
08	05/29/21 9:40:58.658	JobHandler_LuaUPnP::HandleActionRequest device: 0 service: urn:micasaverde-com:serviceId:HomeAutomationGateway1 action: RunLua <0x6d5c2520>
08	05/29/21 9:40:58.658	JobHandler_LuaUPnP::HandleActionRequest argument Code=luup.call_action("urn:bochicchio-com:serviceId:VeraAlexa1","RunCommand",{Command="-e weather -d 'Living Room'"}, 366) <0x6d5c2520>
08	05/29/21 9:40:58.658	JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=0 <0x6d5c2520>
08	05/29/21 9:40:58.659	JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:micasaverde-com:serviceId:HomeAutomationGateway1 <0x6d5c2520>
08	05/29/21 9:40:58.659	JobHandler_LuaUPnP::HandleActionRequest argument action=RunLua <0x6d5c2520>
08	05/29/21 9:40:58.659	JobHandler_LuaUPnP::HandleActionRequest argument _r=1622299258640 <0x6d5c2520>
08	05/29/21 9:40:58.660	JobHandler_LuaUPnP::HandleActionRequest device: 366 service: urn:bochicchio-com:serviceId:VeraAlexa1 action: RunCommand <0x6d5c2520>
08	05/29/21 9:40:58.660	JobHandler_LuaUPnP::HandleActionRequest argument Command=-e weather -d 'Living Room' <0x6d5c2520>
50	05/29/21 9:40:58.661	luup_log:366: VeraAlexa[0.97@366](setVar@120):setVar("urn:bochicchio-com:serviceId:VeraAlexa1","OneTimePassCode","",366) old value "" <0x6d5c2520>
50	05/29/21 9:40:58.662	luup_log:366: VeraAlexa[0.97@366](runCommand@395):Executing command [runCommand]: "-e weather -d 'Living Room'" <0x6d5c2520>

NOTE: All names and S/N's redacted for privacy (so may appear inconsistent in listing)

[CatmanV2]

Hmmm, I have debug set to one and my log looks nothing like that....

This is the LuaUPnP.log yes?

C

[LibraSun]

@catmanv2 said in Alexa TTS is sloooooooow:

This is the LuaUPnP.log yes?

Yes. I get a very verbose response set like that in Vera's LuaUPnP Log every time I attempt one of the Lua commands I use for testing. Some worked with previous revisions, others not, but right now ... literally nothing works for me.

I'm wondering if maybe I have too many Alexa devices defined in my account... or something else unique to "me" that's causing VeraAlexa to choke.

Whenever I update any component of the VeraAlexa plug-in (whether through WinSCP or by dragging files into App > Develop), I always set "Configured" back to 0 and restart Vera, so things have a chance to settle. The cookie is safely there, and "Configured" always sets to 1 without any trouble.

It's as if the plug-in wants to work, but simply doesn't, for me.

[CatmanV2]

@librasun are you on Vera or OpenLuup?

What's in your .alexa.devicelist.all? If you've got duplicate entries it's probably worth deleting it and letting it re-create.

I've just realised my 'new' Echo is not listed, but it's in the guess bedroom so doesn't get used.

C

[LibraSun]

To answer your question, I inspected the contents of my .alexa.devicelist.json file (I see no 'all' file like you mentioned), and found -- after putting it through a JSON Pretty Print converter and filtering for accountName -- just a single copy of each device on my account.

Egads, though, the file is 931 lines long, lol!

If you're suggesting I delete that file, I'm game, but am generally loath to take stabs in the dark like that until I have more data.

[CatmanV2]

AFAIK you should have:
.alexa.devicelist.txt
.alexa.devicelist.all
.alexa.cookie
.alexa.devicelist.json

I think the lack of some or more of these could be part of your issue. Are you on Vera still? I forget

Totally get what you mean about deleting stuff. I tend to rename ;). My understanding is they should be created automagically.

C