appdaemon icon indicating copy to clipboard operation
appdaemon copied to clipboard

Callbacks Show as Never Executed in Admin Interface

Open apop880 opened this issue 5 years ago • 7 comments

I noticed that I had a callback that I would expect would run quite frequently, but showed up with a last executed time of never. I added logging to the function, and it is actually executing, the admin interface just never updates to reflect this. Here are the relevant pieces of the code in question:

class KitchenMotion(hass.Hass):

	def initialize(self):
		self.listen_state(self.motion_off, "sensor.zooz_zse40_4_in_1_sensor_alarm_level_2", new = "0", duration = 5*60)
		self.listen_state(self.motion_on, "sensor.zooz_zse40_4_in_1_sensor_alarm_level_2")
		self.listen_state(self.luminance, "sensor.zooz_zse40_4_in_1_sensor_luminance_2")
	def motion_off(self, entity, attribute, old, new, kwargs):
		#do stuff
	def motion_on(self, entity, attribute, old, new, kwargs):
		#do stuff
	def luminance(self, entity, attribute, old, new, kwargs):
		#do stuff

The motion_off callback is the one that shows as never executing, so perhaps the additional arguments of new and duration could have something to do with it.

apop880 avatar Jul 20 '20 18:07 apop880

Just in case this additional information helps, I'm running AppDaemon 4.0.3 via the Home Assistant add-on. I also did some additional analysis and found that other apps with new, old, or attribute in the callback arguments all populate the last executed time in the admin interface. However, I reproduced the issue in another app that had a callback with a duration argument, so I think that could be the source of the issue.

apop880 avatar Jul 21 '20 02:07 apop880

Okay, ran into this again and did a little more digging with a new app I was working on that uses a duration dependent state callback.

Under the hood, it looks like at the time of state change, a one-time scheduler callback is created for the amount of time in the future of the duration length. So, if I've got a callback with a duration of 60, when the state changes, a scheduler callback is created with an execution time of 60 seconds in the future. I can see that scheduler callback in the admin interface, and then at the time it executes, it is immediately removed from the admin interface. However, when that scheduler callback executes, it never goes back and marks the state change callback as executed in the admin interface.

apop880 avatar Sep 05 '20 13:09 apop880

the AI is still under construction, and for complicated listeners like that its very hard to get it with a correct state.

i dont even know if it would be worth trying to get that right either. because indeed duration starts a schedular and cancels it if within the given time another state change takes place. so its actually a combination from a listen_state and a run_in.

to get a correct update from the listener in the AI there should be added another thing to the run_in that updates the listener entity. but that means that for that time the listener needs to be saved, and the run_in also needs to be told who started it.

my personal opinion is that it complicates AD in the background more then wanted, just to get a statistic right. i think a notice in the docs telling that duration causes the listener state to be incorrect would be better.

ReneTode avatar Sep 06 '20 20:09 ReneTode

@ReneTode Thanks for the confirmation that this is expected behavior presently. That explanation makes sense.

I would say that if the admin interface is going to be there, it ought to be an accurate source of truth for everything, so ideally I think it makes sense to eventually do the work under the hood to get the statistic right. If I'm using it to make sure my callbacks are firing the way I expect them to, having that consistency in the admin interface would be nice (especially since duration callbacks add a level of complexity to debugging).

It's definitely not a high priority, though. As an intermediate change, I'd propose updating the interface so that for duration callbacks, instead of listing a last executed time of never, and 0 times fired and executed, putting N/A in those fields instead, perhaps with a tooltip noting that duration callbacks cannot be accurately tracked at this time.

apop880 avatar Sep 09 '20 15:09 apop880

I would say that if the admin interface is going to be there, it ought to be an accurate source of truth for everything, so ideally I think it makes sense to eventually do the work under the hood to get the statistic right. If I'm using it to make sure my callbacks are firing the way I expect them to, having that consistency in the admin interface would be nice

if the docs explain that the liste_state with duration actually isnt a listen state, it would be enough in my eyes. you dont see how many times you have fired a run_in also.

im not sure if it would be easy to change 0 to N/A for some listeners. but if thats possible i think it would be the easiest solution.

but im sure Andrew will go the difficult way and make the stats accurate at some point in the future, and i dont expect he wil spend time for an inbetween solution. ;)

ReneTode avatar Sep 09 '20 16:09 ReneTode

you dont see how many times you have fired a run_in also.

To be fair, though, in that case that's because the run_in callback is discarded and no longer even visible in the admin interface as soon as it runs (though having a view to see those historical callbacks that no longer exist might be a nice future enhancement)

im not sure if it would be easy to change 0 to N/A for some listeners. but if thats possible i think it would be the easiest solution.

I'll try and look into the code when I have a chance and see if I can put in a PR.

apop880 avatar Sep 10 '20 15:09 apop880

(though having a view to see those historical callbacks that no longer exist might be a nice future enhancement)

nope we had that because of a bug. a very active AD breaks down in a few hours because of that. unless AD starts to create logs for the entity states, but that would severly slow down AD.

so no such things are not really wanted.

i think people should take care of there own history, because it has quite an impact. (thats also the reason why i did stop the history from HA years ago)

I'll try and look into the code when I have a chance and see if I can put in a PR.

if you do so then make sure you add correct info and doc changes. and dont expect it will be implemented shortly (unless Andrew suddenly gets more available time)

ReneTode avatar Sep 10 '20 18:09 ReneTode