[SOLVED] "thread has died - thread will be restarted" loop

I’m having some issues with at least two apps that, under certain “as of yet not completely known” conditions results in an endless loop of:

2022-06-03 15:18:11.948322 CRITICAL AppDaemon: Thread thread-5 has died
2022-06-03 15:18:11.949037 CRITICAL AppDaemon: Pinned apps were: ['car_charge_automation']
2022-06-03 15:18:11.949872 CRITICAL AppDaemon: Thread will be restarted
2022-06-03 15:18:11.950457 INFO AppDaemon: Adding thread 5
2022-06-03 15:18:11.951699 CRITICAL AppDaemon: Thread thread-19 has died
2022-06-03 15:18:11.952173 CRITICAL AppDaemon: Pinned apps were: ['dishwasher_finished']
2022-06-03 15:18:11.952677 CRITICAL AppDaemon: Thread will be restarted
2022-06-03 15:18:11.953380 INFO AppDaemon: Adding thread 19

With my (documented) difficulty understanding timers, I’m kind of suspecting that might be the culprit. I did see something similar in a different thread, but I don’t think the suggestion there is relevant for the first one (car_charge_automation).

For the second (dishwasher_finished), there was something suspiciously similar, namely:

self.power_timer = self.run_in(self.who_and_when(old=old, new=new), 900)

I have tried a few different ways of doing this now, but nothing so far that has worked for me.

I think they work; I get the expected notification, but then the loop starts, and I’m assuming they won’t work again while that’s happening?

AppDaemon script for "car_charge_automation"
import datetime
import hassapi as hass
import globals


class CarCharger(hass.Hass, globals.Entities, globals.Functions):

    def initialize(self):

        self.start_time = None
        self.automate_off_timer = None

        self.charge_time = 3 # Number of hours for full charge. Change with new car.
        self.finish_time = 7 # What time in the morning to finish.

        self.automate(None, None, None, None, None)

        self.listen_state(self.automate, self.nordpool["current_price"], attribute = "tomorrow", old= 24 * [None])
        self.listen_state(self.automate, self.nordpool["current_price"], attribute = "tomorrow", old= [])
        self.listen_state(self.automate, self.automation_control["car_charger"], new="on")
        self.listen_state(self.automate, self.edgeos["kia_niro"], new="on")

        self.run_daily(self.automate(None, None, None, None, None), "22:00:00")

        self.listen_event(self.charge_now, "CAR_CHARGER")
        # self.listen_event(self.automate, "SET_CAR_CHARGER") # Covered by turning off, then on the boolean.


    def automate(self, entity, attribute, old, new, kwargs):
        """
        Determine whether the charger should be automated.
        If yes, run scripts to determine when if the prices for tomorrow are
        available.
        Otherwise turn off, and the listen_state for that attribute will run
        when it is populated by a list of prices (instead on [None]).
        """

        if self.get_state(self.automation_control["car_charger"]) == "on":
            on_time = self.determine_cheapest_time()
            self.toggle_charge_state(on_time)

    def determine_cheapest_time(self):
        """
        Determine the best time to start charging.
        There should probably be a limit that it won't do so before the nordpool
        sensor has prices for tomorrow.
        """

        today = self.get_entity(self.nordpool["current_price"]).get_state(attribute="today")
        tomorrow = self.get_entity(self.nordpool["current_price"]).get_state(attribute="tomorrow")
        now = self.get_state("sensor.time")
        now_hour = int(now.split(":")[0])
        today_from_now = today[now_hour:]
        today_and_tomorrow = self.wait_for_tomorrow_prices(today, tomorrow, today_from_now)
        today_datetime = datetime.date.today()
        tomorrow_datetime = datetime.date.today() + datetime.timedelta(1)

        if today_and_tomorrow != []: # Finds the index, t = i, corresponding to the start time/cost that yoields the cheapest 3 cosecutive hours ending before 07:00. 
            p = 100
            t = None
            for i in range(len(today_and_tomorrow) - (self.charge_time - 1)):
                p1 = 0
                for j in range(self.charge_time):
                    p1 += today_and_tomorrow[i + j]
                if p1 < p:
                    p = p1
                    t = i #  t is an index in the list of prices per hour starting at current time, and going until midnight if not tomorrow times available, or until self.finish_time if they are.

            what_time = t + now_hour # get the hour of the day to start. 

            if what_time >= 24:
                on_time = datetime.datetime.combine(tomorrow_datetime, datetime.time(what_time - 24, 0))
            else:
                on_time = datetime.datetime.combine(today_datetime, datetime.time(what_time, 0))

            return on_time

    def wait_for_tomorrow_prices(self, today, tomorrow, today_from_now):
        """
        Determine whether to wait for tomorrows prices.
        If plugging in after midninght, but before 07:00, don't wait.
        """

        if self.now_is_between("00:00:00", "08:00:00"):
            return today_from_now
        elif len(tomorrow) == 24:
            try:
                float(tomorrow[1]) # Sometimes I've seen 24 * None
                return today_from_now + tomorrow[:self.finish_time]
            except:
                self.turn_on(self.car_charger["sleep_mode"])
                return []
        else:
            self.turn_on(self.car_charger["sleep_mode"])
            return []


    def toggle_charge_state(self, on_time):

        connected_states = ["charging", "connected"]

        now_datetime = self.get_now()

        if self.get_state(self.car_charger["station_status"]) in connected_states:
            if on_time >= datetime.datetime.now():
                self.turn_on(self.car_charger["sleep_mode"])

        data = {"tag": "car_charger_notification"}

        self.call_service(self.notify_phones["walden"], message="Car Charger set for " + str(on_time), data=data)

        if self.start_time: # Recommended here: https://community.home-assistant.io/t/cancel-timer-reporting-invalid-callback-handle/426416/2
            if self.timer_running(self.start_time):
                self.cancel_timer(self.start_time)
            self.start_time = None

        try:
            self.start_time = self.run_at(self.start_charging, on_time) # Can do if event is not in the past.
        except:
            self.start_charging(None) # If on_time was in the past, just start now.

        state, attributes = self.future_events()

        try:
            attributes["car_charging"] = on_time
        except:
            attributes = {"car_charging": "not set"}
            attributes["car_charging"] = on_time
        self.set_state("binary_sensor.future_events", state="on", attributes=attributes)


    def start_charging(self, kwargs):

        self.turn_off(self.car_charger["sleep_mode"])


    def charge_now(self, event_name, data, kwargs):

        if self.automate_off_timer: # Recommended here: https://community.home-assistant.io/t/cancel-timer-reporting-invalid-callback-handle/426416/2
            if self.timer_running(self.automate_off_timer):
                self.cancel_timer(self.automate_off_timer)
            self.automate_off_timer = None

        # if self.automate_off_timer != None:
        #     self.cancel_timer(self.automate_off_timer)
        self.turn_off(self.automation_control["car_charger"])
        self.turn_off(self.car_charger["sleep_mode"])
        self.automate_off_timer = self.run_in(self.turn_on_automation, 10800)

    def turn_on_automation(self):

        self.turn_on(self.automation_control["car_charger"])

    def notify_if_not_charging(self):

        pass
AppDaemon script for "dishwasher_finished"
import hassapi as hass
import globals

class Appliances(hass.Hass, globals.Entities, globals.Functions):

    def initialize(self):

        self.notification_timer = None
        self.power_timer = None

        self.listen_state(self.timer_function, self.power_sensors["dishwasher"])

    def timer_function(self, entity, attribute, old, new, kwargs):
        """
        Check that the dishwasher power consumption is "low", and stays there upon next state update.
        """

        if 20 > float(old) > 10 and float(new) < 5:
            if self.power_timer == None:
                self.power_timer = self.run_in(self.who_and_when(old=old, new=new), 900) #900

    def who_and_when(self, **kwargs): #(self, old, new):
        """
        Check whether the dishwasher is finished (dropping below 5 W).
        Determine who is home to empty it.
        """

        home = []
        old = kwargs["old"]
        new = kwargs["new"]

        if self.get_state(self.device_trackers["emilie"]) == "home":
            home.append("emilie")
        if self.get_state(self.device_trackers["naia"]) == "home":
            home.append("naia")
        if self.get_state(self.device_trackers["kristina"]) == "home":
            home.append("kristina")
        if self.get_state(self.device_trackers["walden"]) == "home":
            home.append("walden")

        self.notify(home, old, new)

        # if len(home) > 0:
        #     if self.awake():
        #         # self.notify(home, old, new)
        #         self.notify(home)
        #     else:
        #         today = self.get_entity(self.workday["actual"]).get_state(attribute = "workday_today") == "on"
        #         tomorrow = self.get_entity(self.workday["actual"]).get_state(attribute = "workday_tomorrow") == "on"
        #         if self.now_is_between("19:30:00", "00:00:00") and tomorrow:
        #             self.notification_timer = self.run_at(self.notify(home, old, new), "07:15:00")
        #         elif self.now_is_between("19:30:00", "00:00:00") and not tomorrow:
        #             self.notification_timer = self.run_at(self.notify(home, old, new), "10:00:00")
        #         elif self.now_is_between("00:00:00", "07:15:00") and today:
        #             self.notification_timer = self.run_at(self.notify(home, old, new), "07:15:00")
        #         elif self.now_is_between("00:00:00", "10:00:00") and not today:
        #             self.notification_timer = self.run_at(self.notify(home, old, new), "10:00:00")


    def notify(self, home, old, new):

        who = home[0]
        notify_who = self.notify_phones[who]
        kids = ["emilie", "naia", "luca"]
        today = self.get_entity(self.workday["actual"]).get_state(attribute="workday_today") == "on"
        tomorrow = self.get_entity(self.workday["actual"]).get_state(attribute="workday_tomorrow") == "on"

        self.call_service(
            self.notify_phones["walden"],
            message = "Opvaskemaskinen er klar til at blive tømt. \nNotify_Who = " + str(notify_who) + ". \nHome = " + str(home) + ".\n old, new = " + str(old) + ", " + str(new)
        )

        # self.call_service(
        #     notify_who,
        #     message = "Opvaskemaskinen er klar til at blive tømt"
        # )
        #
        # if home[0] in kids:
        #     if any((
        #         all(
        #             tomorrow, self.now_is_between("12:00:00", "20:30:00")
        #         ),
        #         all(
        #             today, self.now_is_between("08:00:00", "12:00:00")
        #         ),
        #         all(
        #             not tomorrow, self.now_is_between("12:00:00", "21:30:00")
        #         ),
        #         all(
        #             not today, self.now_is_between("10:00:00", "12:00:00")
        #         )
        #     )):
        #         self.speak()

        title = "Opvaskemaskinen skal tømmes!"
        message = ", opvaskemaskinen er klar til at blive tømt. Husk at starte den igen hvis du fylder den."

        if len(home) > 0:
            pass
            # self.call_service(self.notify_phones[who], title=title, message=who.capitalize() + message)
        else:
            people_to_empty = ["naia", "emilie", "kristina", "walden"]
            for device in people_to_empty:
                self.someone_coming_home = self.listen_state(self.message_when_home, self.device_trackers[device])

        # self.call_service(
        #     "notify/" + self.notify_devices["walden_phone"],
        #     message = "Opvaskemaskinen er klar til at blive tømt"
        # )

    def message_when_home(self, entity, attribute, old, new, kwargs):

        title = "Opvaskemaskinen skal tømmes!"
        message = ", opvaskemaskinen er klar til at blive tømt. Husk at starte den igen hvis du fylder den."
        home = [key for key, val in self.device_trackers.items() if entity == val][0]

        self.call_service(self.notify_phones[entity], title=title, message=home.capitalize() + message)
        self.cancel_listen_state(self.someone_coming_home)

    def speak(self):

        self.call_service(
            "tts/google_translate_say",
            entity_id=self.speakers["top_floor_speaker"],
            message="Opvaskemaskinen er klar til at blive tømt",
            language="da"
        )

if you get those messages, the only thing you can do is restart AD. and indeed it doesnt work anymore at that time.

i did take a short look at the code, but its to much to see a clear cause.
its possible that you change the state from an entity that then triggers an action in the app and it starts looping.

my advise:
add logging, add logging and add more logging.
at the beginning from each function, at the end from each function, after you did retrieve a state, etc.
the more the better.
and then when the app has crashed, look at your logs to see what went wrong.
without logging your driving blind.

and a simple explanation from timers:

self.handler = self.run_in(self.some_cb, 60) does the following:

in a list with all timers there is a record added.

id                                               -  callback                 - time
the number that you find in the self.handler var - the function self.some_cb - the calculated start time

every second AD looks at that list to see if a callback should be triggered.
when its activated its taken from the list
and when you have saved the id (so when you used self.handler = ) then you can use that ID to cancel the timer or to see info about it.

AD doesnt know if you saved the ID or not. so

self.run_in(self.some_cb, 60)

does the exact same thing as

self.handler = self.run_in(self.some_cb, 60)

self.handler is just a normal variable where you store the id if you want to use it later on. (to cancel or retrieve info)

i hope that makes it more clear.

Logs do help a bit:)

To me it looks like the run_in() runs immediately, not after the duration specified.

In the “simpler” of the apps above (diswasher_finished) I see that adding some logging in the first function:

    def timer_function(self, entity, attribute, old, new, kwargs):

        self.log("Dishwasher TIMER FUNCTION", log="diag_log")

        if 20 > float(old) > 10 and float(new) < 5:
            self.log(self.power_timer, log="diag_log")

            if self.power_timer == None:
                self.power_timer = self.run_in(self.who_and_when(old=old, new=new), 5) #900
                self.log("TIMER - AFTER TIMER SET", log="diag_log")
                self.log(self.power_timer, log="diag_log")

Gives logs that make me think it’s not waiting the 5 seconds before running the next function (self.who_and_when()). See my comment at end of log line (third line shouldn’t log until 5 seconds after the first two?):

logs:

2022-06-04 13:49:13.104683 INFO dishwasher_finished: Dishwasher TIMER FUNCTION <-- logged in timer_function()
2022-06-04 13:49:13.105444 INFO dishwasher_finished: None <-- logged in timer_function()
2022-06-04 13:49:13.107449 INFO dishwasher_finished: Dishwasher WHO AND WHEN <-- logged in who_and_when(). Should not log until 5 seconds after timer_function()??
2022-06-04 13:49:13.108040 INFO dishwasher_finished: None <-- logged in who_and_when(). Should not log until 5 seconds after timer_function()??
2022-06-04 13:49:13.118976 INFO dishwasher_finished: Dishwasher NOTIFY <-- logged in notify(). Should not log until 5 seconds after??
2022-06-04 13:49:13.119746 INFO dishwasher_finished: None <-- logged in notify(). Should not log until 5 seconds after??
2022-06-04 13:49:13.141171 INFO dishwasher_finished: TIMER - AFTER TIMER SET <-- logged in timer_function(), but on the line AFTER the self.run_in()
2022-06-04 13:49:13.144082 INFO dishwasher_finished: e01101d172e0446ab7b39b38893eb71f <-- logged in timer_function(), but on the line AFTER the self.run_in(). Now the timer is set.

I do also get something in the logs that I can see when writing to a file (they were hidde by all the new entries about thread restarting when just looking at STDOUT):

2022-06-04 13:47:36.746321 INFO AppDaemon: App initialization complete
Exception in thread thread-19:
Traceback (most recent call last):
  File "/usr/lib/python3.9/threading.py", line 973, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.9/threading.py", line 910, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/lib/python3.9/site-packages/appdaemon/threading.py", line 891, in worker
    callback = "{}() in {}".format(funcref.__name__, name)
AttributeError: 'NoneType' object has no attribute '__name__'
2022-06-04 13:49:18.079434 CRITICAL AppDaemon: Thread thread-19 has died
2022-06-04 13:49:18.080816 CRITICAL AppDaemon: Pinned apps were: ['dishwasher_finished']
2022-06-04 13:49:18.081197 CRITICAL AppDaemon: Thread will be restarted
2022-06-04 13:49:18.081631 INFO AppDaemon: Adding thread 19

I did also notice that during AppDaemon startup, it logs:

2022-06-04 13:47:36.331654 WARNING HASS: Error calling Home Assistant service default/homeassistant/turn_off
2022-06-04 13:47:36.332323 WARNING HASS: Code: 500, error: 500 Internal Server Error
Server got itself in trouble

But doesn’t say which app is doing something wrong. I don’t think it’s related (since I don’t call any turn_off, just wanted to mention in case it’s important.

Update: It was mainly that I was passing (and/or “receiving”) arguments in a wrong way when using any of the timed functions like run_in, run_at.

For the diswasher_finished, I think it was because I used **kwargs instead of kwargs in a app definition; changing

    def who_and_when(self, **kwargs):

to

    def who_and_when(self, kwargs):

stopped the restart loop.

For the car_charge_automation, it was the part run_daily under initialize it didn’t like. I think you can’t/shouldn’t pass positional arguments through that.

I solved it by writing a “dummy” function:

    def daily_wrapper(self, kwargs):
        self.automate(None, None, None, None, None)

and changing the run_daily to

        self.run_daily(self.daily_wrapper, "23:35:00")

And the

2022-06-04 23:20:47.935718 WARNING HASS: Error calling Home Assistant service default/homeassistant/turn_on
2022-06-04 23:20:47.936531 WARNING HASS: Code: 500, error: 500 Internal Server Error
Server got itself in trouble

Looks like a HACS integration that needed to be updated to a beta version to be compatible with Hass Core 2022.6.

So I think it’s all sorted out. If not, I’ll update, i case anyone stumbles on this thread for answers.

indeed you cant use

self.run_in(self.cb(anything), 60)

because then you place a function where it should be a callback.
so it should be

self.run_in(self.cb, 60, anything = anything)

and that goes for all functions like run_in, run_at, run_every, listen_state, etc.

the name kwargs in the callback is actually chosen wrong in the past.
it is actually

def callback(self, my_transport_dict):

for passing variables to the callback you can use:

    self.run_in(self.callback, 60, my_var = "something")
    self.run_daily(self.callback, time, my_var = "something else")

def callback( self, my_transport_dict): # you can still use kwargs as name there
    my_var = my_transport_dict["my_var"]

for your error during startup: HA probably hasnt all its services ready when AD starts up.
that can be changed by adding a delay to the HA plugin in the appdaemon.yaml

2 Likes