Door/Window sensor changing state for no reason - faulty device?

Configuration Z-Wave
1

Last night my door sensor changed state from “false” to “true” for no reason apparently (the door was closed). I am running HA 69.1 on a PI3 with an Aeon Labs Gen5 USB stick. The door sensor I have is an Aeotec ZW120 Door Window Sensor Gen5.

I would reallu appreciate if someone would be able to provide some input or any idea as to why this could happen, and/or how I might prevent it from happening again. This could potentially trigger a false alarm while we’re all sleeping, something which would really not make the wife or the kids happy :wink:

At the same time as the state changed, I was editing some config files on the PI via SAMBA, when my editor seemed to hang for a couple of seconds with no response. When it came back alive, the device reported “door opened”. I don’t know if the fact that the PI became unresponsive for a few seconds has to do with a false positive state report from the Z-wave sensor.

By looking at the Z-wave log, I can see that the device reports four almost simultaneous “true” reports. Could this be a sign of a faulty device? I am also thinking that perhaps a factory reset would be worth a try.

Here is the HA log from the time it happened (at about 22:49:26)

2018-05-19 22:48:34 WARNING (MainThread) [homeassistant.components.sensor] Updating hue sensor took longer than the scheduled update interval 0:00:00.500000
2018-05-19 22:49:26 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-19 22:49:27 WARNING (MainThread) [homeassistant.components.sensor] Updating netatmo sensor took longer than the scheduled update interval 0:00:30
2018-05-19 22:49:27 WARNING (MainThread) [homeassistant.components.sensor] Updating hue sensor took longer than the scheduled update interval 0:00:00.500000
2018-05-19 22:49:28 WARNING (MainThread) [homeassistant.components.sensor] Updating hue sensor took longer than the scheduled update interval 0:00:00.500000
2018-05-19 22:49:28 WARNING (MainThread) [homeassistant.components.sensor] Updating hue sensor took longer than the scheduled update interval 0:00:00.500000
2018-05-19 22:49:36 ERROR (SyncWorker_1) [homeassistant.core] Error doing job: Task was destroyed but it is pending!
2018-05-19 22:49:37 ERROR (SyncWorker_1) [homeassistant.core] Error doing job: Task was destroyed but it is pending!
2018-05-19 22:49:37 ERROR (SyncWorker_1) [homeassistant.core] Error doing job: Task was destroyed but it is pending!
2018-05-19 22:49:37 ERROR (SyncWorker_1) [homeassistant.core] Error doing job: Task was destroyed but it is pending!
2018-05-19 22:52:02 WARNING (MainThread) [homeassistant.components.sensor] Updating hue sensor took longer than the scheduled update interval 0:00:00.500000

And here is the corresponding Z-wave log (The door sensor is Node012)

2018-05-19 22:48:33.077 Detail, Node012, Received: 0x01, 0x09, 0x00, 0x04, 0x00, 0x0c, 0x03, 0x20, 0x01, 0xff, 0x23
2018-05-19 22:49:26.229 Detail,
2018-05-19 22:49:26.229 Info, Node012, Received Basic set from node 12: level=255. Treating it as a Basic report.
2018-05-19 22:49:26.229 Detail, Node012, Refreshed Value: old value=0, new value=255, type=byte
2018-05-19 22:49:26.229 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.229 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:26.269 Detail, Node012, Received: 0x01, 0x09, 0x00, 0x04, 0x00, 0x0c, 0x03, 0x20, 0x01, 0xff, 0x23
2018-05-19 22:49:26.270 Detail,
2018-05-19 22:49:26.270 Info, Node012, Received Basic set from node 12: level=255. Treating it as a Basic report.
2018-05-19 22:49:26.270 Detail, Node012, Refreshed Value: old value=255, new value=255, type=byte
2018-05-19 22:49:26.270 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.270 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:26.309 Detail, Node012, Received: 0x01, 0x09, 0x00, 0x04, 0x00, 0x0c, 0x03, 0x20, 0x01, 0xff, 0x23
2018-05-19 22:49:26.309 Detail,
2018-05-19 22:49:26.309 Info, Node012, Received Basic set from node 12: level=255. Treating it as a Basic report.
2018-05-19 22:49:26.310 Detail, Node012, Refreshed Value: old value=255, new value=255, type=byte
2018-05-19 22:49:26.310 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.310 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:26.348 Detail, Node012, Received: 0x01, 0x09, 0x00, 0x04, 0x00, 0x0c, 0x03, 0x20, 0x01, 0xff, 0x23
2018-05-19 22:49:26.349 Detail,
2018-05-19 22:49:26.349 Info, Node012, Received Basic set from node 12: level=255. Treating it as a Basic report.
2018-05-19 22:49:26.349 Detail, Node012, Refreshed Value: old value=255, new value=255, type=byte
2018-05-19 22:49:26.349 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.349 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:26.397 Detail, Node012, Received: 0x01, 0x09, 0x00, 0x04, 0x00, 0x0c, 0x03, 0x30, 0x03, 0xff, 0x31
2018-05-19 22:49:26.397 Detail,
2018-05-19 22:49:26.397 Info, Node012, Received SensorBinary report: Sensor:49 State=On
2018-05-19 22:49:26.397 Detail, Node012, Refreshed Value: old value=false, new value=true, type=bool
2018-05-19 22:49:26.397 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.397 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:26.439 Detail, Node012, Received: 0x01, 0x09, 0x00, 0x04, 0x00, 0x0c, 0x03, 0x30, 0x03, 0xff, 0x31
2018-05-19 22:49:26.439 Detail,
2018-05-19 22:49:26.439 Info, Node012, Received SensorBinary report: Sensor:49 State=On
2018-05-19 22:49:26.439 Detail, Node012, Refreshed Value: old value=true, new value=true, type=bool
2018-05-19 22:49:26.439 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.439 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:26.485 Detail, Node012, Received: 0x01, 0x09, 0x00, 0x04, 0x00, 0x0c, 0x03, 0x30, 0x03, 0xff, 0x31
2018-05-19 22:49:26.485 Detail,
2018-05-19 22:49:26.485 Info, Node012, Received SensorBinary report: Sensor:49 State=On
2018-05-19 22:49:26.485 Detail, Node012, Refreshed Value: old value=true, new value=true, type=bool
2018-05-19 22:49:26.485 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.486 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:26.525 Detail, Node012, Received: 0x01, 0x09, 0x00, 0x04, 0x00, 0x0c, 0x03, 0x30, 0x03, 0xff, 0x31
2018-05-19 22:49:26.526 Detail,
2018-05-19 22:49:26.526 Info, Node012, Received SensorBinary report: Sensor:49 State=On
2018-05-19 22:49:26.526 Detail, Node012, Refreshed Value: old value=true, new value=true, type=bool
2018-05-19 22:49:26.526 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.526 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:26.625 Detail, Node012, Received: 0x01, 0x10, 0x00, 0x04, 0x00, 0x0c, 0x0a, 0x71, 0x05, 0x00, 0x00, 0x00, 0xff, 0x06, 0x16, 0x00, 0x00, 0x76
2018-05-19 22:49:26.626 Detail,
2018-05-19 22:49:26.626 Info, Node012, Received Alarm report: type=0, level=0, sensorSrcID=0, type:Access Control event:22, status=255
2018-05-19 22:49:26.626 Detail, Node012, Refreshed Value: old value=0, new value=0, type=byte
2018-05-19 22:49:26.626 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.626 Detail, Node012, Refreshed Value: old value=0, new value=0, type=byte
2018-05-19 22:49:26.626 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.626 Detail, Node012, Refreshed Value: old value=0, new value=0, type=byte
2018-05-19 22:49:26.626 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.626 Detail, Node012, Refreshed Value: old value=23, new value=22, type=byte
2018-05-19 22:49:26.626 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.626 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:26.690 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:26.752 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:26.776 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:26.820 Detail, Node012, Received: 0x01, 0x10, 0x00, 0x04, 0x00, 0x0c, 0x0a, 0x71, 0x05, 0x00, 0x00, 0x00, 0xff, 0x06, 0x16, 0x00, 0x00, 0x76
2018-05-19 22:49:26.821 Detail,
2018-05-19 22:49:26.821 Info, Node012, Received Alarm report: type=0, level=0, sensorSrcID=0, type:Access Control event:22, status=255
2018-05-19 22:49:26.821 Detail, Node012, Refreshed Value: old value=0, new value=0, type=byte
2018-05-19 22:49:26.821 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.821 Detail, Node012, Refreshed Value: old value=0, new value=0, type=byte
2018-05-19 22:49:26.821 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.821 Detail, Node012, Refreshed Value: old value=0, new value=0, type=byte
2018-05-19 22:49:26.821 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.821 Detail, Node012, Refreshed Value: old value=22, new value=22, type=byte
2018-05-19 22:49:26.821 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.821 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:26.857 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:26.903 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:26.941 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:26.994 Detail, Node012, Received: 0x01, 0x10, 0x00, 0x04, 0x00, 0x0c, 0x0a, 0x71, 0x05, 0x00, 0x00, 0x00, 0xff, 0x06, 0x16, 0x00, 0x00, 0x76
2018-05-19 22:49:26.994 Detail,
2018-05-19 22:49:26.994 Info, Node012, Received Alarm report: type=0, level=0, sensorSrcID=0, type:Access Control event:22, status=255
2018-05-19 22:49:26.994 Detail, Node012, Refreshed Value: old value=0, new value=0, type=byte
2018-05-19 22:49:26.994 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.994 Detail, Node012, Refreshed Value: old value=0, new value=0, type=byte
2018-05-19 22:49:26.994 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.994 Detail, Node012, Refreshed Value: old value=0, new value=0, type=byte
2018-05-19 22:49:26.995 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.995 Detail, Node012, Refreshed Value: old value=22, new value=22, type=byte
2018-05-19 22:49:26.995 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:26.995 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:27.041 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:27.086 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:27.121 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:27.163 Detail, Node012, Received: 0x01, 0x10, 0x00, 0x04, 0x00, 0x0c, 0x0a, 0x71, 0x05, 0x00, 0x00, 0x00, 0xff, 0x06, 0x16, 0x00, 0x00, 0x76
2018-05-19 22:49:27.163 Detail,
2018-05-19 22:49:27.163 Info, Node012, Received Alarm report: type=0, level=0, sensorSrcID=0, type:Access Control event:22, status=255
2018-05-19 22:49:27.163 Detail, Node012, Refreshed Value: old value=0, new value=0, type=byte
2018-05-19 22:49:27.163 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:27.163 Detail, Node012, Refreshed Value: old value=0, new value=0, type=byte
2018-05-19 22:49:27.163 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:27.163 Detail, Node012, Refreshed Value: old value=0, new value=0, type=byte
2018-05-19 22:49:27.163 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:27.163 Detail, Node012, Refreshed Value: old value=22, new value=22, type=byte
2018-05-19 22:49:27.163 Detail, Node012, Changes to this value are not verified
2018-05-19 22:49:27.164 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:27.221 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:27.263 Detail, Node012, Notification: ValueChanged
2018-05-19 22:49:27.318 Detail, Node012, Notification: ValueChanged
2018-05-19 22:51:59.723 Info, Node006, Value::Set - COMMAND_CLASS_SWITCH_BINARY - Switch - 0 - 1 - False

2

The reception of actual messages on all three channels of notification (both as “basic set”, “binary sensor” and “alarm”) as logged in the z-wave log suggests this was genuine activation report coming from your sensor, not a software glitch on the Pi. You could try verifying that the sensor-magnet distance is not marginal (barely adequate), that the sensor battery isn’t depleted and you might look for any plausible sources of strong interference close to your sensor that might scramble its brains occasionally (Microwave owen? WiFi router? Arc welder…? No idea what qualifies…). If none of the above, your sensor might simply be flaky…

1 Like
3

Thanks for the advice @blinkenlight :slight_smile:
I dont suspect anything is causing electrical interference, or that the sensor-magnet distance is not adequate…I have three other door/window sensors nearby (same model), and they work just fine.

I guess I’ll just wait and see if it happens again, and if its the same pattern (Pi being unresponsive and several simultaneous device reports). If it does happen, I’ll try a factory reset and after that perhaps contact the vendor.