Mi Aquara Door Sensor - Missed updates when contact toggled quickly

[dasrue]

Bug Report

I have been testing some of these sensors using the front door of my office. I found that this door does a little bounce when you close it, and this causes the sensor to trigger twice quickly when the door gets closed. This second message gets missed, and zigbee2mqtt reports that the door is open all the time. I have attached the debug logs, and it looks like the information is being picked up by zigbee-shepard but being missed by zigbee2mqtt.

See log here:
https://gist.github.com/dasrue/97771acf2089cdb8da364000b60291b7

Debug Info

zigbee2mqtt version 1.3.1 (commit #39d6a8e)
CC253X firmware version: CC2531ZNP-Prod_20190223

[Koenkk]

Sorry for the delays, I cannot reproduce this, it seems that the events are also captured by zigbee2mqtt. (zigbee2mqtt:debug 5/9/2019, 8:08:22 AM Received zigbee message of type 'attReport' with data).

Can you share your configuration.yaml?

[dasrue]

Here is my configuration.yaml file. The debounce was me trying to figure out this issue, but it doesn't seem to have any effect.

permit_join: true
mqtt:
  base_topic: zigbee2mqtt
  server: 'mqtt://localhost'
  user: test
  password: test123
serial:
  port: COM31
devices:
  '0x00158d00033aaced':
    friendly_name: '0x00158d00033aaced'
    retain: true
    debounce: 0
  '0x00158d00032b763a':
    friendly_name: 'officeDoor'
    retain: true
    debounce: 0```

[Koenkk]

So without debounce you have the same issue?

If so, could you add to https://github.com/Koenkk/zigbee2mqtt/blob/master/lib/extension/deviceReceive.js#L40

console.log(`\n\nDevice ${device ? device.ieeeAddr : ''});

[dasrue]

The issue still exists without debounce, and I just double checked it. Here is the log with that line added
I must not have done a full debug last time because this one has more messages, so hopefully that will be more help.
https://gist.github.com/dasrue/4b552e37b1581ca2685eb881d23e6734

[Koenkk]

In this log I don't see the problem.

• After every Received zigbee message of type 'attReport' there is a MQTT publish
• Note that the devChange is not published to MQTT because it always succeeds after a attReport (to avoid duplicate messages)

[dasrue]

On line 68 there is an attReport with the "onOff":0 parameter, which from what I can tell looking at the logs is the inverse of the current status, so it should report contact status true to MQTT but that last one seems to get skipped for whatever reason. As far as I can tell this is what the problem is, but it could also be related to the last attReport which seems to have some weird data in it.

[Koenkk]

Good catch, the last attReport probably causes the problem!

Can you change https://github.com/Koenkk/zigbee-shepherd-converters/blob/master/converters/fromZigbee.js#L650 to

if (msg.data.data.hasOwnProperty('65281') && msg.data.data['65281'].hasOwnProperty('100')) {

[dasrue]

Ok I have tried that this morning. It seems to be better so far but I will have to do a bit more testing throughout the day. I had a thought that the strange message might be something xiaomi added into the sensor so that just in case the fast toggling gets missed by their gateway, that extra message gets sent afterwards to make sure the gateway has the proper status.

[dasrue]

I have been testing it today, and found that filtering out those messages has made it a lot more reliable, but it still isn't 100% perfect at picking up the quick toggles. It seems like this time the issue isn't zigbee2mqtt missing packets, it looks like in some situations the sensor won't send the genOnOff command for restoring to normal if the contact is toggled quickly enough. However it seems to prefer to send the genBasic command after a short period of time. After some testing I have been able to get genBasic commands for both states, and found that the parameter that differs is "4", looks like it is 5032 for true, and 17320 for false. Converting the numbers to hex it comes out as 0x13A8 and 0x43A8, so it looks as if some bits change based on the contact status but other remain constant. Not really sure what to make of this, is it possible to add in decoding for these packets?

[Koenkk]

@dasrue the genBasic messages are in a proprietary format, meaning we don't know what the values mean/decode. You can experiment by changing the converter and check if it behaves as expected.

[Ton1965]

It looks like I have the same issue. Sometimes my door sensor in HA stays open even when the door itself is closed.
I have a rather heavy metal door and sometimes it is necessary to push it twice to make it close. It looks like some messages get lost in the process and the sensor state does not change to closed. This error is not constant for me and happens once in probably twenty door operations.
For a long time I attributed this to the sensor itself since the larger part of the sensor is located on the door while xiaomi advises to put it on the unmovable surface. So I thought that the sensor electronics sometimes got too 'shocked' when the door was shut. Recently I added another sensor to the same door so now there are two of them. Just today both showed the door staying open although in reality it is closed. I doubt two sensors might have the some problem with internals at the same time (especially taking into account that sensors are slightly different, one is Mija and the other Aqara).
I do not have any logs since usually my whole zigbee network is ok and z2m is configured with debug level = warning.
I will try to make the code change suggested by @Koenkk above and see if it makes any difference. Unfortunately the problem is intermittent so it might take time to gain some confidence in the result.

[Ton1965]

The code change above did not bring any difference. Yesterday again both sensors stayed in open state. Still Aqara device sent state update to closed together with next alive message in about an hour, so internally the sensor knew it is closed but for some reason this information did not make it to HA. Mija device is still open since door has not been opened yet.
Will do further investigation.

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[dasrue]

After more testing, I think doing the code change mentioned above on the zigbee-shepard converters is worth pulling. I have not been able to make any sense of the genBasic messages so I think that would be the best we can do.

[Koenkk]

@dasrue thanks for reporting back, added it, assumed this can be closed know.