[schedy] Unexpected error running initialize() : without any changes / worked before

[quentin-decre]

Without any changes in my configuration, schedy stopped working. Here is the log I have no matter how many reboots I do.

2021-11-29 10:10:31.313384 INFO schedy_heating: *** 
2021-11-29 10:10:31.318275 INFO schedy_heating: *** This is an app from the hass-apps package.
2021-11-29 10:10:31.323774 INFO schedy_heating: ***   DOCS: https://hass-apps.readthedocs.io/en/stable/
2021-11-29 10:10:31.329503 INFO schedy_heating: *** 
2021-11-29 10:10:31.335286 INFO schedy_heating: *** You like this app, want to honor the effort put into
2021-11-29 10:10:31.340879 INFO schedy_heating: *** it, ensure continuous development and support?
2021-11-29 10:10:31.346188 INFO schedy_heating: *** Then please consider making a donation.
2021-11-29 10:10:31.350953 INFO schedy_heating: ***   DONATE: https://hass-apps.readthedocs.io/en/stable/#donations
2021-11-29 10:10:31.356006 INFO schedy_heating: *** Thank you very much and enjoy schedy!
2021-11-29 10:10:31.360783 INFO schedy_heating: *** 
2021-11-29 10:10:31.479793 INFO schedy_heating: --- Actor type is: 'thermostat'
2021-11-29 10:10:31.520560 WARNING schedy_heating: !!! [R:groundfloorbathroom] [A:climate.heating_groundfloorbathroomheater] HVAC mode support has been disabled, but the modes ['heat'] seem to be supported. Maybe disabling it was a mistake?
2021-11-29 10:10:31.545035 INFO schedy_heating: --> [R:groundfloorbathroom] [A:climate.heating_groundfloorbathroomheater] Received value of 16.0��.
2021-11-29 10:10:41.749759 WARNING schedy_heating: ------------------------------------------------------------
2021-11-29 10:10:41.752421 WARNING schedy_heating: Unexpected error running initialize() for schedy_heating
2021-11-29 10:10:41.755128 WARNING schedy_heating: ------------------------------------------------------------
2021-11-29 10:10:41.764910 WARNING schedy_heating: Traceback (most recent call last):
  File "/usr/lib/python3.9/site-packages/appdaemon/app_management.py", line 165, in initialize_app
    await utils.run_in_executor(self, init)
  File "/usr/lib/python3.9/site-packages/appdaemon/utils.py", line 308, in run_in_executor
    response = future.result()
asyncio.exceptions.TimeoutError
2021-11-29 10:10:41.766476 WARNING schedy_heating: ------------------------------------------------------------
2021-11-29 10:10:41.780285 INFO AppDaemon: App initialization complete

[quentin-decre]

Here is my configuration file, which worked for months :

  module: hass_apps_loader
  class: SchedyApp

  actor_type: thermostat
  reset_at_startup: true # mettre à false après debug

  actor_templates:
    # By default, an actor inherits its settings from the "default" template.
    # removed default template
    default:
      send_retries: 20
      send_retry_interval: 120

  expression_environment: |
    def presence_quentin():
      return state("input_boolean.presence_quentin") == "on"
    def presence_laure():
      return state("input_boolean.presence_laure") == "on"
    def presence_invites():
      return (presence_quentin() or presence_laure()) and state('input_boolean.presence_invites') == 'on'
    def presence_enfants():
      return (presence_quentin() or presence_laure()) and state("input_boolean.presence_enfants") == "on"
    def absence_longue_duree():
      return state("input_boolean.absence_longue_duree") == "on"
    def cheminee_inactive():
      return float(state("input_number.cheminee_puissancebuche")) == 0
    def journee_ecole():
      return state("binary_sensor.enfants_a_l_ecole") == 'on'
    def cold_outside():
      return float(state("sensor.weather_temperature")) < 7

  # température par défaut
  schedule_append:
    - rules:
        # Si on est loin, on met le chauffage en hors gel
        - x: "Next() if absence_longue_duree() else Break()"
        - v: 8
    - rules:
        # Si on est près, on maintien une temperature minimale pas trop basse.
        - x: "Next() if not absence_longue_duree() else Break()"
        - v: 15.5

  rooms:
    groundfloorbathroom:
      actors:
        climate.heating_groundfloorbathroomheater:
          supports_hvac_modes: false
      watched_entities:
        - input_boolean.presence_quentin
        - sensor.weather_temperature
        - input_boolean.absence_longue_duree
      rescheduling_delay: 120
      allow_manual_changes: true
      schedule:
        - x: "Next() if presence_quentin() else Break()"
        - { v: 21, start: "22:00", end: "23:30" }

    lise:
      actors:
        climate.heating_liseheater:
          supports_hvac_modes: false
      watched_entities:
        - input_boolean.presence_enfants
        - input_boolean.presence_quentin
        - input_boolean.presence_laure
        - input_number.cheminee_puissancebuche
        - input_boolean.absence_longue_duree
      rescheduling_delay: 120
      allow_manual_changes: true
      schedule:
        - x: "Next() if presence_enfants() and cheminee_inactive() else Break()"
        - { v: 19, start: "22:00", end: "8:00" }
        - { v: 19, start: "9:00", end: "22:00" }

    alicerose:
      actors:
        climate.heating_roseheater:
          supports_hvac_modes: false
        climate.heating_aliceheater:
          supports_hvac_modes: false
      watched_entities:
        - input_boolean.presence_enfants
        - input_boolean.presence_quentin
        - input_boolean.presence_laure
        - input_number.cheminee_puissancebuche
        - input_boolean.absence_longue_duree
      rescheduling_delay: 120
      allow_manual_changes: true
      schedule:
        - x: "Next() if presence_enfants() and cheminee_inactive()  else Break()"
        - { v: 18, start: "21:00", end: "6:00" }
        - { v: 19.5, start: "6:00", end: "7:00" }
        - { v: 19.5, start: "8:30", end: "21:00" }

    parents:
      actors:
        climate.heating_parentsheater:
          supports_hvac_modes: false
      watched_entities:
        - input_boolean.presence_quentin
        - input_boolean.presence_laure
        - input_boolean.absence_longue_duree
      rescheduling_delay: 120
      allow_manual_changes: true
      schedule:
        - x: "Next() if presence_laure() or presence_quentin() else Break()"
        - { v: 18, start: "23:00", end: "5:00" }
        - { v: 19.5, start: "5:00", end: "7:00" }
        - { v: 20, start: "8:30", end: "18:00" }
        - { v: 19.5, start: "18:00", end: "23:00" }

    kitchen:
      actors:
        climate.heating_kitchenheater:
          supports_hvac_modes: false
      watched_entities:
        - input_boolean.presence_quentin
        - input_boolean.presence_laure
        - input_number.cheminee_puissancebuche
        - sensor.weather_temperature
        - binary_sensor.enfants_a_l_ecole
        - input_boolean.absence_longue_duree
      rescheduling_delay: 120
      allow_manual_changes: true
      schedule:
        - x: "Next() if (presence_laure() or presence_quentin()) and cheminee_inactive() else Break()"
        - rules:
            # On chauffe plus pour les matins frais où il n'y a pas le temps de faire un feu
            - x: "Next() if cold_outside() and journee_ecole() else Break()"
            - { v: 19, start: "4:30", end: "8:00" }
        - rules:
            # On chauffe moins avec la chaudière le matin s'il fait froid dehors
            - x: "Next() if cold_outside() and not journee_ecole() and presence_laure() else Break()"
            - { v: 18, start: "5:00", end: "14:30" }
        - rules:
            - x: "Next() if not cold_outside() and presence_laure() else Break()"
            - { v: 19, start: "6:00", end: "14:30" }
        - rules:
            - x: "Next() if presence_laure() else Break()"
            - { v: 19, start: "14:30", end: "18:00" }
        - { v: 19.5, start: "18:00", end: "21:00" }
        - { v: 19, start: "21:00", end: "23:00" }

    livingroom:
      actors:
        climate.heating_northlivingroomheater:
          supports_hvac_modes: false
        climate.heating_southlivingroomheater:
          supports_hvac_modes: false
      watched_entities:
        - input_boolean.presence_quentin
        - input_boolean.presence_laure
        - input_number.cheminee_puissancebuche
        - sensor.weather_temperature
        - binary_sensor.enfants_a_l_ecole
        - input_boolean.absence_longue_duree
      allow_manual_changes: true
      schedule:
        - x: "Next() if (presence_laure() or presence_quentin()) and cheminee_inactive() else Break()"
        - rules:
            # On chauffe plus pour les matins frais où il n'y a pas le temps de faire un feu
            - x: "Next() if cold_outside() and journee_ecole() else Break()"
            - { v: 20, start: "4:30", end: "8:00" }
        - rules:
            # On chauffe moins avec la chaudière le matin s'il fait froid dehors
            - x: "Next() if cold_outside() and not journee_ecole() and presence_laure() else Break()"
            - { v: 18.5, start: "5:00", end: "14:30" }
        - rules:
            - x: "Next() if not cold_outside() and presence_laure() else Break()"
            - { v: 20, start: "6:00", end: "14:30" }
        - rules:
            - x: "Next() if presence_laure() else Break()"
            - { v: 20, start: "14:30", end: "18:00" }
        - { v: 20.5, start: "18:00", end: "22:00" }
        - { v: 19.5, start: "22:00", end: "23:00" }

    entrance:
      actors:
        climate.heating_entranceheater:
          supports_hvac_modes: false
        climate.heating_mezzanineheater:
          supports_hvac_modes: false
      watched_entities:
        - input_boolean.presence_quentin
        - input_boolean.presence_laure
        - input_number.cheminee_puissancebuche
        - sensor.weather_temperature
        - binary_sensor.enfants_a_l_ecole
        - input_boolean.absence_longue_duree
      allow_manual_changes: true
      schedule:
        - x: "Next() if (presence_laure() or presence_quentin()) and cheminee_inactive() else Break()"
        - rules:
            # On chauffe moins avec la chaudière le matin s'il fait froid dehors
            - x: "Next() if cold_outside() and presence_laure() else Break()"
            - { v: 17, start: "5:00", end: "14:30" }
        - rules:
            - x: "Next() if not cold_outside() and presence_laure() else Break()"
            - { v: 18, start: "6:00", end: "14:30" }
        - rules:
            - x: "Next() if presence_laure() else Break()"
            - { v: 18, start: "14:30", end: "18:00" }
        - { v: 18, start: "18:00", end: "23:30" }

    firstfloorbathroom:
      actors:
        climate.heating_firstfloorbathroomheater:
          supports_hvac_modes: false
      watched_entities:
        - input_boolean.presence_quentin
        - input_boolean.presence_laure
        - input_boolean.presence_enfants
        - input_number.cheminee_puissancebuche
        - input_boolean.absence_longue_duree
      rescheduling_delay: 120
      allow_manual_changes: true
      schedule:
        - x: "Next() if presence_laure() and cheminee_inactive() else Break()"
        - { v: 19, start: "6:00", end: "7:30" }
        - { v: 21, start: "22:00", end: "23:00" }
        - rules:
            - x: "Next() if presence_enfants() else Break()"
            - { v: 21, start: "17:45", end: "18:45" }

[bob1de]

Hi,

It seems like something is taking too long (> 10 secs) during initialization. Actually, I can't tell you what happens there, AppDaemon doesn't produce any meaningful traceback to work with. Probably one of the state queries to Home Assistant times out... Is HA not responding timely? What happens if you just restart AppDaemon after HA was already running for some time?

[quentin-decre]

Hi, Thank you for having a look.

What happens if you just restart AppDaemon after HA was already running for some time?

It just does the same thing

Is HA not responding timely?

I have no performance problem with HA. Just suddenly with Schedy. I thought it was due to an incompatibility with a new version of AppDaemon. And the states watched are basic inputs and of course the climate controllers of my heaters which I have for years.

Home automation is really great, but when it stops working, this is major inconvenience...

[quentin-decre]

If I let schedy run after this error, I have this one regularly (and of course, nothing works ; temperature are not scheduled).

Any idea ?

2021-11-30 15:12:49.256856 WARNING schedy_heating: Unexpected error in worker for App schedy_heating:
2021-11-30 15:12:49.258184 WARNING schedy_heating: Worker Ags: {'id': '7b04e602920743759118452f351d53a0', 'name': 'schedy_heating', 'objectid': '08f3e068fab3425b80c206aa3bd863da', 'type': 'scheduler', 'function': <bound method Room._rescheduling_timer_cb of <Room R:alicerose>>, 'pin_app': True, 'pin_thread': 1, 'kwargs': {'__thread_id': 'thread-1'}}
2021-11-30 15:12:49.259800 WARNING schedy_heating: ------------------------------------------------------------
2021-11-30 15:12:49.262643 WARNING schedy_heating: Traceback (most recent call last):
  File "/usr/lib/python3.9/site-packages/appdaemon/threading.py", line 890, in worker
    funcref(self.AD.sched.sanitize_timer_kwargs(app, args["kwargs"]))
  File "/usr/lib/python3.9/site-packages/hass_apps/schedy/room.py", line 50, in wrapper
    result = handler(self, *args, **kwargs)
  File "/usr/lib/python3.9/site-packages/hass_apps/schedy/room.py", line 196, in _rescheduling_timer_cb
    self.apply_schedule(reset=True)
  File "/usr/lib/python3.9/site-packages/hass_apps/schedy/room.py", line 50, in wrapper
    result = handler(self, *args, **kwargs)
  File "/usr/lib/python3.9/site-packages/hass_apps/schedy/room.py", line 408, in apply_schedule
    self.set_value(new_scheduled_value, force_resend=force_resend)
  File "/usr/lib/python3.9/site-packages/hass_apps/schedy/room.py", line 587, in set_value
    changed |= actor.set_value(value, force_resend=force_resend)[0]
  File "/usr/lib/python3.9/site-packages/hass_apps/schedy/actor/base.py", line 285, in set_value
    self._resending_cb({"left_tries": self.cfg["send_retries"] + 1})
  File "/usr/lib/python3.9/site-packages/hass_apps/schedy/room.py", line 50, in wrapper
    result = handler(self, *args, **kwargs)
  File "/usr/lib/python3.9/site-packages/hass_apps/schedy/actor/base.py", line 93, in _resending_cb
    self.do_send()
  File "/usr/lib/python3.9/site-packages/hass_apps/schedy/actor/thermostat.py", line 323, in do_send
    self.app.call_service(
  File "/usr/lib/python3.9/site-packages/appdaemon/utils.py", line 197, in inner_sync_wrapper
    f = run_coroutine_threadsafe(self, coro(self, *args, **kwargs))
  File "/usr/lib/python3.9/site-packages/appdaemon/utils.py", line 317, in run_coroutine_threadsafe
    result = future.result(self.AD.internal_function_timeout)
  File "/usr/lib/python3.9/concurrent/futures/_base.py", line 447, in result
    raise TimeoutError()
concurrent.futures._base.TimeoutError
2021-11-30 15:12:49.265381 WARNING schedy_heating: ------------------------------------------------------------
2021-11-30 15:12:49.273712 WARNING AppDaemon: callback _rescheduling_timer_cb() in schedy_heating has now completed
2021-11-30 15:21:04.848528 INFO schedy_heating: Previous message repeated 1 times
2021-11-30 15:21:04.849797 INFO schedy_heating: --> [R:alicerose] [A:climate.heating_roseheater] Received value of 15.5��.

[bob1de]

That log again shows a timeout while communicating with HA (during call_service). Do you have lots of apps running in AppDaemon at the same time? Is another app suffering from these errors as well?

I run latest HA + AppDaemon and see nothing like this.

Sorry, but I really have no idea so far, and don't know much about AppDaemon internals either (other than it's a massive beast). Originally I planned to port Schedy onto another framework to get rid of this AppDaemon stuff, but there are other things that are of higher priority right now, which is why Schedy went into maintenance-only mode for now.

[quentin-decre]

Solved \o/

I just rebooted the rasberrypi. Don't ask me why it changed something (I previously tried to restart appdaemon and restart hassio).

Thank you for your time.

[quentin-decre]

Is there any good alternative to schedy ? Because this is great and doing the same with automation will be a pain.

[bob1de]

Oh... expected you to've tried that already. Will try not to forget asking this first in the future ;).

[quentin-decre]

To be honest, I though that restart hassio was a deeper restart that that. But thank you really, I would not have dug that much if you did not came to help.

[quentin-decre]

The problem occured again. I think my sd card is corrupted. Not enough to make hassio crash, but enough to create small, deep and brain fucking bugs. I am backuping and restoring on a new sd card. Hope it solves the problem... If no news from me, consider it was the SDCard. Otherwise, I'll tell you.