pnbruckner / ha-composite-tracker

Home Assistant Composite Device Tracker
The Unlicense
144 stars 11 forks source link

DB contains records with same state #63

Closed ildar170975 closed 5 months ago

ildar170975 commented 8 months ago

Here is a "states" table for one device_tracker entity:

изображение

Look at the "attributes_id" column. Here just 2 entries with different attribute_id:

изображение

изображение

A difference is only in "last_seen" attribute. In this particular example it was a tracker for Apple watch - this device is usually not "visible" & rarely changes it's state. In case of another device there could be LOTS of records in DB.

Is it possible to exclude the last_seen from DB & not store a new record when only this attribute is changed?

pnbruckner commented 8 months ago

I'm curious, if that entity is usually not "visible" (which I'm not entirely sure what you mean), and rarely changes, why are you using it as an input to a composite entity?

For most device_tracker entities that include a last_seen (or similar) attribute (including those created by composite), that attribute only changes when one or more of the "location" attributes (such as latitude, longitude, etc.) are also changing, so there's going to be a new record anyway. Sure, that record will be smaller if the last_seen attribute is not recorded, but how significant is that?

FWIW, this integration was created well before it was possible to filter individual attributes from the DB. It currently does not use that feature at all. (In fact, most of my integrations are old enough that they didn't do this. I've only used it so far on two of them, sun2 & google_maps.)

Anyway, I'll consider adding this feature. Probably several of the attributes shouldn't be recorded. However, I'm not entirely convinced last_seen is one of them. If you want the history of movement, last_seen is just as important as latitude, etc.

ildar170975 commented 8 months ago

I'm curious, if that entity is usually not "visible" (which I'm not entirely sure what you mean), and rarely changes, why are you using it as an input to a composite entity?

Long story... First, I was using ASUSWRT for Apple Watch. But it usually reported not_home. Only sometimes is displayed home. Apple watch connected to the router (ASUS AC68U) for sure: sometimes I switched off Bluetooth on a phone, but Watch was still able to sync mails. So, the problem was about "router does not see Watch".

Then I started using iphonedetect integration. At least it was able to see Watch at home as home, otherwise - not_home.

For a mainly testing purpose I "linked" these 2 integration - ASUSWRT & iphonedetect - inside the Composite.

After some update of ASUS router both integration (ASUSWRT & iphonedetect) stopped seeing Watch at all (although Watch still can sync mails w/o bluetooth via Wifi) - but it is another story...

ildar170975 commented 8 months ago

Here is a code:

composite:
  trackers:
    - name: apple_watch_s4_composite
      entity_id:
        - device_tracker.apple_watch_s4_asuswrt
        - device_tracker.apple_watch_s4_iphonedetect

Here is a History:

изображение

Due to a "brilliant" decision not to display entity_id, it is hard to guess which entities are here. In fact, they are device_tracker.apple_watch_s4_iphonedetect & device_tracker.apple_watch_s4_composite. (the ASUSWRT entity was not created - the router does not see the Watch).

Here is a current state of the composite tracker: изображение

No idea why it says "last seen yesterday". And yet the "states" table contains 47 records: изображение

pnbruckner commented 8 months ago

You might want to read the composite docs more closely, especially the part that talks about watched entities, and the all_states option. If you still have questions after that, let me know.

ildar170975 commented 8 months ago

For most device_tracker entities that include a last_seen (or similar) attribute (including those created by composite), that attribute only changes when one or more of the "location" attributes (such as latitude, longitude, etc.) are also changing, so there's going to be a new record anyway. Sure, that record will be smaller if the last_seen attribute is not recorded, but how significant is that?

Absolutely agree. If coords (+maybe accuracy), state, battery data are changed -> a new record. But is it possible that some integration just reports smth like "still alive" (which may cause an update of "last seen") and no other attributes (stored in composite tracker) are changed?

Anyway, I'll consider adding this feature. Probably several of the attributes shouldn't be recorded. However, I'm not entirely convinced last_seen is one of them. If you want the history of movement, last_seen is just as important as latitude, etc.

Could you specify a way by which we can use this historical attribute in Lovelace?

ildar170975 commented 8 months ago

You might want to read the composite docs more closely, especially the part that talks about watched entities, and the all_states option. If you still have questions after that, let me know.

A composite tracker entity was defined w/o all_states option. It depends on a device_tracker.apple_watch_s4_iphonedetect entity which has these attributes:

изображение

and these records in the "states" table with same state & same attributes (issue):

изображение

So, based on DB see no reason for Composite to update last_seen since no attributes in a monitored tracker changed.

pnbruckner commented 8 months ago

Could you specify a way by which we can use this historical attribute in Lovelace?

That is not the only way historical data can be used.

and these records in the "states" table with same state & same attributes

That's not completely true. last_update_ts is changing. And since this entity does not supply a last_seen attribute, the composite has to fall back and use last_updated. So, the problem is not the composite entity, it's the input entity that is constantly changing, even though it shouldn't be.

ildar170975 commented 8 months ago

That is not the only way historical data can be used.

I would agree. Even there are some custom cards like "custom logbook" which seem to show historical attributes.

So, the problem is not the composite entity, it's the input entity that is constantly changing, even though it shouldn't be.

Do you mean that the "iphonedetect" entity declares itself as "updated" with changed "last_updated" attribute (although it is not in fact) - and this is why the composite tracker reacts the way it creates a new record? Will "all_states: false" help me to avoid it? (until the iphonedetect platform is fixed)

Here is a curr state of "iphonedetect" entity: изображение

A cur state of composite: изображение

I see that "last_seen" corresponds to the "last_updated" of the "iphonedetect" entity. (may be unrelated) But why the composite entity has "last_changed" = yesterday 20:56 (although the state is "away" since 23.02) ?

pnbruckner commented 8 months ago

Do you mean that the "iphonedetect" entity declares itself as "updated" with changed "last_updated" attribute (although it is not in fact) - and this is why the composite tracker reacts the way it creates a new record?

Yes.

Will "all_states: false" help me to avoid it? (until the iphonedetect platform is fixed)

No, that is already the default value of that option. It is using all states because there are no GPS-based inputs, and really no other input either.

I see that "last_seen" corresponds to the "last_updated" of the "iphonedetect" entity. (may be unrelated)

It is directly related.

But why the composite entity has "last_changed" = yesterday 20:56 (although the state is "away" since 23.02) ?

I couldn't say. I'd need to see the complete state history for both for that time period to say. Or maybe did HA restart at one of those times? Did the router entity become unavailable or something? Again, hard to say without knowing the exact state changes of both for that period.

ildar170975 commented 8 months ago

It is directly related.

Hope you understood me properly, these "(may be unrelated)" words were about the "But why the composite entity has "last_changed" = yesterday" sentence.

I'd need to see the complete state history for both for that time period to say. Or maybe did HA restart at one of those times? Did the router entity become unavailable or something? Again, hard to say without knowing the exact state changes of both for that period.

I see. Not sure if it can help you:

  1. The router restarts every 06:00 morning. But I see no changes for this time in History (state is same "not_home") & DB (same "not_home", same attributes - only "last_seen" changes for composite & no changes for that "iphonedetect").
  2. This is a test setup, HA is restarted rather often. And same remark about History & DB as above.

I think I found it: HA was started ~20:55: изображение The last-changed fro Composite is ~20:56: изображение

My expectation was: if the state of composite tracker is not changed (see a History above) - then its "last-changed" should be some old value, not a time of last HA startup.

Could it be related that config is still in yaml? изображение


As for the main issue: Let's wait & see what the author of that "iphonedetect" integration says. I created the issue.

pnbruckner commented 8 months ago

My expectation was: if the state of composite tracker is not changed (see a History above) - then its "last-changed" should be some old value, not a time of last HA startup.

Yours, as well as many others. But, unfortunately, that's now how HA works. The last_changed & last_updated state fields are set by HA core code and is based on when the state is set by an integration. last_changed simply is the last time the state string is changed (e.g., home, not_home, etc.), whereas last_updated is the last time any part of the state (including attributes) is changed. The only thing an integration can change about that is that it can, if it wants, force last_changed to update even if the state string hasn't changed (assuming at least something else about the state has changed.) These fields initially get set when HA (and the integration) starts. Therefore, even if an entity is restored (with its state from before HA restarted), last_changed & last_updated can't be any value earlier than when HA starts.

ildar170975 commented 8 months ago

Therefore, even if an entity is restored (with its state from before HA restarted), last_changed & last_updated can't be any value earlier than when HA starts.

I see, like some other entities in HA (helpers). So this part of the issue is "closed" (at least we have an explanation).

As for the initial issue: Let's wait for any feedback from that "iphonedetect" integration. Currently this integration causes the Composite tracker to update w/o need (and spam into DB as a result).

pnbruckner commented 8 months ago

I took a look at the iphonedetect integration and the issue you raised there. That integration is pretty old and fairly simple. Reading through that code, and the associated device_tracker component level code, I'm not seeing how it would create state_changed events, and additional records in the DB, when its state remains not_home. Are you sure you're reading the DB tables correctly?

What would help is if you could enable debug for homeassistant.core. Then, whenever any entity in the system changes, and a state_changed event is fired, there would be a record of it. Then you could search for all those messages that are related to device_tracker.apple_watch_s4_iphonedetect & device_tracker.apple_watch_s4_composite, and that would help conclusive determine what's really happening in your system.

Please add the following to your configuration.yaml file:

logger:
  logs:
    homeassistant.core: debug

Then restart HA. When you believe there have been unnecessary DB records created for these entities, search home-assistant.log in the same folder as configuration.yaml. If you can get to a command line and know how to use grep, you might try something like:

grep home-assistant.log -e "new_state=<state device_tracker\.apple_watch_s4_iphonedetect" -e "new_state=<state device_tracker\.apple_watch_s4_composite"

Then share that output here.

If you're not familiar with how to do this from a command line, you could always go to Settings -> System -> Logs, then enter new_state=<state device_tracker.apple_watch_s4 in the "Search logs" box, then click LOAD FULL LOGS.

pnbruckner commented 8 months ago

BTW, I'm also curious, do you still use the asuswrt integration? If so, it apparently adds a last_time_reached attribute. That seems like another perfect input to the composite integration (rather than falling back on the last_updated state field.)

ildar170975 commented 8 months ago

BTW, I'm also curious, do you still use the asuswrt integration?

I use ASUSWRT, but for some devices (like Mikrotik switches) is shows not_home rather often - even when a ping sensor (manually updated every 1 minute) shows on (i.e. home). Also, ASUSWRT (as long as I remember) tend to show not_home for that Apple Watch; very rarely it was home. I am experimenting with different platforms - ASUSWRT, iphonedetect, traccar, life3690 (R.I.P.), companion.

I will answer your long post a bit later. Thanks a LOT for supporting!

ildar170975 commented 8 months ago

Are you sure you're reading the DB tables correctly?

First I must apologize - we have started sorting out issues caused by ANOTHER integration. But since the integration providing input data for the Composite platform - then may be there is a way to create a some kind of "safety block" to avoid frequent changes caused by any "input" integration?

Here is how I found out the problem:

  1. Open DB file (stored in HA config folder visible from Win-machine) in DB Browser for SQLite.

  2. Go to states_meta table. Filter the table by our monitored entity_id & find metadata_id: image

  3. Go to states table. Filter the table by this metadata_id: image

  4. We have now all records for the entity. We can see a lot of records with same attributes (attributes_id): image

  5. Select some part of the table by a mouse & copy/paste to Excel. Add a column to convert timestamps to a datetime: image

Yellow = records with same state & attributes. Let's check what happened 23.02 - here is a HA uptime graph: image

So, within one run of HA (~02:20 ... ~17:30) we still have some number of repeating records.

Conclusion: the integration iphonedetect updates it's last_updated attribute even when a state & attributes do not change. This causes updating the Composite entity as well.

From one side = it is good: I see that the entity has a recent last-updated. Means - the data are RECENT, the integration is not "sleeping". From another side - every update is writing smth to DB.

Is it possible to see an updated last-updated value in a "state machine" - but w/o writing all these SAME records into DB?

ildar170975 commented 8 months ago

What would help is if you could enable debug for homeassistant.core

I will do it a bit later.

pnbruckner commented 8 months ago

FWIW, I have a Python script that can extract info from HA's database. It broke a while ago when the schema changed, but I just updated it. It should be good for HA versions 2023.4 and later. Anyway, it looks kind of like this:

$ hadb.py -d test/config/home-assistant_v2.db -s device_tracker.phil last_seen -cA -S 09:00:00 -E 09:30:00
Schema version: 42
Showing from 2024-02-28 09:00:00 to 2024-02-28 09:30:00
     entity_id / event_type     | last_updated / time_fired  | state | attributes
--------------------------------|----------------------------|-------|-----------------------------------------------------------------------------------------------------------------------
device_tracker.phil             | 2024-02-28 08:57:38.269220 | home  | last_seen=2024-02-28T08:56:39-06:00
--------------------------------|----------------------------|-------|-----------------------------------------------------------------------------------------------------------------------
device_tracker.phil             | 2024-02-28 09:00:38.626000 | home  | last_seen=2024-02-28T09:00:13-06:00
                                | 2024-02-28 09:01:38.525860 | home  | last_seen=2024-02-28T09:01:30-06:00
                                | 2024-02-28 09:03:39.088350 | home  | last_seen=2024-02-28T09:03:11-06:00
                                | 2024-02-28 09:06:38.660960 | home  | last_seen=2024-02-28T09:06:00-06:00
                                | 2024-02-28 09:07:38.653720 | home  | last_seen=2024-02-28T09:07:24-06:00
                                | 2024-02-28 09:09:38.637050 | home  | last_seen=2024-02-28T09:08:57-06:00
                                | 2024-02-28 09:11:38.835490 | home  | last_seen=2024-02-28T09:11:02-06:00
                                | 2024-02-28 09:12:38.858310 | home  | last_seen=2024-02-28T09:12:22-06:00
###### homeassistant_stop ##### | 2024-02-28 09:13:38.094450 |
== homeassistant_final_write == | 2024-02-28 09:13:38.350430 |
device_tracker.phil             | 2024-02-28 09:13:50.476130 | home  | last_seen=2024-02-28T09:12:22-06:00
===== core_config_updated ===== | 2024-02-28 09:14:22.604160 |
===== homeassistant_start ===== | 2024-02-28 09:14:22.604320 |
===== core_config_updated ===== | 2024-02-28 09:14:22.621800 |
==== homeassistant_started ==== | 2024-02-28 09:14:22.623910 |
###### homeassistant_stop ##### | 2024-02-28 09:14:41.826620 |
== homeassistant_final_write == | 2024-02-28 09:14:42.091500 |
device_tracker.phil             | 2024-02-28 09:14:51.194080 | home  | last_seen=2024-02-28T09:14:24-06:00
===== core_config_updated ===== | 2024-02-28 09:14:51.326860 |
===== homeassistant_start ===== | 2024-02-28 09:14:51.327020 |
===== core_config_updated ===== | 2024-02-28 09:14:51.339300 |
==== homeassistant_started ==== | 2024-02-28 09:14:51.339460 |
device_tracker.phil             | 2024-02-28 09:17:51.070410 | home  | last_seen=2024-02-28T09:17:07-06:00
                                | 2024-02-28 09:18:50.874920 | home  | last_seen=2024-02-28T09:18:28-06:00
                                | 2024-02-28 09:20:50.669730 | home  | last_seen=2024-02-28T09:20:08-06:00
                                | 2024-02-28 09:22:50.824030 | home  | last_seen=2024-02-28T09:22:26-06:00
                                | 2024-02-28 09:23:50.764130 | home  | last_seen=2024-02-28T09:23:35-06:00
                                | 2024-02-28 09:25:51.015430 | home  | last_seen=2024-02-28T09:25:05-06:00
                                | 2024-02-28 09:27:50.536970 | home  | last_seen=2024-02-28T09:27:30-06:00
                                | 2024-02-28 09:28:50.579820 | home  | last_seen=2024-02-28T09:28:41-06:00

You can specify which entity_id's you want to see, and optionally you can specify which attributes you want to see, and you can see events. All of those can optionally use regular expressions. You also have flexible control as to what time window you want to see. And the output is colorized to make it easier to browse over.

If you're interested at all in this script, let me know and I can get it to you and explain how to install and use it.

pnbruckner commented 8 months ago

It looks like the data you got from the database is relevant, but it's not really sorted, and it doesn't show if/when HA restarted in that sequence. Getting the DEBUG state_changed events from the log, or using my script, either way would help to fully understand what is happening with that entity, and how that impacts the composite entity that uses its state.

ildar170975 commented 8 months ago

If you're interested at all in this script, let me know and I can get it to you and explain how to install and use it.

It's very kind of you! I do not know sql, have to analyse tables in my primitive way. I will try to check it later when will be less busy, thank you!

t looks like the data you got from the database is relevant, but it's not really sorted

Check the "last-changed" column (or added datetime) - it is sorted by a date. In fact, they are sorted by the 1st state_id column.

Getting the DEBUG state_changed events from the log, or using my script, either way would help to fully understand what is happening with that entity, and how that impacts the composite entity that uses its state.

Will try to prepare info soon.

pnbruckner commented 8 months ago

Ok, I see that now. It is indeed sorted by time (and, of course, state_id, which is effectively is the same thing for sorting this data.)

Whenever you can, no rush. As you say, at this point we're really trying to better understand the iphonedetect entity first.

pnbruckner commented 8 months ago

After looking at the iphonedetect code I realized it might work with my Android phone, too. So, I installed it on my test system and configured it to check my Android phone.

Sure enough, it found it, and created a device_tracker entity whose state was home. I let it run a while, then turned off my phone's WiFi. Via DEBUG messages I could see the next time it checked the phone, it noticed it no longer responded. Then, after the configured consider_home period, the device_tracker changed to not_home.

I checked the log and used my script that extracts state info about entities, and both showed the iphonedetect device_tracker entity behaved as I expected. I.e., it did not create state_changed events constantly. It only created them when it first changed to home, and when it later changed to not_home.

Next, I added a composite entity whose only input is the iphonedetect device_tracker. It, too, behaved as I expected. I.e., it only created state_changed events, and DB entries, when it changed state based on the iphonedetect entity changing state. It did not create multiple entries with the same state except for last_seen.

So, I could not reproduce what you're observing.

pnbruckner commented 8 months ago

And, FWIW, a direct query of the DB:

sqlite> select state_id, m.entity_id, state, last_updated_ts, shared_attrs from states as s inner join states_meta as m on s.metadata_id = m.metadata_id inner join state_attributes as a on s.attributes_id = a.attributes_id where m.entity_id = "device_tracker.ping_phil" or m.entity_id = "device_tracker.phil_iphonedetect_test" order by state_id;
state_id|entity_id|state|last_updated_ts|shared_attrs
735856|device_tracker.ping_phil|home|1709169569.24975|{"source_type":"router","ip":"<IP_ADDR>","friendly_name":"ping_phil"}
736159|device_tracker.ping_phil|not_home|1709169740.17445|{"source_type":"router","ip":"<IP_ADDR>","friendly_name":"ping_phil"}
736439|device_tracker.phil_iphonedetect_test|not_home|1709170509.4819|{"source_type":"router","entities":["device_tracker.ping_phil"],"last_entity_id":"device_tracker.ping_phil","last_seen":"2024-02-28T19:22:20-06:00","friendly_name":"Phil iphonedetect Test"}
736466|device_tracker.ping_phil|home|1709170566.05488|{"source_type":"router","ip":"<IP_ADDR>","friendly_name":"ping_phil"}
736467|device_tracker.phil_iphonedetect_test|home|1709170566.06026|{"source_type":"gps","latitude":41.5593425366867,"longitude":-88.20533931255342,"gps_accuracy":0,"entities":["device_tracker.ping_phil"],"last_entity_id":"device_tracker.ping_phil","last_seen":"2024-02-28T19:36:06-06:00","friendly_name":"Phil iphonedetect Test"}
736522|device_tracker.ping_phil|not_home|1709170700.17444|{"source_type":"router","ip":"<IP_ADDR>","friendly_name":"ping_phil"}
736523|device_tracker.phil_iphonedetect_test|not_home|1709170700.17992|{"source_type":"router","entities":["device_tracker.ping_phil"],"last_entity_id":"device_tracker.ping_phil","last_seen":"2024-02-28T19:38:20-06:00","friendly_name":"Phil iphonedetect Test"}

device_tracker.ping_phil is the iphonedetect entity, and device_tracker.phil_iphonedetect_test is the composite entity.

ildar170975 commented 8 months ago

Interesting. Could it be related to a router?

But anyway. Assume this is not iphonedetect but some xxxdetect. It creates records with "home/not_home" & some attributes. Assume this integration updates itself (changing 'last_updated') w/o changing a state & attributes. Example - Starline car integration creates device_tracker entity. And - surprise! - it may be "updated" w/o changing a state / attributes - issue. Same. And assume that Composite somehow filters these "updates w/o changes" - and do NOT update itself. Or - which is much better, does update itself - but do not write SAME record into DB.

As I said earlier, this is a dilemma:

  1. If some device_tracker has a new last_updated - means "it works", and it does not matter that it's state/attrs are same.
  2. From other side, no need to write same records into DB.

I do not think that currently it is possible to "skip a write to DB" if an object is updated (here - last_updated is updated). So probably I will have to accept the current status.

pnbruckner commented 8 months ago

Interesting. Could it be related to a router?

I doubt it. The integration is directly sending UDP packets to the phone. I doubt the switch function of the router would have any effect on that.

But anyway. Assume this is not iphonedetect but some xxxdetect. It creates records with "home/not_home" & some attributes. Assume this integration updates itself (changing 'last_updated') w/o changing a state & attributes.

That is possible, but unlikely. An integration can force an update (where both last_updated & last_changed are updated), even if the state & attributes do not change, but most do not. I checked iphonedetect and it does not. I browsed the starline issue & code and I don't see where it does it either.

I think the issue here is that you're seeing updates from different runs of HA, i.e., across restarts. When HA & integrations start, they will fire state_changed events for all the entity objects that are created, which will result in DB records. If those integrations restore state, then likely the state & attributes will be the same. If you look closely to the records you circled above, you'll see the values in the old_state_id column for those records are all NULL. This means all these records happened when the entity object was created, either when HA starts, or when the integration is reloaded.

Bottom line, I think your interpretation of the DB records is incorrect. What would help, as I've said before, is messages from the log and/or using my hadb.py script to pull out not only the records associated with state changes, but also events that show when HA restarts.

ildar170975 commented 8 months ago

I think the issue here is that you're seeing updates from different runs of HA, i.e., across restarts.

Absolutely not. As I described you - I took "last_updated" values, converted them to local time - these moments are within one HA run.

When HA & integrations start, they will fire state_changed events for all the entity objects that are created, which will result in DB records

Yes, as you explained it here - https://github.com/pnbruckner/ha-composite-tracker/issues/63#issuecomment-1966729455

If you look closely to the records you circled above, you'll see the values in the old_state_id column for those records are all NULL. This means all these records happened when the entity object was created, either when HA starts, or when the integration is reloaded.

Interesting. I will look closer.

Bottom line, I think your interpretation of the DB records is incorrect. What would help, as I've said before, is messages from the log and/or using my hadb.py script to pull out not only the records associated with state changes, but also events that show when HA restarts.

OK, I will do it! Thanks again!

pnbruckner commented 8 months ago

@ildar170975, can you provide an update?

ildar170975 commented 8 months ago

Hi! Not yet... Was very far from a PC, just came back. Will try to give smth these days, thanks for not forgetting!!!

pnbruckner commented 5 months ago

Closing since there has not been an update for a couple of months. Also, I don't believe this integration is doing anything wrong here. Feel free to reopen with new data/info.

ildar170975 commented 5 months ago

Was not able to add any updates since was rather far from a home PC. Will try to test the issue when will be back.