TTS Slow

📢 Feedback
1

For the past few days I've experienced occasional very slow TTS generated by BigTalker to LanNouncer loaded on Android and Fire HD8 devices. For example: some door open close announcements were about 5 minutes late. It's output device agnostic, and currently it seems to be OK. I'm used to the HD8s Amazon system putting Lannouncer to sleep, this is not that problem.

Just wondering if there was/is some sort of TTS outage, if my Hub is having an issue, or if there is anything I can do to mitigate the issue.

2

Back door open/close announcement just ran 3 minutes late. It is my hub or TTS?
Contact sensor

dev:1302019-02-15 12:10:54.787 infoBack Door Sensor was closed

dev:1302019-02-15 12:10:54.390 infoBack Door Sensor is [x:-20,y:-1016,z:85]

dev:1302019-02-15 12:10:53.382 infoBack Door Sensor is [x:112,y:-1016,z:116]

dev:1302019-02-15 12:10:52.373 infoBack Door Sensor is [x:92,y:-1021,z:77]

dev:1302019-02-15 12:10:51.369 infoBack Door Sensor is [x:-35,y:-1016,z:96]

dev:1302019-02-15 12:10:50.412 infoBack Door Sensor is [x:63,y:-1031,z:57]

dev:1302019-02-15 12:10:50.398 infoBack Door Sensor is active

dev:1302019-02-15 12:10:50.291 infoBack Door Sensor was opened

BigTalker
app:2592019-02-15 12:10:55.152 debugBIGTALKER2(P2.0.8.AAB002) || [PARENT] TALK(Doors Open Part 2 and Close.contact) |sS| >> back door sensor is now closed

app:2592019-02-15 12:10:52.247 debugBIGTALKER2(P2.0.8.AAB002) || [PARENT] TALK(Doors Open Part 2 and Close.contact) |sS| >> back door sensor is now open

app:2592019-02-15 12:10:50.742 debugBIGTALKER2(P2.0.8.AAB002) || [PARENT] TALK(Doors Open Part 1 Chime.contact) |sS| >> |chime|

Lannouncer Device
dev:1332019-02-15 12:13:02.512 warnThe server failed to respond with a valid HTTP response

dev:1332019-02-15 12:13:02.399 debugGET /&SPEAK=back%20door%20sensor%20is%20now%20closed&@DONE@ HTTP/1.1 Accept: / User-Agent: Linux UPnP/1.0 Hubitat HOST: 192.168.0.111:1035

dev:1332019-02-15 12:13:02.393 debug040B

dev:1332019-02-15 12:13:02.392 debugIP address entered is 192.168.0.111 and the converted hex code is C0A8006F

dev:1332019-02-15 12:13:02.391 infoSending command &SPEAK=back%20door%20sensor%20is%20now%20closed&@DONE@ to 192.168.0.111:1035

dev:1332019-02-15 12:13:02.388 infoCommand request: &SPEAK=back%20door%20sensor%20is%20now%20closed&@DONE@

dev:1332019-02-15 12:13:02.387 debugExecuting 'speak'

dev:1332019-02-15 12:12:59.640 warnThe server failed to respond with a valid HTTP response

dev:1332019-02-15 12:12:59.524 debugGET /&SPEAK=back%20door%20sensor%20is%20now%20open&@DONE@ HTTP/1.1 Accept: / User-Agent: Linux UPnP/1.0 Hubitat HOST: 192.168.0.111:1035

Tagging @bravenel @mike.maxwell

3

Hi, did you reboot your hub? I saw a lag in my hub 2 days ago but after a reboot now everything looks normal.

4

when we talk about TTS we need to be clear on whos TTS service were talking about...

Hubitat's internal system TTS?, or something else...

5

I did a couple of days ago when this issue got bad.

Just rebooted the hub again and TTS seems to be normal again, but this has been going on for about 5 days.

I don't want to constantly have to reboot the hub to keep TTS functional. It's bad enough I have to reboot the Amazon HD8's get Lannouncer working, when restarting Lannouncer does make it start talking again. Lannouncer works properly on an old Android phone, but participates in the slow TTS

6

How do I make that determination? I'm using lannouncer DTH and BigTalker speak command

7

I don't know what those applications use, speak is a public driver method, so anything could be used behind it.
A hubitat system tts call would use the built in tts method textToSpeech(text)

9

The textToSpeech command is used with a device having capability.musicPlayer. Lannouncer devices are capability.speechSynthesis anduse the speak command.

The delay noted in my second post seems to be between the time BigTalker issues the speak, and when the Lannouncer DTH issues actual commands

The DTH speak code

def speak(toSay) {
log.debug "Executing 'speak'"
if (!toSay?.trim()) {
    if (ReplyOnEmpty) {
        toSay = "LANnouncer Version ${version}"
    }
}
toSay = toSay.replaceAll("\\s","%20")
toSay = toSay.replaceAll("[|]","%7C")
toSay = toSay.replaceAll("[=]","%3D")
if (toSay?.trim()) {
    def command="&SPEAK="+toSay+"&"+getDoneString()
    return sendCommands(command)
}}


private sendCommands(command) {
log.info "Command request: "+command
sendSMSCommand(command)
return sendIPCommand(command)

}

private sendIPCommand(commandString, sendToS3 = false) {
log.info "Sending command "+ commandString+" to "+DeviceLocalLan+":"+DevicePort
if (DeviceLocalLan?.trim()) {
    def hosthex = convertIPtoHex(DeviceLocalLan)
    def porthex = convertPortToHex(DevicePort)
    device.deviceNetworkId = "$hosthex:$porthex"

    def headers = [:] 
    headers.put("HOST", "$DeviceLocalLan:$DevicePort")

    def method = "GET"

    def hubAction = new hubitat.device.HubAction(
        method: method,
        path: "/"+commandString,
        headers: headers
        );
    if (sendToS3 == true)
    {
        hubAction.options = [outputMsgToS3:true];
    }
    log.debug hubAction
    return hubAction;
}

}

10

not here it isn't, it would need to be declared as a custom command in the driver
https://docs.hubitat.com/index.php?title=Driver_Capability_List#MusicPlayer

in any event Hubitats TTS is not being used in the code you posted.

11

I agree it is not using the textToSpeech command.

Is there any way to explain the today's 3 second delay, and delays of perhaps a minute or more on other occasions.

12

you would have to speak to the software's author, I imagine there could be any number of reasons for this.

13

I understand and thank you for taking a look at this.:sob:

Tagging @rayzurbock @jpark @fpstassi
Any ideas or suggestions appreciated.

14

I've reviewed the logs combined.

You can see that BigTalker responds within the same second as the physical event registers (door open/door closed). There is a delay on door open, likely due to calling Chime and immediately following with "back door is now open" . This is likely a delay added in BigTalker between speech events to prevent back-to-back speech (I recommend one or the other. Not more than 1 speech call per event among ALL of your apps/rules,etc. So if door open for that door is sending speech to "Office" speaker, nothing else among all your apps, rules, etc should also send another speech event to that same speaker for the same event). LANNouncer itself doesn't send it's commands to your device until much later than it is commanded to do so by BigTalker so it would seem there is a delay in processing within the LANNouncer device driver that you are using.

When BigTalker logs show [ PARENT ] TALK(.....) it has passed the phrase on to your speech device's driver to handle from that point forward.

The main points in the logs combined to me in order are (pay no attention to coloring. The forum is doing that I don't speak forum markup well):

12:10:50.291 Your Back Door Sensor changes to open state
12:10:50.742 BigTalker sends the Speak() command for your event group "Doors Open Part 1 Chime" (stating |chime|; using LANNouncer to play a chime tone which never appears to play according to their log)
12:10:52.247 BigTalker sends the Speak() command for your event group "Doors Open Part 2 and Close"  (stating "back door sensor is now open").  Note: This 2 second delay is likely the delay restriction between BigTalker calling speak commands back to back to prevent message cut-offs (ie:  |chime|, wait to prevent back-to-back messages cutting off, now speak "back door sensor is now open")
12:10:54.787 Your Back Door Sensor changes to closed state
12:10:55.152 BigTalker sends the Speak() command for your event group "Doors Open Part 2 and Close" (stating "back door sensor is now closed")
12:12:59.524 LanNouncer sends the (non-standard) HTML GET request to your physical speech device for the SECOND BigTalker speech request stating "back door sensor is now open".  It's worth noting that there is a significant 2 minute delay within LANNouncer processing here.  This is in reference to the 12:10:50.291 contact open event and BigTalker command sent at 2:10:52.247.  Note, we do NOT see the chime command/processing occur within LANNouncer which we should have seen before now so it was never sent from the LANNouncer driver (perhaps it wasn't formatted/understood correctly).  This 2 second delay is likely the delay restriction between BigTalker calling speak commands (ie:  |chime|, wait to prevent back-to-back messages cutting off, now speak "back door sensor is now open") (2 second BigTalker delay; 2 minute LANNouncer delay)
12:13:02.399 LanNouncer sends the (non-standard) HTML GET request to your physical speech device for the THIRD BigTalker command sent at 12:10:55.152 stating "back door sensor is now closed".  It's worth noting that there is again a 2 minute delay within processing here. (265ms BigTalker delay; 2 minute LANNouncer delay)

So, given this data, my analysis is that there is an issue with the LANNouncer port (or just LANNouncer in general) that you are using in Hubitat. Given that there is a consistent 2 minute delay in LANNouncer, I would assume it's something implemented in it's driver code or the way Hubitat is handling it's code/requests. It's definitely in the LANNouncer driver processing. Hubitat is showing the event, I assume on time and BigTalker is responding within reasonable time (2 seconds) yet LANNouncer is taking 2 minutes to sent it's GET requests to your device to speak.

Raw logs, combined, in order (newest to oldest; so read bottom to top for context):

dev:133 2019-02-15 12:13:02.512 warnThe server failed to respond with a valid HTTP response
dev:133 2019-02-15 12:13:02.399 debugGET /&SPEAK=back%20door%20sensor%20is%20now%20closed&@DONE@ HTTP/1.1 Accept: / User-Agent: Linux UPnP/1.0 Hubitat HOST: 192.168.0.111:1035
dev:133 2019-02-15 12:13:02.393 debug040B
dev:133 2019-02-15 12:13:02.392 debugIP address entered is 192.168.0.111 and the converted hex code is C0A8006F
dev:133 2019-02-15 12:13:02.391 infoSending command &SPEAK=back%20door%20sensor%20is%20now%20closed&@DONE@ to 192.168.0.111:1035
dev:133 2019-02-15 12:13:02.388 infoCommand request: &SPEAK=back%20door%20sensor%20is%20now%20closed&@DONE@
dev:133 2019-02-15 12:13:02.387 debugExecuting 'speak'
dev:133 2019-02-15 12:12:59.640 warnThe server failed to respond with a valid HTTP response
dev:133 2019-02-15 12:12:59.524 debugGET /&SPEAK=back%20door%20sensor%20is%20now%20open&@DONE@ HTTP/1.1 Accept: / User-Agent: Linux UPnP/1.0 Hubitat HOST: 192.168.0.111:1035
APP:259 2019-02-15 12:10:55.152 debugBIGTALKER2(P2.0.8.AAB002) || [PARENT] TALK(Doors Open Part 2 and Close.contact) |sS| >> back door sensor is now closed
dev:130 2019-02-15 12:10:54.787 infoBack Door Sensor was closed
dev:130 2019-02-15 12:10:54.390 infoBack Door Sensor is [x:-20,y:-1016,z:85]
dev:130 2019-02-15 12:10:53.382 infoBack Door Sensor is [x:112,y:-1016,z:116]
dev:130 2019-02-15 12:10:52.373 infoBack Door Sensor is [x:92,y:-1021,z:77]
APP:259 2019-02-15 12:10:52.247 debugBIGTALKER2(P2.0.8.AAB002) || [PARENT] TALK(Doors Open Part 2 and Close.contact) |sS| >> back door sensor is now open
dev:130 2019-02-15 12:10:51.369 infoBack Door Sensor is [x:-35,y:-1016,z:96]
APP:259 2019-02-15 12:10:50.742 debugBIGTALKER2(P2.0.8.AAB002) || [PARENT] TALK(Doors Open Part 1 Chime.contact) |sS| >> |chime|
dev:130 2019-02-15 12:10:50.412 infoBack Door Sensor is [x:63,y:-1031,z:57]
dev:130 2019-02-15 12:10:50.398 infoBack Door Sensor is active
dev:130 2019-02-15 12:10:50.291 infoBack Door Sensor was opened
15

Thank you for evaluating the logs. I'll try your suggestions and post my results.

16

Prior to changing the Big Talker message settings and perhaps the code, I had to fix a Samsung motion sensor that was stuck on with motion, with 55% battery. After replacing the battery, and remounting the sensor to the wall, it fell to the floor, stopped working, so it was removed from HE.

So before working on the message issue, I decided to test the system. Surprise, Bigtalker/Lannouncer messages, including the chimes, worked normally. All I can surmise is that hub and motion sensor were in some sort of processing loop or timeout/enque/deque lockup that impacted message processing.