[schedy] Failed service calls cause an unhandled exception

[kat0r]

Hi,
I got a room (unten) with 3 thermostats (untenl, untenr, oben). Today schedy failed to set the value for one (climate.oben) of them, and then completely ignored it forever (I assume until the next schedules change/restart).

Log:

2019-12-30 08:00:00.050194 INFO schedy_heating: <-- [R:unten] [A:climate.untenl] Setting value 21.0�� (left tries = 11, interval = 30).
2019-12-30 08:00:00.052176 INFO schedy_heating: <-- [R:unten] [A:climate.untenl] Setting temperature = 21.0��, HVAC mode = '<unset>'.
2019-12-30 08:00:03.776438 INFO schedy_heating: <-- [R:unten] [A:climate.untenr] Setting value 21.0�� (left tries = 11, interval = 30).
2019-12-30 08:00:03.778646 INFO schedy_heating: <-- [R:unten] [A:climate.untenr] Setting temperature = 21.0��, HVAC mode = '<unset>'.
2019-12-30 08:00:06.978859 INFO schedy_heating: <-- [R:unten] [A:climate.oben] Setting value 21.0�� (left tries = 11, interval = 30).
2019-12-30 08:00:06.981146 INFO schedy_heating: <-- [R:unten] [A:climate.oben] Setting temperature = 21.0��, HVAC mode = '<unset>'.
2019-12-30 08:00:15.061688 WARNING AppDaemon: ------------------------------------------------------------
2019-12-30 08:00:15.062481 WARNING AppDaemon: Unexpected error in worker for App schedy_heating:
2019-12-30 08:00:15.062700 WARNING AppDaemon: Worker Ags: {'name': 'schedy_heating', 'id': UUID('de9d66b9-6b08-4b89-bed3-fa78b25e6d13'), 'type': 'timer', 'function': <bound method Room._scheduling_timer_cb of <Room R:unten>>, 'kwargs': {'interval': 86400}}
2019-12-30 08:00:15.062965 WARNING AppDaemon: ------------------------------------------------------------
2019-12-30 08:00:15.063756 WARNING AppDaemon: Traceback (most recent call last):
  File "/usr/lib/python3.7/site-packages/appdaemon/appdaemon.py", line 586, in worker
    funcref(self.sanitize_timer_kwargs(app, args["kwargs"]))
  File "/usr/lib/python3.7/site-packages/hass_apps/schedy/room.py", line 50, in wrapper
    result = handler(self, *args, **kwargs)
  File "/usr/lib/python3.7/site-packages/hass_apps/schedy/room.py", line 204, in _scheduling_timer_cb
    self.apply_schedule()
  File "/usr/lib/python3.7/site-packages/hass_apps/schedy/room.py", line 50, in wrapper
    result = handler(self, *args, **kwargs)
  File "/usr/lib/python3.7/site-packages/hass_apps/schedy/room.py", line 409, in apply_schedule
    self.set_value(new_scheduled_value, force_resend=force_resend)
  File "/usr/lib/python3.7/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.7/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.7/site-packages/hass_apps/schedy/room.py", line 50, in wrapper
    result = handler(self, *args, **kwargs)
  File "/usr/lib/python3.7/site-packages/hass_apps/schedy/actor/base.py", line 93, in _resending_cb
    self.do_send()
  File "/usr/lib/python3.7/site-packages/hass_apps/schedy/actor/thermostat.py", line 326, in do_send
    temperature=temp.value,
  File "/usr/lib/python3.7/site-packages/appdaemon/plugins/hass/hassapi.py", line 22, in func_wrapper
    return func(*args, **kwargs)
  File "/usr/lib/python3.7/site-packages/appdaemon/plugins/hass/hassapi.py", line 522, in call_service
    r.raise_for_status()
  File "/usr/lib/python3.7/site-packages/requests/models.py", line 940, in raise_for_status
    raise HTTPError(http_error_msg, response=self)
requests.exceptions.HTTPError: 500 Server Error: Internal Server Error for url: http://hassio/homeassistant/api/services/climate/set_temperature

2019-12-30 08:00:15.063960 WARNING AppDaemon: ------------------------------------------------------------
2019-12-30 08:00:15.065019 INFO schedy_heating: --> [R:unten] [A:climate.untenl] Attribute 'temperature' is 21.0.
2019-12-30 08:00:15.066506 INFO schedy_heating: --> [R:unten] [A:climate.untenl] Attribute 'current_temperature' is 21.0.
2019-12-30 08:00:15.067997 INFO schedy_heating: --- [R:unten] [A:climate.untenl] Cancelled re-sending timer.
2019-12-30 08:00:15.069310 INFO schedy_heating: --> [R:unten] [A:climate.untenl] Received value of 21.0��.
2019-12-30 08:00:15.070741 INFO schedy_heating: <-- [R:unten] Sending state to HA: state='21.0', attributes={'actor_wanted_values': {'climate.untenl': '21.0', 'climate.untenr': '21.0', 'climate.oben': '21.0'}, 'scheduled_value': '21.0', 'rescheduling_time': None, 'overlay_active': False}
2019-12-30 08:00:15.093425 INFO schedy_heating: --> [R:unten] [A:climate.untenr] Attribute 'temperature' is 21.0.
2019-12-30 08:00:15.095015 INFO schedy_heating: --> [R:unten] [A:climate.untenr] Attribute 'current_temperature' is 21.0.
2019-12-30 08:00:15.096561 INFO schedy_heating: --- [R:unten] [A:climate.untenr] Cancelled re-sending timer.
2019-12-30 08:00:15.097899 INFO schedy_heating: --> [R:unten] [A:climate.untenr] Received value of 21.0��.
2019-12-30 08:00:15.099850 INFO schedy_heating: --- [R:unten] Unchanged HA state: state='21.0', attributes={'actor_wanted_values': {'climate.untenl': '21.0', 'climate.untenr': '21.0', 'climate.oben': '21.0'}, 'scheduled_value': '21.0', 'rescheduling_time': None, 'overlay_active': False}
2019-12-30 08:02:12.869535 INFO schedy_heating: --> [R:unten] [A:climate.untenl] Attribute 'temperature' is 21.0.
2019-12-30 08:02:12.871628 INFO schedy_heating: --> [R:unten] [A:climate.untenl] Attribute 'current_temperature' is 21.0.
2019-12-30 08:02:12.873643 INFO schedy_heating: --- [R:unten] Unchanged HA state: state='21.0', attributes={'actor_wanted_values': {'climate.untenl': '21.0', 'climate.untenr': '21.0', 'climate.oben': '21.0'}, 'scheduled_value': '21.0', 'rescheduling_time': None, 'overlay_active': False}
2019-12-30 08:02:14.821104 INFO schedy_heating: --> [R:unten] [A:climate.untenr] Attribute 'temperature' is 21.0.
2019-12-30 08:02:14.823097 INFO schedy_heating: --> [R:unten] [A:climate.untenr] Attribute 'current_temperature' is 21.0.

In this case I would expect schedy to retry, ignoring the error.

[bob1de]

Hi,

Thanks for reporting.

Hmm, I'll have to think about how to handle this best. Never faced an exception during a service call. Maybe this should just cause AppDaemon to restart the whole app...

I'll keep you updated.

Best regards
Robert

[stovedoctor]

was this resolved? after a month of use and no changes other that hassio update now I'm getting the same errors. I uninstalled appdaemon and schedy reloaded appdaemon and no error until I set up schedy again.

[stovedoctor]

was this resolved? after a month of use and no changes other that hassio update now I'm getting the same errors. I uninstalled appdaemon and schedy reloaded appdaemon and no error until I set up schedy again.

I figured out my issue.
The configuration screwed up
appdaemon.yaml
My url to the http port was formated wrong