Strange behaviour for CGPR1 sensor's `last_changed`

[andrey-yantsen]

Hey! First of all, the integration is awesome! Thank you so much for creating it and for the continuous development!

Now the strange part: I have a bunch of motions sensors made by Qingping — CGPR1, and last_changed attribute behaves pretty strange: it gets updated even when the current status is the same as the old one, while according to the documentation it should be updated only when the state itself is changed. Feel free to yell at me, if it's actually a home-assistant bug.

I'm on version 5.2.1 of the integration, and hass v2021.9.6.

I'm using the following automation to collect some debug logs, that you could see later in the issue description:

alias: Motion debug
description: ''
trigger:
  - platform: state
    entity_id: binary_sensor.ble_motion_motion_sensor_bathroom
# plus a few more motion sensors here
condition: []
action:
  - service: system_log.write
    data:
      level: warning
      logger: motion_debug
      message: >-
        {{ trigger.entity_id }}: state: {{ trigger.from_state.state }} => {{
        trigger.to_state.state }}; last_changed: {{
        trigger.from_state.last_changed }} => {{ trigger.to_state.last_changed
        }}; last_motion: {{ trigger.from_state.attributes['last motion'] }} =>
        {{ trigger.to_state.attributes['last motion'] }}; last_packet_id: {{
        trigger.from_state.attributes['last packet id'] }} => {{
        trigger.to_state.attributes['last packet id'] }}
mode: queued
max: 1000

Here're the records from the log I have questions for:

2021-09-14 14:35:22 WARNING (MainThread) [motion_debug] binary_sensor.ble_motion_motion_sensor_bathroom: state: off => off; last_changed: 2021-09-14 14:32:48.764656+00:00 => 2021-09-14 14:35:22.693553+00:00; last_motion: 2021-09-14 15:30:40.812255+01:00 => 2021-09-14 15:30:40.812255+01:00; last_packet_id: 63 => 63
2021-09-14 14:35:40 WARNING (MainThread) [motion_debug] binary_sensor.ble_motion_motion_sensor_lounge_kitchen: state: on => on; last_changed: 2021-09-14 14:35:38.942077+00:00 => 2021-09-14 14:35:40.488394+00:00; last_motion: 2021-09-14 15:35:38.941471+01:00 => 2021-09-14 15:35:38.941471+01:00; last_packet_id: 147 => 148
2021-09-14 14:35:46 WARNING (MainThread) [motion_debug] binary_sensor.ble_motion_motion_sensor_bathroom: state: off => off; last_changed: 2021-09-14 14:35:22.693553+00:00 => 2021-09-14 14:35:46.960364+00:00; last_motion: 2021-09-14 15:30:40.812255+01:00 => 2021-09-14 15:30:40.812255+01:00; last_packet_id: 63 => 68
2021-09-14 14:36:09 WARNING (MainThread) [motion_debug] binary_sensor.ble_motion_motion_sensor_corridor_entrance: state: off => off; last_changed: 2021-09-14 14:33:48.058008+00:00 => 2021-09-14 14:36:09.222853+00:00; last_motion: 2021-09-14 15:31:11.299890+01:00 => 2021-09-14 15:31:11.299890+01:00; last_packet_id: 136 => 141

The issue prevents me from having automation like "turn off the lights if there's no motion for 1 minute" because sensors are being "randomly changed". Any feedback will be appreciated.

P.S. Valid changes are also being caught by the log, e.g.:

2021-09-14 14:35:38 WARNING (MainThread) [motion_debug] binary_sensor.ble_motion_motion_sensor_lounge_kitchen: state: off => on; last_changed: 2021-09-14 14:33:43.950028+00:00 => 2021-09-14 14:35:38.942077+00:00; last_motion: 2021-09-14 15:31:43.489968+01:00 => 2021-09-14 15:35:38.941471+01:00; last_packet_id: 145 => 147
2021-09-14 14:36:13 WARNING (MainThread) [motion_debug] binary_sensor.ble_motion_motion_sensor_lounge_kitchen: state: on => off; last_changed: 2021-09-14 14:35:40.488394+00:00 => 2021-09-14 14:36:13.943774+00:00; last_motion: 2021-09-14 15:35:38.941471+01:00 => 2021-09-14 15:35:38.941471+01:00; last_packet_id: 148 => 148
2021-09-14 14:39:40 WARNING (MainThread) [motion_debug] binary_sensor.ble_motion_motion_sensor_bathroom: state: off => on; last_changed: 2021-09-14 14:38:16.010539+00:00 => 2021-09-14 14:39:40.022209+00:00; last_motion: 2021-09-14 15:30:40.812255+01:00 => 2021-09-14 15:39:40.021577+01:00; last_packet_id: 68 => 72
2021-09-14 14:39:43 WARNING (MainThread) [motion_debug] binary_sensor.ble_motion_motion_sensor_corridor_bedroom: state: off => on; last_changed: 2021-09-14 14:36:10.585040+00:00 => 2021-09-14 14:39:43.296518+00:00; last_motion: 2021-09-14 15:31:07.245838+01:00 => 2021-09-14 15:39:43.295377+01:00; last_packet_id: 213 => 215
2021-09-14 14:39:43 WARNING (MainThread) [motion_debug] binary_sensor.ble_motion_motion_sensor_corridor_entrance: state: off => on; last_changed: 2021-09-14 14:36:09.222853+00:00 => 2021-09-14 14:39:43.944760+00:00; last_motion: 2021-09-14 15:31:11.299890+01:00 => 2021-09-14 15:39:43.944023+01:00; last_packet_id: 141 => 143

[Ernst79]

I'm not sure I follow you. Where did you find this last_changed attribute. If I look at the attributes, I only see the last_motion attribute?

Anyway, why don't you use the last_motion attribute for your automation in stead of last_changed?

[andrey-yantsen]

@Ernst79 my bad, sorry — I'm not talking about attribute, it's a property of the HASS' State object.

To be honest, I have high doubts that it's the integration's issue, but those 8 motion sensors are the only place where I can see the problem with last_changed.

[andrey-yantsen]

Anyway, why don't you use the last_motion attribute for your automation in stead of last_changed?

Because I basically need the opposite — I need to know when the sensor stopped detecting any motion.

[Ernst79]

But the time of last motion is the last time it detected motion. Most sensors go to cleared after x seconds, where x is the time you have set in the options (with reset timer). So, doesn't that mean you can just do stopped detection motion = last motion + x seconds? (I'm probably thinking too simple, so don't hesitate to tell me where my thoughts go wrong.

Do you know if it is easily possible to see this last_changed attribute. I think the only way is an attribute sensor, I guess.

[andrey-yantsen]

But the time of last motion is the last time it detected motion. Most sensors go to cleared after x seconds, where x is the time you have set in the options (with reset timer). So, doesn't that mean you can just do stopped detection motion = last motion + x seconds? (I'm probably thinking too simple, so don't hesitate to tell me where my thoughts go wrong.

Hm, yeah, that will do, thanks! It will be a bit more complicated than just adding a condition for something like "off for 5 minutes", but it's doable.

Do you know if it is easily possible to see this last_changed attribute. I think the only way is an attribute sensor, I guess.

Not sure what do you mean exactly, sorry. You can get the last_changed using a template {{ states.<sensor>.last_changed }}.

[Ernst79]

Don't you need to use last_updated. The docs say that last_updated isn't changing its timestamp if the state doesn't change.

state.last_updated: Time the state was written to the state machine in UTC time. Note that writing the exact same state including attributes will not result in this field being updated.

The definition of last_changed is

state.last_changed: Time the state changed in the state machine in UTC time. This is not updated when there are only updated attributes.

So, I think last_changed does update when the same state is written

In your case, you will need last_updated, isn't it? I have to say that the naming seems to be a bit misleading, you would expect the opposite naming.

[andrey-yantsen]

Hm, interesting! I don't think last_updated will work here, because attributes are changing (e.g. the last packet id). But let me add it to my creepy debug log and see it in action. Thanks for checking.

[andrey-yantsen]

Well, that didn't work out — last_updated is being updated as well.

Is it at all possible to not send state updates for the same state?

[Ernst79]

Ah, I think the force_update = True is causing this, see https://developers.home-assistant.io/docs/core/entity/#advanced-properties. This setting is forcing an update on each update, even if the state is the same.

try changing it to False here

https://github.com/custom-components/ble_monitor/blob/aa8ac60d6d18f60b54b66339811f74bd36d2981b/custom_components/ble_monitor/binary_sensor.py#L231

[andrey-yantsen]

@Ernst79 yes, thank you! This helped, now last_changed is not being updated without state changes.

[Ernst79]

Ok, great. I have to do some serious thinking if it is ok to change this for all (binary) sensors. After that thinking, I will update this change (or not).

[andrey-yantsen]

I'll stick with the patched version for now. Thanks again for bearing with me :)

[Ernst79]

Just thinking. We have the following binary sensors. I think part of them needs to update when it gets the same state (like remotes, switches). Most others don't, I guess.

remote single press --> update on same state remote long press --> update on same state switch --> update on same state opening --> no update on same state light --> no update on same state moisture (wet/dry) --> no update on same state motion --> no update on same state weight removed --> no update on same state smoke detector --> no update on same state fingerprint --> update on same state lock --> update on same state toothbrush --> no update on same state

@Magalex2x14 @andrey-yantsen Does this seem right to you? It's easy to make it different for each type, that's not the issue. We can define it in the BinarySensorEntityDescription.

[andrey-yantsen]

I'm down with the proposal. But I would've added a configuration parameter, so users could configure individual sensors if (somehow) they will require different behaviour. Of course, if it does not complicate things (I'm not familiar with the codebase/HASS API).

[Ernst79]

I was working on implementing a config option to choose between True and False for force_update, but the issue is that a device can have multiple sensors, like light, motion, battery, etc. We would have to make a setting for each individual sensor per device, which is making it too complicated. I think I stick to fixed values, as described in my previous post.

[Ernst79]

Fixed in 5.4.0.

[andrey-yantsen]

Awesome, thank you!