[ANSWERED]: Multiple log entries from fibaro motion sensor

I have been seeing this issue for some time. I see double or triple log entries for the same event.
I don't think it has caused any issues, but I assume it should not be like this.

The copy from the event log below is for one of my motions sensors. As far as I have seen this is only an issue with the fibaro motion devices. I have 5 of these.

Code: Select all

12 Aug 2014 08:21:57
  Z-Wave                          received "Bevegelsessensor stue" status update is off
  Z-Wave                          received "Bevegelsessensor stue" status update is off
  Indigo Cocoa client authenticated (10.0.1.34)
  Z-Wave                          received "Bevegelsessensor stue" status update is on
  Trigger                         Last Motion - Stue
  Z-Wave                          received "Bevegelsessensor stue" status update is on

12 Aug 2014 08:22:36
  Z-Wave                          received "Bevegelsessensor stue" status update is off
  Z-Wave                          received "Bevegelsessensor stue" status update is off

12 Aug 2014 08:24:55
  Z-Wave                          received "Bevegelsessensor stue" status update is on
  Trigger                         Last Motion - Stue
  Z-Wave                          received "Bevegelsessensor stue" status update is on

12 Aug 2014 08:25:25
  Z-Wave                          received "Bevegelsessensor stue" status update is off
  Z-Wave                          received "Bevegelsessensor stue" status update is off


Håvard

Is there any way I can identify if this hardware or software related?

Is there any way I can identify if this hardware or software related?

I am getting the same duplicates with my Fibaro motion detector. I have just turned on Z-Wave debugging (set via Interfaces > Z-Wave > Configure... > Show debug logging of interface communications) and it looks like it is the hardware sending the messages but they could be subtly different messages even though they appear as a common message in the log e.g. 'received "Fibaro-Motion" status update is on'.

I haven't got time this morning to look at this in more detail but will follow it up later

... I haven't got time this morning to look at this in more detail but will follow it up later

Here is the follow up; edited entries from the log are:

2014-08-14 12:43:00.474 Z-Wave Debug RCVD requestBinarySensorStatus: 01 09 00 04 00 52 03 30 03 FF 6F
2014-08-14 12:43:00.474 Z-Wave Debug . . requestBinarySensorStatus: node 082, endpoint None, value 255
2014-08-14 12:43:00.475 Z-Wave received "S10-Motion" status update is on
2014-08-14 12:43:00.509 Z-Wave Debug RCVD sensorSetLevel: 01 09 00 04 00 52 03 20 01 FF 7D
2014-08-14 12:43:00.509 Z-Wave Debug . . sensorSetLevel: node 082, endpoint None, cmdClass 20, value 255
2014-08-14 12:43:00.511 Z-Wave received "S10-Motion" status update is on

2014-08-14 12:43:30.788 Z-Wave Debug RCVD requestBinarySensorStatus: 01 09 00 04 00 52 03 30 03 00 90
2014-08-14 12:43:30.789 Z-Wave Debug . . requestBinarySensorStatus: node 082, endpoint None, value 0
2014-08-14 12:43:30.789 Z-Wave received "S10-Motion" status update is off
2014-08-14 12:43:30.855 Z-Wave Debug RCVD sensorSetLevel: 01 09 00 04 00 52 03 20 01 00 82
2014-08-14 12:43:30.856 Z-Wave Debug . . sensorSetLevel: node 082, endpoint None, cmdClass 20, value 0
2014-08-14 12:43:30.856 Z-Wave received "S10-Motion" status update is off

Not sure if this casts any light on the question but it does seem that the z-wave is receiving 'requestBinarySensorStatus' and 'sensorSetLevel' as two separate messages which is causing Indigo to display either "S10-Motion" status update is on / off messages.

Not sure what other messages are being sent through when more than two occurrences happen as I haven't been able to log that.

This is definitely useful information. I am also for the main part receiving double on/off notifications. So can something be done by the way indigo interpret the data?

[matt (support)]

I've made a modification so that Indigo only logs one Status Update per change. This will be in the next Indigo minor update release.

Thanks for the debug logging information — it was helpful.

Great news Matt, thanks.

Clarifying question: is this fix just for Fibaro sensors, or all Z-wave devices? I've seen similar behavior from an Everspring illumination sensor.

Dave

[matt (support)]

Just the Fibaro motion sensor. Copy/paste the debug log showing the duplicates for other modules and I'll investigate those as well.

Thanks for the update!

Just the Fibaro motion sensor. Copy/paste the debug log showing the duplicates for other modules and I'll investigate those as well.

Will do.

I've made a modification so that Indigo only logs one Status Update per change. This will be in the next Indigo minor update release.

Thanks for the debug logging information — it was helpful.

Thanks for fixing it in the next release

I do still have this issue with some fibaro motion sensor

[matt (support)]

Please turn on the debug logging (via Interfaces->Z-Wave->Configure... menu), then capture a few examples illustrating the problem and copy/paste the results into a forum reply.

Here is an example log entry:

Code: Select all

19.04.2015 09:16:48
  Z-Wave Debug                    RCVD requestVarSensorStatus: 01 0C 00 04 00 18 06 31 05 03 0A 00 80 54
  Z-Wave Debug                    . .  requestVarSensorStatus: node 024, endpoint None, type 3, raw value 0A00...
  Z-Wave Debug                    . .  requestVarSensorStatus: 128 lux (float: 128.000000)
  Z-Wave Debug                    received "Luminance Büro" sensor update to 128 lux

19.04.2015 09:18:49
  Z-Wave Debug                    RCVD requestVarSensorStatus: 01 0C 00 04 00 18 06 31 05 03 0A 00 81 55
  Z-Wave Debug                    . .  requestVarSensorStatus: node 024, endpoint None, type 3, raw value 0A00...
  Z-Wave Debug                    . .  requestVarSensorStatus: 129 lux (float: 129.000000)
  Z-Wave Debug                    received "Luminance Büro" sensor update to 129 lux

19.04.2015 09:20:49
  Z-Wave Debug                    RCVD requestVarSensorStatus: 01 0C 00 04 00 18 06 31 05 03 0A 00 81 55
  Z-Wave Debug                    . .  requestVarSensorStatus: node 024, endpoint None, type 3, raw value 0A00...
  Z-Wave Debug                    . .  requestVarSensorStatus: 129 lux (float: 129.000000)
  Z-Wave Debug                    received "Luminance Büro" sensor update to 129 lux

19.04.2015 09:21:24
  WUnderground                    There are no severe weather alerts for the ...  location.

19.04.2015 09:22:08
  Z-Wave Debug                    RCVD requestBinarySensorStatus: 01 09 00 04 00 03 03 30 03 FF 3E
  Z-Wave Debug                    . .  requestBinarySensorStatus: node 003, endpoint None, value 255
  Z-Wave Debug                    RCVD sensorSetLevel: 01 09 00 04 00 03 03 20 01 FF 2C
  Z-Wave Debug                    . .  sensorSetLevel: node 003, endpoint None, cmdClass 20, value 255

19.04.2015 09:22:50
  Z-Wave Debug                    RCVD requestVarSensorStatus: 01 0C 00 04 00 18 06 31 05 03 0A 00 81 55
  Z-Wave Debug                    . .  requestVarSensorStatus: node 024, endpoint None, type 3, raw value 0A00...
  Z-Wave Debug                    . .  requestVarSensorStatus: 129 lux (float: 129.000000)
  Z-Wave Debug                    received "Luminance Büro" sensor update to 129 lux
  Z-Wave Debug                    RCVD requestBinarySensorStatus: 01 09 00 04 00 03 03 30 03 00 C1
  Z-Wave Debug                    . .  requestBinarySensorStatus: node 003, endpoint None, value 0
  Z-Wave Debug                    RCVD sensorSetLevel: 01 09 00 04 00 03 03 20 01 00 D3
  Z-Wave Debug                    . .  sensorSetLevel: node 003, endpoint None, cmdClass 20, value 0

19.04.2015 09:24:51
  Z-Wave Debug                    RCVD requestVarSensorStatus: 01 0C 00 04 00 18 06 31 05 03 0A 00 81 55
  Z-Wave Debug                    . .  requestVarSensorStatus: node 024, endpoint None, type 3, raw value 0A00...
  Z-Wave Debug                    . .  requestVarSensorStatus: 129 lux (float: 129.000000)
  Z-Wave Debug                    received "Luminance Büro" sensor update to 129 lux


Each of those updates is two minutes apart.

Can you check what polling is set on this device (in Edit device) and also what interval you've set for luminance updates in the same place?

Two of the parameters are for 'send luminance updates every ....' and for 'if luminance changes by .... then send update immediately'.