AppDaemon bug or am I misunderstanding something?

bg1000 · April 4, 2019, 1:34am

This seems like a possible bug to me but I am fairly new to AppDaemon so I thought I would ask if I am missing something.

I have the following app:

class AlarmOff(hass.Hass):

    def initialize(self):
        self.listen_state(self.someone_home, "person.XXXX", new = "home")

    def someone_home(self, entity, attribute, old, new, kwargs):
        self.log("appdaemon version: " + self.get_ad_version())
        self.log("entity = " + str(entity))
        self.log("attribute = " + str(attribute))
        self.log("old = " + str(old))
        self.log("new = " + str(new))
        if self.get_state("alarm_control_panel.XXXX") == "armed_away":
            self.log("Someone is home. Shutting off the alarm from appdaemon.")
            self.call_service("alarm_control_panel/alarm_disarm",entity_id = "alarm_control_panel.XXXX")

If I check the log file at anytime after person.XXXX arrives home I see something like this:

2019-04-03 19:48:45.736356 INFO AlarmOff: attribute = state
2019-04-03 19:48:45.738526 INFO AlarmOff: old = home
2019-04-03 19:48:45.744738 INFO AlarmOff: new = home
2019-04-03 19:49:49.719596 INFO AlarmOff: appdaemon version: 3.0.2
2019-04-03 19:49:49.721849 INFO AlarmOff: entity = person.XXXX
2019-04-03 19:49:49.723982 INFO AlarmOff: attribute = state
2019-04-03 19:49:49.728326 INFO AlarmOff: old = home
2019-04-03 19:49:49.730595 INFO AlarmOff: new = home
2019-04-03 19:50:53.450009 INFO AlarmOff: appdaemon version: 3.0.2
2019-04-03 19:50:53.452638 INFO AlarmOff: entity = person.XXXX
2019-04-03 19:50:53.454874 INFO AlarmOff: attribute = state
2019-04-03 19:50:53.457109 INFO AlarmOff: old = home
2019-04-03 19:50:53.459496 INFO AlarmOff: new = home
2019-04-03 19:52:02.598946 INFO AlarmOff: appdaemon version: 3.0.2
2019-04-03 19:52:02.601602 INFO AlarmOff: entity = person.XXXX
2019-04-03 19:52:02.604014 INFO AlarmOff: attribute = state
2019-04-03 19:52:02.606542 INFO AlarmOff: old = home
2019-04-03 19:52:02.609069 INFO AlarmOff: new = home
2019-04-03 19:53:15.324774 INFO AlarmOff: appdaemon version: 3.0.2
2019-04-03 19:53:15.327048 INFO AlarmOff: entity = person.XXXX
2019-04-03 19:53:15.329344 INFO AlarmOff: attribute = state
2019-04-03 19:53:15.331526 INFO AlarmOff: old = home
2019-04-03 19:53:15.333622 INFO AlarmOff: new = home
2019-04-03 19:54:29.790176 INFO AlarmOff: appdaemon version: 3.0.2
2019-04-03 19:54:29.792464 INFO AlarmOff: entity = person.XXXX
2019-04-03 19:54:29.794752 INFO AlarmOff: attribute = state
2019-04-03 19:54:29.796874 INFO AlarmOff: old = home
2019-04-03 19:54:29.799251 INFO AlarmOff: new = home
2019-04-03 19:55:50.302093 INFO AlarmOff: appdaemon version: 3.0.2
2019-04-03 19:55:50.304560 INFO AlarmOff: entity = person.XXXX
2019-04-03 19:55:50.309518 INFO AlarmOff: attribute = state
2019-04-03 19:55:50.311979 INFO AlarmOff: old = home
2019-04-03 19:55:50.314231 INFO AlarmOff: new = home
2019-04-03 19:57:03.852409 INFO AlarmOff: appdaemon version: 3.0.2
2019-04-03 19:57:03.857981 INFO AlarmOff: entity = person.XXXX
2019-04-03 19:57:03.863057 INFO AlarmOff: attribute = state
2019-04-03 19:57:03.869587 INFO AlarmOff: old = home

Further details:

AppDaemon version: 3.02
Home Assistant Version: 0.90.2
Hassbian
Person.XXXX is tracked by one device tracker using GPSLogger
The Logbook shows exactly one transition to/from not_home/home when person.XXX arrives or leaves. This has been 100% reliable on this particular phone for several weeks.

The error log is clear.

Things I am questioning:

Based on the AppDaemon documentation I would expect “old” to log something other than home and “new” to log home (a change in state) yet they both show home.
I would expect the callback to run one time when person XXX arrives yet it is obviously running over and over. As you can see these executions are slightly more than 1 minute apart. GPSLogger is set to update location every one minute.

I think I can work around this by calling cancel_listen_state when the callback runs and calling listen_state again when person_XXXX’s state changes to "not_home. However if I am making a mistake I would like to learn what that is and if there is a bug I would like to report it. I would appreciate any input.

MikeA · April 4, 2019, 2:23am

The first thing that comes to mind is, what does self.get_state(“alarm_control_panel.XXXX”) return?

Burningstone · April 4, 2019, 7:48am

I think the problem is that somehow the state gets updated every minute even if it doesn’t change. So new state is ‘home’ and old state is ‘home’. You can just add old=‘not_home’ to the callback listener. Like this:

self.listen_state(self.someone_home, “person.XXXX”, new = “home”, old=“not_home”)

Odianosen25 · April 4, 2019, 8:45am

You right @bg1000,

There is a little bug in there and this will be fixed in the next release.

Regards

Burningstone · April 4, 2019, 9:51am

Where is the bug? In the GPS Logger?

Odianosen25 · April 4, 2019, 10:17am

Not exactly.

The way HA and AD interacts is that, when anything changes in an entity, whether state nor attribute, HA sends the whole data to AD. If an attribute changes and not the state, because one is already listening to the entity’s state change like in the example above, and everything is passed by HA, AD still processes it. One could argue its not exactly a bug on AD’s part, to be honest.

So in the next release, it will be ensured that before the callback is dispatched, AD checks if the state truly changed, and based on that the callback is executed. This has been seen to improve on AD’s internal as it significantly reduced the number of callbacks execution by over 40% from my records.

Regards

Burningstone · April 4, 2019, 11:37am

Ah I understand.

You are right I totally forgot this, I’ve worked around this with the ‘new’ and ‘old’ arguments so many times that I do it automatically now and forgot why I even did it in the first place

Odianosen25 · April 4, 2019, 11:43am

Well that was also my work around for a while, but it sometimes led to thread starvation.

Also if one is working with an entity, that sometimes generated a whole lot of data stream on an attribute, and even if that attribute was not being listened to, it led to serious issues.

So it definitely needed a fix.

Burningstone · April 4, 2019, 11:58am

Yeah I could Imagine that. Luckily this was never an issue for me.
Do you know anything about when the new AD version will be released? I’ve already read the docs and I can’t wait to get my hands on the new version

Odianosen25 · April 4, 2019, 12:28pm

Feel you bro.

Well hoping very soon really, as I can’t tell myself. There is still a couple of works that will need doing first, so that taking a bit of time.

Regards

bg1000 · April 4, 2019, 1:10pm

Thanks Odianosen25 and Burningstone for the confirmation and all the discussion. I should also add I think AppDaemon is very impressive and I really appreciate all the work on it and the fact that you are sharing it.

This should be easy enough to work around for now. I’ll start with the suggested - self.listen_state(self.someone_home, “person.XXXX”, new = “home”, old=“not_home”) as that’s a lot simpler that what I was thinking of doing and see how that works.