TTS Queue for HA Annoucements

Hi,
I used a combination of @ReneTode and @aimc code in this post to build a small AD module to use for TTS announcements. This has been working well upto about 2 months ago and then it has since just thrown an error. I scrambled around thinking it had to do with API passwords and the like but was wrong.

I hooked this up to simple test app and can now confirm, upon restarting AD (Hassio) and activating the test switch I get an announcement played like before. If I activate it again, nothing is played. It is throwing an error on the try: in the code below. It appears there is an issue getting to the queue object. Nothing is added to the log using the self.log(sys.exc_info()) in the except: block
As this was working fine and then seemed to stop following a HA or AD upgrade at some point a few months ago. I was wondering if this is the result of some AD code change or library change that has happened in the last few months. I am no expert python developer - just hack around for fun - so if there is another way to debug what is going on here that would be good to know

thanks

import appdaemon.plugins.hass.hassapi as hass
from queue import Queue
from threading import Thread
from threading import Event
import time

#
# App to manage announcements via TTS and stream sound files to Google Home
#
# Provides methods to enqueue TTS and Media file requests and make sure that only one is executed at a time
# Volume of the media player is set to a specified level and then restored afterwards
#
# Args:
#
# player: media player to use for announcements
# TTSVolume: media played volume 0-1



class Sound(hass.Hass):

  def initialize(self):
    
    # Create Queue
    self.queue = Queue(maxsize=0)

    # Create worker thread
    t = Thread(target=self.worker)
    t.daemon = True
    t.start()
    self.event = Event()
    
  def worker(self):
    active = True
    while active:
      try:
        # Get data from queue
        data = self.queue.get()
        if data["type"] == "terminate":
          active = False
        else:
          # Save current volume
          volume = self.get_state(self.args["player"], attribute="volume_level")
          
          # Turn on Google and Set to the desired volume
          self.call_service("media_player/turn_on", entity_id = self.args["player"])
          self.call_service("media_player/volume_set", entity_id = self.args["player"], volume_level = self.args["TTSVolume"])
          self.log("Set the Volume to {}".format(self.args["TTSVolume"]))
          
          if data["type"] == "tts":
            # Call TTS service
            self.call_service("tts/google_say", entity_id = self.args["player"], message = data["text"])
            self.log("tThis is the text said - {}".format(data["text"]))
          
          # Sleep to allow message to complete before restoring volume
          time.sleep(int(data["length"]))
          
          # Restore volume
          self.call_service("media_player/volume_set", entity_id = self.args["player"], volume_level = volume)
          
          # Set state locally as well to avoid race condition
          self.set_state(self.args["player"], attributes = {"volume_level": volume})
      except:
        self.log("Error")
        self.log(sys.exc_info()) 

      # Rinse and repeat
      self.queue.task_done()
      
    self.log("Worker thread exiting")
    self.event.set()
       
  def tts(self, text, length):
    self.queue.put({"type": "tts", "text": text, "length": length})
    
  def terminate(self):
    self.event.clear()
    self.queue.put({"type": "terminate"})
    self.event.wait()
1 Like

me neither. so for guys like us there is 1 thing very important: make sure you got good working logfiles, and check them over and over and over!

you normally got at least 2 logfiles 1 for errors and 1 where you get your “normal” output.
the errorlog is your best friend. if you havent set any logfiles in appdaemon.yaml thats the first thing to do.

and when you get errors that you dont understand, thats the part you really want to share.
i can look at your code 1000 times, but without trying and seeing if there is an error, ill probably am as good as you :wink:
there havent been much updates in AD lately, so i dont know what could have been affecting you, but there is 1 other thing i would say to you:
every update that you do, check out if there are breaking changes and after the update check if everything works as expected. if not, take care of it at that point (or as soon as you notice it) if you let it go for months, there are other things changing (for sure if you make other updates) and you get to a point where it gets harder and harder to find out what your original problem was.

Hi Rene,
Yes I do have all logs setup, but nothing is being reported. I do also check the the release notes each app daemon release and nothing relating to this has been called out.
I will add some more debugging, but it does appear the threading and queuing classes have changed/ work different’y was hoping someone had already found this problem and rectified

Also I have noticed of late that the only way I can get app changes to be picked up by AppDaemon is if I restart app daemon. They used to be picked up when ever I saved a new version of either the .py or the .yaml file.

there havent been any changes in that (unless you moved to the dev version)

do you have set production mode in appdaemon.yaml?
if so this is expected behaviour, if not your setup has a problem somewhere.

in the app you have above you got a try/except. remove that and add logging, to see where things go wrong.

and please clear logs, restart AD and show me what is in the logs after startup.

Hi
thanks for helping. I think the queue class is working fine, it just appears that the worker thread is not being called when a new item is added to the queue, it does it the first time around, but then never again unleass I re-start AD

Here is the startup log for AD. Production is set to false in my appdaemon.yaml. I have ~25 AD apps running and they seem to all be working Ok except for the ones using the sound utility to announce things through TTS

[s6-init] making user provided files available at /var/run/s6/etc...exited 0.
[s6-init] ensuring user provided files have correct perms...exited 0.
[fix-attrs.d] applying ownership & permissions fixes...
[fix-attrs.d] done.
[cont-init.d] executing container initialization scripts...
[cont-init.d] 00-banner.sh: executing... 
-----------------------------------------------------------
 Hass.io Add-on: AppDaemon v1.6.0
 Python Apps and HADashboard using AppDaemon 3.x for Home Assistant
 From: Community Hass.io Add-ons
 By: Franck Nijhof <[email protected]>
-----------------------------------------------------------
 armhf / HassOS 1.12 / HA 0.86.4 / SU 142 / stable
-----------------------------------------------------------
[cont-init.d] 00-banner.sh: exited 0.
[cont-init.d] 01-log-level.sh: executing... 
Log level is set to INFO
[cont-init.d] 01-log-level.sh: exited 0.
[cont-init.d] 02-updates.sh: executing... 
INFO: You are running the latest version of this add-on
[cont-init.d] 02-updates.sh: exited 0.
[cont-init.d] 20-init-configuration.sh: executing... 
[cont-init.d] 20-init-configuration.sh: exited 0.
[cont-init.d] 21-compiled-dir.sh: executing... 
[cont-init.d] 21-compiled-dir.sh: exited 0.
[cont-init.d] 30-auto-token.sh: executing... 
INFO: Updating Hass.io API token in AppDaemon with the current one...
[cont-init.d] 30-auto-token.sh: exited 0.
[cont-init.d] 31-ha-url.sh: executing... 
[cont-init.d] 31-ha-url.sh: exited 0.
[cont-init.d] 50-compiled-symlink.sh: executing... 
[cont-init.d] 50-compiled-symlink.sh: exited 0.
[cont-init.d] 80-system-packages.sh: executing... 
[cont-init.d] 80-system-packages.sh: exited 0.
[cont-init.d] 81-python-packages.sh: executing... 
[cont-init.d] 81-python-packages.sh: exited 0.
[cont-init.d] done.
[services.d] starting services
[services.d] done.

This is the app I am using for testing - just fires of a state change of an Input boolean

import appdaemon.plugins.hass.hassapi as hass
import globals
import random

## App for testing

class AppTest(hass.Hass):

    def initialize(self):
        # Subscribe to sensors
        self.sound = self.get_app("ttssound")
        self.utility = self.get_app("utilities")
        self.listen_state(self.state_change_detected, self.args["sensor"])
        self.handle = None


    def state_change_detected(self, entity, attribute, old, new, kwargs):
        name = self.friendly_name(self.args["sensor"])
        #message = self.args["message"] 
        message = self.getLeaveMessage("Scott")
            
        self.sendNotification(message)
        
    def sendNotification(self,  notifyMessage):
        self.log(notifyMessage)
        if self.args["notifyOn"]:
            self.utility.send_notification(notifyMessage,NotificationService = 1, titleText = "Test App")
        self.playTTS(notifyMessage)

    def playTTS(self, TTSMessage):
        self.log(" External tts called")
        self.sound.tts(TTSMessage, len(TTSMessage)/11)

    def getLeaveMessage(self, name):
        with open ('/config/appdaemon/apps/message/leave.txt') as f:
            leavelines = f.read().splitlines()
        quote = (random.choice(leavelines)) %(name)
        return quote     

The utility app where the problem is - with lots of debugging turned on this is instance ttssound. I removed all the try/catch statements it now reflects the original code snipet posted by @aimc inthe post i mentioned above

import appdaemon.plugins.hass.hassapi as hass
from queue import Queue
from threading import Thread
from threading import Event
import time

#
# App to manage announcements via TTS and stream sound files to Google Home
#
# Provides methods to enqueue TTS and Media file requests and make sure that only one is executed at a time
# Volume of the media player is set to a specified level and then restored afterwards
#
# Args:
#
# player: media player to use for announcements
# TTSVolume: media played volume 0-1



class Sound(hass.Hass):

  def initialize(self):
    
    # Create Queue
    self.queue = Queue(maxsize=0)

    # Create worker thread
    t = Thread(target=self.worker)
    t.daemon = True
    t.start()
    self.event = Event()
    self.log("Thread Alive {}, {}" .format (t.isAlive(), t.is_alive()))
  def worker(self):
    while True:
        self.log("Calling TTS from worker")
        #try:
        
        # Get data from queue
        data = self.queue.get()
        self.log(" This is has been pulled off the current Queue {}".format(data))

        # Save current volume
        volume = self.get_state(self.args["player"], attribute="volume_level")
        self.log("Current Volume save {}".format(volume))

        # Turn on Google and Set to the desired volume
        self.call_service("media_player/turn_on", entity_id = self.args["player"])
        self.call_service("media_player/volume_set", entity_id = self.args["player"], volume_level = self.args["TTSVolume"])
        self.log("Set the Volume to {}".format(self.args["TTSVolume"]))
          
        # Call TTS service
        self.call_service("tts/google_say", entity_id = self.args["player"], message = data["text"])
        self.log("This is the text said - {}".format(data["text"]))
          
        # Sleep to allow message to complete before restoring volume
        self.log("Now sleep for {}".format(int(data["length"])))
        time.sleep(int(data["length"]))
          
        # Restore volume
        self.call_service("media_player/volume_set", entity_id = self.args["player"], volume_level = volume)
        self.log("Restore Volume")

        # Set state locally as well to avoid race condition
        self.set_state(self.args["player"], attributes = {"volume_level": volume})
        
        self.queue.task_done()
      
    self.log("Worker thread exiting")

       
  def tts(self, text, length):
    self.queue.put({"text": text, "length": length})
    self.log("Message added to queue Queue enmpy {}".format(self.queue.empty()))
    self.log("Queue Size is now {}".format(self.queue.qsize()))
    self.log(self.queue.queue)

  def terminate(self):
    self.event.clear()
    self.queue.put({"type": "terminate"})
    self.log(" Terminate function called")
    self.event.wait()

A snippet of the info.log ( nothing in the error log.). This is the result of changing the input boolean three times. The first time it fires off the worker thread and plays the TTS message, the subsequent ones are added to the queue, but the worker function is not called

2019-02-03 16:29:01.673543 INFO automation_test: Scott, Life is a series of hellos and goodbyes
2019-02-03 16:29:02.716449 INFO utilities: Scott, Life is a series of hellos and goodbyes
2019-02-03 16:29:02.724997 INFO automation_test:  External tts called
2019-02-03 16:29:02.737850 INFO ttssound:  This is has been pulled off the current Queue {'text': 'Scott, Life is a series of hellos and goodbyes', 'length': 4.181818181818182}
2019-02-03 16:29:02.749289 INFO ttssound: Current Volume save None
2019-02-03 16:29:02.773843 INFO ttssound: Message added to queue Queue enmpy False
2019-02-03 16:29:02.795868 INFO ttssound: Queue Size is now 0
2019-02-03 16:29:02.797518 INFO ttssound: deque([])
2019-02-03 16:29:03.423809 INFO ttssound: Set the Volume to 0.7
2019-02-03 16:29:03.567851 INFO ttssound: This is the text said - Scott, Life is a series of hellos and goodbyes
2019-02-03 16:29:03.582922 INFO ttssound: Now sleep for 4
2019-02-03 16:29:23.017036 INFO automation_test: where for art thou Scott
2019-02-03 16:29:23.786153 INFO utilities: where for art thou Scott
2019-02-03 16:29:23.794649 INFO automation_test:  External tts called
2019-02-03 16:29:23.803889 INFO ttssound: Message added to queue Queue enmpy False
2019-02-03 16:29:23.812771 INFO ttssound: Queue Size is now 1
2019-02-03 16:29:23.814048 INFO ttssound: deque([{'text': 'where for art thou Scott', 'length': 2.1818181818181817}])
2019-02-03 16:29:51.292356 INFO automation_test: Scott has gone, but will return soon
2019-02-03 16:29:53.083603 INFO utilities: Scott has gone, but will return soon
2019-02-03 16:29:53.093565 INFO automation_test:  External tts called
2019-02-03 16:29:53.103075 INFO ttssound: Message added to queue Queue enmpy False
2019-02-03 16:29:53.112814 INFO ttssound: Queue Size is now 2
2019-02-03 16:29:53.114181 INFO ttssound: deque([{'text': 'where for art thou Scott', 'length': 2.1818181818181817}, {'text': 'Scott has gone, but will return soon', 'length': 3.272727272727273}])

@ScottSuine,

I don’t use this code neither am I an expert in threading, but I I think I have an idea why you having this issue.

First looking at this function self.queue.task_done(), you have it being called outside the try..except block. Now this function has the ability to throw up an error, if called more than the number of queue size as explained here. So should only be called, when a task has been executed.

If for any reason that is happening, that will explain why you are not able to catch it and know what is going on. So for starters, do put what within the try..except block. Also I also scanned the original code, and I noticed ti was in there. Besides its possible that might even kill the thread, and you might not know. So will work for the first, but the rest nope it won’t.

I do understand that data = self.queue.get() is supposed to block, until something is inputted into the queue, but its very possible it gets to it and breaks your stuff

Regards

this is not the startup log from AD, but the startup from the addon.
the startuplog from AD shows what apps are loaded and initialised.
and it can also show me if there is a problem in the startup somewhere

you use a thread that is not 1 of the AD threads. errors are not reported in the errorlog because of that, but in the terminalscreen (which you would only see when you start AD manually)

the log shows that the app is alive but the loop in the worker thread dies after the first announcement, but before it gets to the second loop.
you can even see where the thread dies.

we know that this is done, because its in the log:

        self.log("Now sleep for {}".format(int(data["length"])))
        time.sleep(int(data["length"]))

but the next log line never shows. and nothing after that.
so the problem is somewhere here:

        self.log("Now sleep for {}".format(int(data["length"])))
        time.sleep(int(data["length"]))
          
        # Restore volume
        self.call_service("media_player/volume_set", entity_id = self.args["player"], volume_level = volume)
        self.log("Restore Volume")

looking at it a bit more the logs also show me why it goes wrong there.

2019-02-03 16:29:02.749289 INFO ttssound: Current Volume save None

so you try to get the old volume, but it gives you a value None.
after that you try to set the volume to None and the call_service for that gives an error and the loop dies.

then we look to your first code and we see that you got the line

        data = self.queue.get()

inside your try/except an

     self.queue.task_done()

outside it.

because we now know that there was an error inside the try/except, we know that the first line never was executed before the second line was called.
that also breaks the loop with an error.

so you need to find out why this returns None:

      volume = self.get_state(self.args["player"], attribute="volume_level")

did you provide the wrong entity? probably not, because it works once.
so my biggest guess is that the attribute doesnt exist anymore or has changed its name.

Hi,
Thanks. I removed the two lines

volume = self.get_state(self.args["player"], attribute="volume_level")
self.call_service("media_player/volume_set", entity_id = self.args["player"], volume_level = volume)

and it worked. I have checked the attributes for mediaplayer ( google Home) and it appears this is still a valid attribute so I need to dig into a this a little more.
I couple of questions re your last post.

you use a thread that is not 1 of the AD threads. errors are not reported in the errorlog because of that, but in the terminalscreen (which you would only see when you start AD manually)

How do you view these logs or start AD Manually, I can’t seem to find anything in the docs about this. I am running Hassio so maybe this is something that is not possible through the hassio cli? This level of logs would have really helped debugging this

thanks again for your help

i am not sure if its possible and how to start AD manual in hassio.

if you use subthreading like this you could make sure that you get everything in the log by using a lot of try/except.

      try:
        #do 1 line of code
      except:
        self.log("Error describe the line")
        self.log(sys.exc_info()) 

but with debugging like this you need to pay extra attention to the output.
as you saw there was a lot to learn from your logging.
most of all from which logging didnt take place.

Thanks
whats does sys.ec.log do. does it writer to the info.log or to somewhere else?

it gets the last known error from the try/except and does log it in the logfile (at least thats the idea)

So I have had the same issue with the google homes basically what I did was force a value to the current volume if it doesn’t exist so something like this.

volume = self.get_state(<entity_name>, attribute='volume_level') or 0.50

This would allow you to keep your logic and would stop the error.

1 Like

Hi Scott,

Did you do any update on this app? Is it somewhere on github maybe? I wanted to start on a queue for Google home devices and came across this… Would love to build upon it. I have 4 separate devices around the house, wondering if I’m going to make 4 queue(apps) or all 4 in 1 :slight_smile:

Hi there,
This the sound app I have been using for a while now. I recently added the ability to pick from all the speakers in my house for the announcement.

import appdaemon.plugins.hass.hassapi as hass
from queue import Queue
from threading import Thread
from threading import Event
import time
import globals



#
# App to manage announcements via TTS to Google Home
#
# Provides methods to enqueue TTS and Media file requests and make sure that only one is executed at a time
# Volume of the media player is set to a specified level and then restored afterwards
#
# Args:
#
# speaker: media player to use for announcements
# TTSVolume: media played volume 0-1

class Sound(hass.Hass):
  Sound.speakers = [] 
  def initialize(self):
    Sound.speakers = ["dummy"]
    # Create Queue
    self.queue = Queue(maxsize=0)

    # Create worker thread
    t = Thread(target=self.worker)
    t.daemon = True
    t.start()
    self.event = Event()
    self.log("Thread Alive {}, {}" .format (t.isAlive(), t.is_alive()))
    for speaker in self.args["speakers"]:
      Sound.speakers.append(speaker)
    self.log(Sound.speakers)

  def worker(self):
    while True:
      try:
        # Get data from queue
        data = self.queue.get()
        self.log(" This is has been pulled off the current Queue {}".format(data))

        if data["type"] == "terminate":
          active = False
        else:
          current_speaker = Sound.speakers[int(data["speaker"])]

          if self.now_is_between(globals.TTSStart, globals.TTSFinish):
            # Save current volume
            volume = self.get_state(current_speaker, attribute="volume_level")
            self.log("Current Volume save {}".format(volume))

            # Turn on Google and Set to the desired volume
            self.call_service("media_player/turn_on", entity_id = current_speaker)
            self.call_service("media_player/volume_set", entity_id = current_speaker, volume_level = self.args["TTSVolume"])
            self.log("Set the Volume to {}".format(self.args["TTSVolume"]))
            
            # Call TTS service
            self.call_service("tts/google_translate_say", entity_id = current_speaker, message = data["text"])
            self.log("This is the text said - {}".format(data["text"]))
            
            # Sleep to allow message to complete before restoring volume
            self.log("Now sleep for {}".format(int(data["length"])))
            time.sleep(int(data["length"])+3)
            
            # Restore volume
            self.call_service("media_player/volume_set", entity_id = current_speaker, volume_level = volume)
            self.log("Restore Volume")

            # Set state locally as well to avoid race condition
            ##self.set_state(self.args["player"], attributes = {"volume_level": volume})
      except:  
        self.log("Error")
        #self.log(sys.exc_info())
      
      self.queue.task_done()
      
    self.log("Worker thread exiting")
    self.event.set()
       
  def tts(self, text, length, speaker = 0):
    if self.now_is_between(globals.TTSStart, globals.TTSFinish) and speaker !=0 :
       self.queue.put({"type": "tts","text": text, "length": length, "speaker": speaker})

  def terminate(self):
    self.event.clear()
    self.queue.put({"type": "terminate"})
    self.log(" Terminate function called")
    self.event.wait()

The app.yaml is below

ttssound:
  class: Sound
  module: sound
  global_dependencies: globals
  TTSVolume: 0.7
  speakers:
    - media_player.kitchen_display
    - media_player.ensuite_speaker
    - media_player.gallery_speaker
    - media_player.la_speaker
    - media_player.study_speaker
    - media_player.bedrooms
    - media_player.everywhere
    - media_player.upstairs
    - media_player.downstairs
    - media_player.main_speakers
    - media_player.em_speaker
    - media_player.za_speaker

I have a notification include and use an app Arg to configure what speaker is notified for each event, it then calls this sound app to do the job

import appdaemon.plugins.hass.hassapi as hass
import random
import time
import globals

#
# App to handle all notifications across Home Assistant
#
# 
# # Apps

class Notifications(hass.Hass):
    notification_targets = []   
    def initialize(self):
        Notifications.notification_targets = ["dummy"]
        self.sound = self.get_app("ttssound")
        for target in self.args["notification_targets"]:
            Notifications.notification_targets.append(target)
        
    def send(self, text, service = "00",titleText = "Notification", threadID = "HA"):
        """
        This function will take a 2 number binanry number and send messages to the numbers set as 1
        first number = Mobile Phones
        second number = TTS Services as defined in Sound
        """

        targetService = ""
        targetFlag = 0
        notificationQueue = []
        notificationQueue.clear()

        self.log(text)
        # Check first Number - this is for mobile notifcations
        if service[0] == "0":
            notificationQueue.clear()  
        elif service[0] == "6":
           for target_service in Notifications.notification_targets:
               notificationQueue.append(target_service)
        else:
            target_service = Notifications.notification_targets[int(service[0])]
            notificationQueue.append(target_service)
  

        #Send Message
        if service[0] != "0" or service[0] != 0:
          for notification in notificationQueue:
            try:  
              self.call_service(service = notification, title = titleText, message = text , data = {"push":{"thread-id": threadID}})
              logMessage = " {} sent to {}". format(text, notification)
              self.log(logMessage)

            except:
              self.log("Error: Notification Service")
              self.log(notification)
              #self.log(sys.exc_info()) 
        else:
            self.log("No mobile notification service selected")

        # Check second Number. Use the number provided to map to the TTS service in Class Sound
        if service[1] != "0" or service[1] != 0:
            self.sound = self.get_app("ttssound")
            # add some letters to the the service to account for more than 9 Speakers
            if service[1] == "A":
               TTS_service = 10
            elif service[1] == "B":
               TTS_service = 11
            elif service[1] == "C":
               TTS_service = 12
            elif service[1] == "D":
               TTS_service = 13      
            else:   
               TTS_service = int(service[1])
            
            #self.log(TTS_service)
            self.sound.tts(text, len(text)/11, speaker = TTS_service)  
        else:
            return

The method I put in my apps to call the notification service including the TTS service

def send_notifcation(self, notifyMessage):
        self.notifications = self.get_app("notification")
        self.notifications.send(text = notifyMessage,service = self.args["notifcationTarget"],titleText = "Location")

It will notify my phone or the google homes depending on the time off day and the config i send it. I am no developer, so please excue the crude code. Hope this helps

3 Likes