Thank you for the update. I grabbed the latest build and then removed and readded the device using HABmin. I then updated the items file to include a item and associated it to the new channel. Should I have done anything additional to apply the changes?
Contact FF_Mud_Entry_Sensor "Mud Entry [%s]" <door> (FF_Mud, Door) {channel="zwave:device:cab10335:node23:sensor_door"}
Number FF_Mud_Entry_Battery "Mud Entry Battery [%d %%]" <energy> (FF_Mud, Status) {channel="zwave:device:cab10335:node23:battery-level"}
Switch FF_Mud_Entry_Tamper "Mud Tamper [%s]" <siren> (FF_Mud, Status) {channel="zwave:device:cab10335:node23:alarm_burglar"}
Switch FF_Mud_Entry_Binary "Mud Entry Binary [%s]" <door> (FF_Mud, Door) {channel="zwave:device:cab10335:node23:sensor_binary"}
I’m new to these logs so I’m not really sure what to make of everything but my interpretation is that the only channel I’m seeing get updated is alarm_burglar.
When I remove the magnet to put the Reed Switch into open I get:
2018-01-20 10:16:37.547 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 23: Application Command Request (ALIVE:DYNAMIC_VALUES)
2018-01-20 10:16:37.550 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 23: Incoming command class BASIC
2018-01-20 10:16:37.552 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 23: Received Basic Request
2018-01-20 10:16:37.555 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 23: Basic Set sent to the controller will be processed as Basic Report
2018-01-20 10:16:37.557 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 23: Basic report, value = 0xFF
2018-01-20 10:16:37.562 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2018-01-20 10:16:37.564 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Got a value event from Z-Wave network, endpoint = 0, command class = BASIC, value = 255
2018-01-20 10:16:37.567 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Message has Ack Pending: Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=23, callback=159, payload=17 02 30 02
2018-01-20 10:16:37.616 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 23: Application Command Request (ALIVE:DYNAMIC_VALUES)
2018-01-20 10:16:37.617 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 23: Incoming command class BASIC
2018-01-20 10:16:37.619 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 23: Received Basic Request
2018-01-20 10:16:37.620 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 23: Basic Set sent to the controller will be processed as Basic Report
2018-01-20 10:16:37.621 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 23: Basic report, value = 0xFF
2018-01-20 10:16:37.623 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
2018-01-20 10:16:37.624 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2018-01-20 10:16:37.625 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Got a value event from Z-Wave network, endpoint = 0, command class = BASIC, value = 255
2018-01-20 10:16:37.627 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Message has Ack Pending: Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=23, callback=159, payload=17 02 30 02
2018-01-20 10:16:37.912 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 23: Application Command Request (ALIVE:DYNAMIC_VALUES)
2018-01-20 10:16:37.916 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 23: Incoming command class BASIC
2018-01-20 10:16:37.920 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 23: Received Basic Request
2018-01-20 10:16:37.923 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 23: Basic Set sent to the controller will be processed as Basic Report
2018-01-20 10:16:37.927 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 23: Basic report, value = 0xFF
2018-01-20 10:16:37.934 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2018-01-20 10:16:37.937 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Got a value event from Z-Wave network, endpoint = 0, command class = BASIC, value = 255
2018-01-20 10:16:37.941 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Message has Ack Pending: Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=23, callback=159, payload=17 02 30 02
2018-01-20 10:16:38.041 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 23: Application Command Request (ALIVE:DYNAMIC_VALUES)
2018-01-20 10:16:38.045 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 23: Incoming command class ALARM
2018-01-20 10:16:38.048 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 23: Received ALARM command V2
2018-01-20 10:16:38.051 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 23: Process NOTIFICATION_REPORT V2
2018-01-20 10:16:38.053 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 23: NOTIFICATION report - 7 = 255, event=2, status=255
2018-01-20 10:16:38.056 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 23: Alarm Type = BURGLAR (7)
2018-01-20 10:16:38.061 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Got an event from Z-Wave network: ZWaveAlarmValueEvent
2018-01-20 10:16:38.063 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Got a value event from Z-Wave network, endpoint = 0, command class = ALARM, value = 255
2018-01-20 10:16:38.076 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Updating channel state zwave:device:cab10335:node23:alarm_burglar to ON [OnOffType]
2018-01-20 10:16:38.081 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Message has Ack Pending: Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=23, callback=159, payload=17 02 30 02
I see that there is a BASIC command coming in with a value of 0xFF. Shouldn’t that be what updates the channel for the sensor_door to open?
I also see an ALARM command coming in immediately after with the Alarm Type BURGLAR and a NOTIFICATION report - 7 = 255, event=2, status=255 which is what I assume made the alarm_burglar update to ON.
I don’t see anything in the logs for the node while the Reed Switch remains open.
When I return the magnet to close the reed switch I get:
2018-01-20 10:42:59.025 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 23: Application Command Request (ALIVE:DYNAMIC_VALUES)
2018-01-20 10:42:59.028 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 23: Incoming command class BASIC
2018-01-20 10:42:59.030 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 23: Received Basic Request
2018-01-20 10:42:59.031 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 23: Basic Set sent to the controller will be processed as Basic Report
2018-01-20 10:42:59.032 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 23: Basic report, value = 0x00
2018-01-20 10:42:59.035 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2018-01-20 10:42:59.036 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Got a value event from Z-Wave network, endpoint = 0, command class = BASIC, value = 0
2018-01-20 10:42:59.088 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 23: Application Command Request (ALIVE:DYNAMIC_VALUES)
2018-01-20 10:42:59.090 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 23: Incoming command class ALARM
2018-01-20 10:42:59.091 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 23: Received ALARM command V2
2018-01-20 10:42:59.092 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 23: Process NOTIFICATION_REPORT V2
2018-01-20 10:42:59.093 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 23: NOTIFICATION report - 7 = 0, event=2, status=255
2018-01-20 10:42:59.095 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 23: Alarm Type = BURGLAR (7)
2018-01-20 10:42:59.097 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Got an event from Z-Wave network: ZWaveAlarmValueEvent
2018-01-20 10:42:59.098 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Got a value event from Z-Wave network, endpoint = 0, command class = ALARM, value = 255
2018-01-20 10:42:59.103 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Updating channel state zwave:device:cab10335:node23:alarm_burglar to ON [OnOffType]
I see that there is a BASIC command coming in with a value of 0x00. Shouldn’t that be what updates the channel for the sensor_door to closed?
I also see an ALARM command coming in immediately after with the Alarm Type BURGLAR and a NOTIFICATION report - 7 = 0, event=2, status=255 which is what I assume made the alarm_burglar update but why is it still to ON? The difference I see is that the report is “255” for open and “0” for closed.
When I remove the back cover I get:
2018-01-20 10:12:59.115 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 23: Application Command Request (ALIVE:DYNAMIC_VALUES)
2018-01-20 10:12:59.117 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 23: Incoming command class ALARM
2018-01-20 10:12:59.119 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 23: Received ALARM command V2
2018-01-20 10:12:59.120 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 23: Process NOTIFICATION_REPORT V2
2018-01-20 10:12:59.122 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 23: NOTIFICATION report - 7 = 255, event=3, status=255
2018-01-20 10:12:59.124 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 23: Alarm Type = BURGLAR (7)
2018-01-20 10:12:59.128 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Got an event from Z-Wave network: ZWaveAlarmValueEvent
2018-01-20 10:12:59.129 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Got a value event from Z-Wave network, endpoint = 0, command class = ALARM, value = 255
2018-01-20 10:12:59.135 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Updating channel state zwave:device:cab10335:node23:alarm_burglar to ON [OnOffType]
The same alarm_burglar is triggered to on. The difference I noticed in this command over the reed switch command is the NOTIFICATION report - 7 = 255, event=3, status=255. It is a event 3 instead of the 2 for the reed switch. This matches with what @HomeAutomation included earlier
The same commands repeat in the logs every 20-seconds while the back cover is off.
When I return the cover I get:
2018-01-20 10:15:32.035 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 23: Is awake with 3 messages in the wake-up queue.
2018-01-20 10:15:32.040 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 23: Wakeup during initialisation.
2018-01-20 10:15:32.042 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 23: Node advancer - DYNAMIC_VALUES: queue length(3), free to send(false)
2018-01-20 10:15:32.045 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 23: Node advancer - queued packet. Queue length is 3
2018-01-20 10:15:32.050 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Got an event from Z-Wave network: ZWaveWakeUpEvent
2018-01-20 10:15:32.052 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 23: Sending REQUEST Message = 01 0B 00 13 17 04 71 04 00 06 25 9E 3C
2018-01-20 10:15:32.078 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:cab10335:node23' has been updated.
2018-01-20 10:15:32.084 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 23: Sent Data successfully placed on stack.
2018-01-20 10:15:32.281 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 23: SendData Request. CallBack ID = 158, Status = Transmission complete and ACK received(0)
2018-01-20 10:15:32.285 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=23, callback=158, payload=17 04 71 04 00 06
2018-01-20 10:15:37.055 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 23: Timeout while sending message. Requeueing - 1 attempts left!
2018-01-20 10:15:37.060 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 23: Is sleeping
2018-01-20 10:15:37.062 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 23: Message already on the wake-up queue. Removing original.
2018-01-20 10:15:37.065 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 23: Putting message SendData in wakeup queue.
2018-01-20 10:15:37.070 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 23: Putting message SendData in wakeup queue.
I didn’t see any channel updates being triggered and I also didn’t see any NOTIFICATION report.
I apologize for such a long response but I am really trying to learn so that I can help troubleshoot these types of issues more quickly and maybe be of help to others in the future.
Thank you,
B34N