Initialization problem with Fibaro Door Sensor FGK101

groobie · February 4, 2017, 10:14pm

Hi

I have troubles with the initlization of my Fibaro Door Sensor FGK101. Node shows up in openHab 2 PaperUI. But no data (Battery Level, Door Open Status) is displayed in the control panel.

No node.xml was created for the node.

I attached the log file and some screen shots:

12:39:06.342 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
12:39:06.343 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
12:39:06.343 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
12:39:06.344 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
12:39:06.344 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
12:39:06.346 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update request. Node information received.
12:39:06.346 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Node is ALIVE. Init stage is WAIT.
12:39:06.347 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveNodeStatusEvent
12:39:06.347 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Status event during initialisation - Node is ALIVE
12:39:06.347 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - WAIT: queue length(0), free to send(true)
12:39:06.347 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - WAIT try 1: stageAdvanced(false)
12:39:06.347 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: WAIT - Listening=false, FrequentlyListening=false
12:39:06.347 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: WAIT - Still waiting!
12:39:06.348 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveNodeStatusEvent
12:39:06.348 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Setting ONLINE
12:39:06.352 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:984dd667:node2' changed from ONLINE: Node initialising: WAIT to ONLINE
12:39:06.349 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 2: Node Status event - Node is ALIVE
12:39:06.353 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class ZWAVE_PLUS_INFO
12:39:06.354 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class ZWAVE_PLUS_INFO, endpoint null created
12:39:06.358 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class ZWAVE_PLUS_INFO.
12:39:06.359 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class ZWAVE_PLUS_INFO to the list of supported command classes.
12:39:06.360 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class ASSOCIATION_GROUP_INFO
12:39:06.361 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class ASSOCIATION_GROUP_INFO, endpoint null created
12:39:06.361 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class ASSOCIATION_GROUP_INFO.
12:39:06.362 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class ASSOCIATION_GROUP_INFO to the list of supported command classes.
12:39:06.363 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class APPLICATION_STATUS
12:39:06.363 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class APPLICATION_STATUS, endpoint null created
12:39:06.364 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class APPLICATION_STATUS.
12:39:06.365 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class APPLICATION_STATUS to the list of supported command classes.
12:39:06.365 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class BATTERY
12:39:06.366 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class BATTERY, endpoint null created
12:39:06.366 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class BATTERY.
12:39:06.367 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class BATTERY to the list of supported command classes.
12:39:06.367 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class CRC_16_ENCAP
12:39:06.368 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class CRC_16_ENCAP, endpoint null created
12:39:06.369 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class CRC_16_ENCAP.
12:39:06.369 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class CRC_16_ENCAP to the list of supported command classes.
12:39:06.370 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class FIRMWARE_UPDATE_MD
12:39:06.371 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class FIRMWARE_UPDATE_MD, endpoint null created
12:39:06.372 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class FIRMWARE_UPDATE_MD.
12:39:06.372 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class FIRMWARE_UPDATE_MD to the list of supported command classes.
12:39:06.373 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class MANUFACTURER_SPECIFIC
12:39:06.373 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class MANUFACTURER_SPECIFIC, endpoint null created
12:39:06.374 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class MANUFACTURER_SPECIFIC.
12:39:06.375 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class MANUFACTURER_SPECIFIC to the list of supported command classes.
12:39:06.375 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class POWERLEVEL
12:39:06.376 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class POWERLEVEL, endpoint null created
12:39:06.376 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class POWERLEVEL.
12:39:06.388 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class POWERLEVEL to the list of supported command classes.
12:39:06.389 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class SECURITY
12:39:06.390 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class SECURITY, endpoint null created
12:39:06.391 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: setupNetworkKey useSchemeZero=false
12:39:06.393 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class SECURITY.
12:39:06.393 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class SECURITY to the list of supported command classes.
12:39:06.394 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveSecurityCommandClassWithInitialization@2fb226fd already registered
12:39:06.394 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class VERSION
12:39:06.395 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class VERSION, endpoint null created
12:39:06.396 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class VERSION.
12:39:06.397 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class VERSION to the list of supported command classes.
12:39:06.400 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=IsFailedNodeID[0x62], type=Request[0x00], priority=High, dest=255, callback=0, payload=02
12:39:06.401 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
12:39:06.402 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationUpdate, callback id=0, expected=IsFailedNodeID, cancelled=false      MISMATCH

Some help would be much appreciated.

Many thanks,
Oliver

chris · February 5, 2017, 12:02am

There’s two possible issues -:

You have security enabled - go to the controller and disable security.
The device just hasn’t woken up enough. Wake the device up using the button on the device with it in range of the controller so that openhab can initialise the device. It often takes a few wakeups for it to configure fully

groobie · February 6, 2017, 8:34pm

Hi Chris,

many thanks. security in the controller (Z-wave.me uzb stick) is disabled (see screenshot). But when I try to include the door sensor by pressing the inclusion button 3 times I still get an MISMATCH error in the logs (see below). Any other ideas ?

21:23:17.055 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Node is ALIVE. Init stage is WAIT.
21:23:17.055 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveNodeStatusEvent
21:23:17.055 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Status event during initialisation - Node is ALIVE
21:23:17.055 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - WAIT: queue length(0), free to send(true)
21:23:17.055 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - WAIT try 1: stageAdvanced(false)
21:23:17.055 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: WAIT - Listening=false, FrequentlyListening=false
21:23:17.055 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: WAIT - Still waiting!
21:23:17.055 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 2: Node Status event - Node is ALIVE
21:23:17.056 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class ZWAVE_PLUS_INFO
21:23:17.056 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class ZWAVE_PLUS_INFO, endpoint null created
21:23:17.056 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class ZWAVE_PLUS_INFO.
21:23:17.056 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class ZWAVE_PLUS_INFO to the list of supported command classes.
21:23:17.056 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class ASSOCIATION_GROUP_INFO
21:23:17.056 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class ASSOCIATION_GROUP_INFO, endpoint null created
21:23:17.056 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class ASSOCIATION_GROUP_INFO.
21:23:17.056 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class ASSOCIATION_GROUP_INFO to the list of supported command classes.
21:23:17.056 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class APPLICATION_STATUS
21:23:17.056 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class APPLICATION_STATUS, endpoint null created
21:23:17.056 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class APPLICATION_STATUS.
21:23:17.056 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class APPLICATION_STATUS to the list of supported command classes.
21:23:17.056 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class BATTERY
21:23:17.057 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class BATTERY, endpoint null created
21:23:17.057 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class BATTERY.
21:23:17.057 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class BATTERY to the list of supported command classes.
21:23:17.057 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class CRC_16_ENCAP
21:23:17.059 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class CRC_16_ENCAP, endpoint null created
21:23:17.059 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class CRC_16_ENCAP.
21:23:17.060 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class CRC_16_ENCAP to the list of supported command classes.
21:23:17.060 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class FIRMWARE_UPDATE_MD
21:23:17.061 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class FIRMWARE_UPDATE_MD, endpoint null created
21:23:17.061 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class FIRMWARE_UPDATE_MD.
21:23:17.061 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class FIRMWARE_UPDATE_MD to the list of supported command classes.
21:23:17.062 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class MANUFACTURER_SPECIFIC
21:23:17.062 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class MANUFACTURER_SPECIFIC, endpoint null created
21:23:17.062 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class MANUFACTURER_SPECIFIC.
21:23:17.063 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class MANUFACTURER_SPECIFIC to the list of supported command classes.
21:23:17.063 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class POWERLEVEL
21:23:17.064 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class POWERLEVEL, endpoint null created
21:23:17.064 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class POWERLEVEL.
21:23:17.064 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class POWERLEVEL to the list of supported command classes.
21:23:17.065 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class SECURITY
21:23:17.065 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class SECURITY, endpoint null created
21:23:17.066 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: setupNetworkKey useSchemeZero=false
21:23:17.071 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class SECURITY.
21:23:17.071 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class SECURITY to the list of supported command classes.
21:23:17.072 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveSecurityCommandClassWithInitialization@47f00782 already registered
21:23:17.072 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class VERSION
21:23:17.072 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class VERSION, endpoint null created
21:23:17.072 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class VERSION.
21:23:17.072 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class VERSION to the list of supported command classes.
21:23:17.072 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=IsFailedNodeID[0x62], type=Request[0x00], priority=High, dest=255, callback=0, payload=02
21:23:17.074 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
21:23:17.075 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationUpdate, callback id=0, expected=IsFailedNodeID, cancelled=false      MISMATCH
21:23:43.208 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
21:23:43.209 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
21:23:43.209 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
21:23:43.210 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
21:23:43.210 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
21:23:43.210 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update request. Node information received.
21:23:43.210 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=IsFailedNodeID[0x62], type=Request[0x00], priority=High, dest=255, callback=0, payload=02
21:23:43.210 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
21:23:43.210 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationUpdate, callback id=0, expected=IsFailedNodeID, cancelled=false      MISMATCH
21:23:46.308 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
21:23:46.308 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
21:23:46.309 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
21:23:46.309 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
21:23:46.309 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
21:23:46.309 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update request. Node information received.
21:23:46.309 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=IsFailedNodeID[0x62], type=Request[0x00], priority=High, dest=255, callback=0, payload=02
21:23:46.309 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
21:23:46.310 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationUpdate, callback id=0, expected=IsFailedNodeID, cancelled=false      MISMATCH
21:23:49.210 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
21:23:49.211 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
21:23:49.211 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
21:23:49.211 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
21:23:49.211 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
21:23:49.212 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update request. Node information received.
21:23:49.212 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=IsFailedNodeID[0x62], type=Request[0x00], priority=High, dest=255, callback=0, payload=02
21:23:49.212 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
21:23:49.212 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationUpdate, callback id=0, expected=IsFailedNodeID, cancelled=false      MISMATCH
21:24:57.206 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
21:24:57.206 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
21:24:57.207 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
21:24:57.207 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
21:24:57.207 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
21:24:57.207 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update request. Node information received.
21:24:57.207 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=IsFailedNodeID[0x62], type=Request[0x00], priority=High, dest=255, callback=0, payload=02
21:24:57.208 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
21:24:57.208 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationUpdate, callback id=0, expected=IsFailedNodeID, cancelled=false      MISMATCH
21:24:59.906 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
21:24:59.907 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
21:24:59.907 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
21:24:59.907 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
21:24:59.907 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
21:24:59.907 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update request. Node information received.
21:24:59.908 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=IsFailedNodeID[0x62], type=Request[0x00], priority=High, dest=255, callback=0, payload=02
21:24:59.908 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
21:24:59.908 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationUpdate, callback id=0, expected=IsFailedNodeID, cancelled=false      MISMATCH
21:25:04.109 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
21:25:04.109 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
21:25:04.110 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
21:25:04.110 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
21:25:04.110 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
21:25:04.110 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update request. Node information received.
21:25:04.110 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=IsFailedNodeID[0x62], type=Request[0x00], priority=High, dest=255, callback=0, payload=02
21:25:04.111 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
21:25:04.111 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationUpdate, callback id=0, expected=IsFailedNodeID, cancelled=false      MISMATCH

chris · February 6, 2017, 8:55pm

I don’t see any errors - the log looks ok. Note that the MISMATCH is a debug message - it’s fine.

groobie · February 13, 2017, 7:40pm

Hi Chris.
Still got the same problem. My Fibaro/door window sensor (Node 2) does not complete initialization. I still cannot find a node2.xml unter userdata/zwave. Do you have any other ideas?

Please find a full log after restarting OpenHab attached.

Many thanks,
Oliver

20:12:01.837 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link ‘ZWaveNode2FGK101DoorOpeningSensor_DoorSensor-zwave:device :984dd667:node2:sensor_door’ has been added.
20:12:01.848 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link ‘ZWaveNode2FGK101DoorOpeningSensor_BatteryLevel-zwave:devi ce:984dd667:node2:battery-level’ has been added.
20:12:02.035 [INFO ] [smarthome.event.ItemAddedEvent ] - Item ‘ZWaveNode2FGK101DoorOpeningSensor_DoorSensor’ has been ad ded.
20:12:02.044 [INFO ] [smarthome.event.ItemAddedEvent ] - Item ‘ZWaveNode2FGK101DoorOpeningSensor_BatteryLevel’ has been added.
20:12:02.051 [INFO ] [smarthome.event.ThingAddedEvent ] - Thing ‘zwave:device:984dd667:node2’ has been added.
20:12:02.056 [INFO ] [smarthome.event.ThingAddedEvent ] - Thing ‘zwave:serial_zstick:984dd667’ has been added.
20:12:02.077 [INFO ] [smarthome.event.ItemRemovedEvent ] - Item ‘ZWaveNode2FGK101DoorOpeningSensor_BatteryLevel’ has been removed.
20:12:02.080 [INFO ] [smarthome.event.ItemAddedEvent ] - Item ‘ZWaveNode2FGK101DoorOpeningSensor_BatteryLevel’ has been added.
20:12:02.082 [INFO ] [smarthome.event.ItemRemovedEvent ] - Item ‘ZWaveNode2FGK101DoorOpeningSensor_DoorSensor’ has been re moved.
20:12:02.088 [INFO ] [smarthome.event.ItemAddedEvent ] - Item ‘ZWaveNode2FGK101DoorOpeningSensor_DoorSensor’ has been ad ded.
20:12:03.448 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start
20:12:04.315 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
20:12:04.618 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
20:12:04.746 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
20:12:04.976 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin
20:12:04.988 [DEBUG] [org.openhab.binding.zwave ] - BundleEvent STARTING - org.openhab.binding.zwave
20:12:04.996 [DEBUG] [inding.zwave.internal.ZWaveActivator] - Z-Wave binding started. Version 2.0.0
20:12:05.000 [DEBUG] [org.openhab.binding.zwave ] - BundleEvent STARTED - org.openhab.binding.zwave
20:12:05.027 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.Co nfigOptionProvider, org.eclipse.smarthome.config.core.ConfigDescriptionProvider}={component.name=org.openhab.binding.zwave.Co nfigDescription, component.id=157, service.id=286, service.bundleid=183, service.scope=bundle} - org.openhab.binding.zwave
20:12:05.290 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.events.Ev entFactory}={component.name=org.openhab.binding.zwave.event.BindingEventFactory, component.id=158, service.id=287, service.bu ndleid=183, service.scope=bundle} - org.openhab.binding.zwave
20:12:05.335 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.bin ding.ThingHandlerFactory}={component.name=org.openhab.binding.zwave.internal.ZWaveHandlerFactory, component.id=161, service.i d=288, service.bundleid=183, service.scope=bundle} - org.openhab.binding.zwave
20:12:05.446 [INFO ] [me.event.ThingStatusInfoChangedEvent] - ‘zwave:device:984dd667:node2’ changed from UNINITIALIZED to UNI NITIALIZED (HANDLER_MISSING_ERROR)
20:12:08.611 [INFO ] [me.event.ThingStatusInfoChangedEvent] - ‘zwave:serial_zstick:984dd667’ changed from UNINITIALIZED to IN ITIALIZING
20:12:08.618 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller.
20:12:08.619 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller.
20:12:08.630 [INFO ] [me.event.ThingStatusInfoChangedEvent] - ‘zwave:serial_zstick:984dd667’ changed from INITIALIZING to OFF LINE (BRIDGE_OFFLINE): Controller is offline
20:12:08.636 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0’
20:12:08.672 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.st atus.ConfigStatusProvider}={service.id=291, service.bundleid=183, service.scope=singleton} - org.openhab.binding.zwave
20:12:08.761 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Starting receive thread
20:12:08.766 [INFO ] [me.event.ThingStatusInfoChangedEvent] - ‘zwave:device:984dd667:node2’ changed from UNINITIALIZED (HANDL ER_MISSING_ERROR) to INITIALIZING
20:12:08.769 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
20:12:08.770 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive
20:12:08.770 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller
20:12:08.797 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler.
20:12:08.806 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Command received zwave:device:984dd667:node2:sensor_doo r --> REFRESH
20:12:08.807 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - Controller handler not found. Cannot handle command without ZWa ve controller.
20:12:08.808 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Command received zwave:device:984dd667:node2:battery-le vel --> REFRESH
20:12:08.808 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - Controller handler not found. Cannot handle command without ZWa ve controller.
20:12:08.809 [INFO ] [me.event.ThingStatusInfoChangedEvent] - ‘zwave:device:984dd667:node2’ changed from INITIALIZING to OFFL INE (BRIDGE_OFFLINE): Controller is offline
20:12:08.812 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - Update networkKey
20:12:08.850 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
20:12:08.850 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
20:12:08.858 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Starting ZWave thread: Send
20:12:08.868 [DEBUG] [ve.internal.protocol.ZWaveController] - Starting ZWave thread: Input
20:12:08.869 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - Activating ZWave discovery service for zwave:serial_zstick:984d d667
20:12:08.884 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discove ry.DiscoveryService}={service.id=292, service.bundleid=183, service.scope=singleton} - org.openhab.binding.zwave
20:12:11.851 [DEBUG] [.ZWaveController$InitializeDelayTask] - Initialising network
20:12:11.860 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
20:12:11.864 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9
20:12:11.865 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9
20:12:11.871 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 01 15 5A 2D 57 61 76 65 20 34 2E 30 35 00 01 97
20:12:11.877 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 0. Queue={}
20:12:11.883 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
20:12:11.890 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 2. Queue={}
20:12:11.899 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:12:11.900 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 10 01 15 5A 2D 57 61 76 65 20 34 2E 30 35 00 01 97
20:12:11.901 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 10 01 15 5A 2D 57 61 76 65 20 34 2E 30 35 00 01 97
20:12:11.904 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=GetVersion[0x15], type=Response[0x01], priority= High, dest=255, callback=0, payload=5A 2D 57 61 76 65 20 34 2E 30 35 00 01
20:12:11.912 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 3. Queue={}
20:12:11.925 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID
20:12:11.928 [DEBUG] [serialmessage.GetVersionMessageClass] - Got MessageGetVersion response. Version = Z-Wave 4.05, Library Type = 0x01
20:12:11.936 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=GetVersion[0 x15], type=Request[0x00], priority=High, dest=255, callback=0, payload=
20:12:11.938 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 4. Queue={}
20:12:11.942 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=GetVersion[0 x15], type=Response[0x01], priority=High, dest=255, callback=0, payload=5A 2D 57 61 76 65 20 34 2E 30 35 00 01
20:12:11.946 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=GetVersion, callback id=0, expected=GetVersion, cancelled=false transaction complete!
20:12:11.949 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
20:12:11.956 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 88ms/88ms.
20:12:11.956 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 3
20:12:11.957 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 20 DC
20:12:11.957 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 20 DC
20:12:11.963 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 01 20 D1 FD DA FF 01 DE
20:12:11.964 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:12:11.968 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 01 20 D1 FD DA FF 01 DE
20:12:11.970 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 08 01 20 D1 FD DA FF 01 DE
20:12:11.973 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=MemoryGetId[0x20], type=Response[0x01], priority =High, dest=255, callback=0, payload=D1 FD DA FF 01
20:12:11.975 [DEBUG] [erialmessage.MemoryGetIdMessageClass] - Got MessageMemoryGetId response. Home id = 0xD1FDDAFF, Controll er Node id = 1
20:12:11.978 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=MemoryGetId[ 0x20], type=Request[0x00], priority=High, dest=255, callback=0, payload=
20:12:11.979 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=MemoryGetId[ 0x20], type=Response[0x01], priority=High, dest=255, callback=0, payload=D1 FD DA FF 01
20:12:11.982 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=MemoryGetId, callback id=0 , expected=MemoryGetId, cancelled=false transaction complete!
20:12:11.984 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
20:12:11.986 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 24ms/88ms.
20:12:11.987 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 2
20:12:11.987 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 07 FB
20:12:11.988 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 07 FB
20:12:11.993 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 2B 01 07 05 06 01 15 04 00 00 01 FE 83 FF 88 CF 1F 00 00 FB 9F 7D A0 67 00 80 80 00 80 86 00 00 00 E8 73 00 00 0E 00 00 40 1A 00 0D
20:12:11.997 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:12:11.999 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 2B 01 07 05 06 01 15 04 00 00 01 FE 83 FF 88 CF 1F 00 00 FB 9F 7D A0 67 00 80 80 00 80 86 00 00 00 E8 73 00 00 0E 00 00 40 1A 00 0D
20:12:12.002 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 2B 01 07 05 06 01 15 04 00 00 01 FE 83 FF 88 CF 1F 00 00 FB 9F 7D A0 67 00 80 80 00 80 86 00 00 00 E8 73 00 00 0E 00 00 40 1A 00 0D
20:12:12.006 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SerialApiGetCapabilities[0x07], type=Response[0x 01], priority=High, dest=255, callback=0, payload=05 06 01 15 04 00 00 01 FE 83 FF 88 CF 1F 00 00 FB 9F 7D A0 67 00 80 80 00 80 86 00 00 00 E8 73 00 00 0E 00 00 40 1A 00
20:12:12.008 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - API Version = 5.6
20:12:12.011 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Manufacture ID = 0x115
20:12:12.013 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Device Type = 0x400
20:12:12.014 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Device ID = 0x1
20:12:12.017 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: SerialApiGetInitData
20:12:12.017 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: SerialApiApplicationNodeInfo
20:12:12.020 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: ApplicationCommandHandler
20:12:12.023 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: GetControllerCapabilities
20:12:12.024 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: SerialApiSetTimeouts
20:12:12.027 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: SerialApiGetCapabilities
20:12:12.029 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: SerialApiSoftReset
20:12:12.030 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0x09
20:12:12.032 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0x0a
20:12:12.034 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: RfReceiveMode
20:12:12.035 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: SetSleepMode
20:12:12.036 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: SendNodeInfo
20:12:12.039 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: SendData
20:12:12.041 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: SendDataMulti
20:12:12.042 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: GetVersion
20:12:12.044 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: SendDataAbort
20:12:12.045 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: RfPowerLevelSet
20:12:12.048 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: SendDataMeta
20:12:12.049 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: GetRandom
20:12:12.050 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: MemoryGetId
20:12:12.052 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: MemoryGetByte
20:12:12.053 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: MemoryPutByte
20:12:12.055 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: ReadMemory
20:12:12.056 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: WriteMemory
20:12:12.057 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0x27
20:12:12.059 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0x28
20:12:12.061 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0x29
20:12:12.063 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0x2a
20:12:12.065 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0x2b
20:12:12.066 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0x2c
20:12:12.069 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0x2d
20:12:12.070 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: IdentifyNode
20:12:12.071 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: SetDefault
20:12:12.073 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: ReplicationCommandComplete
20:12:12.074 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: ReplicationSendData
20:12:12.075 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: AssignReturnRoute
20:12:12.077 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: DeleteReturnRoute
20:12:12.078 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: RequestNodeNeighborUpdate
20:12:12.080 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: ApplicationUpdate
20:12:12.083 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: AddNodeToNetwork
20:12:12.085 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: RemoveNodeFromNetwork
20:12:12.086 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: CreateNewPrimary
20:12:12.088 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: ControllerChange
20:12:12.089 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: SetLearnMode
20:12:12.091 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: AssignSucReturnRoute
20:12:12.092 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: RequestNetworkUpdate
20:12:12.093 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: SetSucNodeID
20:12:12.095 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: DeleteSUCReturnRoute
20:12:12.097 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: GetSucNodeId
20:12:12.098 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: SendSucId
20:12:12.099 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: ExploreRequestInclusion
20:12:12.101 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: RequestNodeInfo
20:12:12.102 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: RemoveFailedNodeID
20:12:12.104 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: IsFailedNodeID
20:12:12.105 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: ReplaceFailedNode
20:12:12.107 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0x66
20:12:12.108 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0x67
20:12:12.110 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0x78
20:12:12.112 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: GetRoutingInfo
20:12:12.114 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: LockRoute
20:12:12.115 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0x92
20:12:12.117 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0x93
20:12:12.118 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0x98
20:12:12.120 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0xb4
20:12:12.120 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: WatchDogKick
20:12:12.121 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: WatchDogDisable
20:12:12.122 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0xb8
20:12:12.125 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0xb9
20:12:12.127 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: RfPowerLevelSet
20:12:12.128 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: GetLibraryType
20:12:12.129 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: SendTestFrame
20:12:12.129 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: GetProtocolStatus
20:12:12.132 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0xd2
20:12:12.134 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0xd3
20:12:12.135 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0xd4
20:12:12.138 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0xef
20:12:12.139 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0xf2
20:12:12.141 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0xf4
20:12:12.143 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Supports: Unknown Class 0xf5
20:12:12.145 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SerialApiGet

groobie · February 13, 2017, 7:42pm

Capabilities[0x07], type=Request[0x00], priority=High, dest=255, callback=0, payload=
20:12:12.149 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SerialApiGet Capabilities[0x07], type=Response[0x01], priority=High, dest=255, callback=0, payload=05 06 01 15 04 00 00 01 FE 83 FF 88 CF 1F 00 00 FB 9F 7D A0 67 00 80 80 00 80 86 00 00 00 E8 73 00 00 0E 00 00 40 1A 00
20:12:12.150 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SerialApiGetCapabilities, callback id=0, expected=SerialApiGetCapabilities, cancelled=false transaction complete!
20:12:12.152 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
20:12:12.153 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 165ms/165ms.
20:12:12.154 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 1
20:12:12.154 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 06 96 0F 65
20:12:12.158 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 06 96 0F 65
20:12:12.159 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 2. Queue={}
20:12:12.162 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 01 06 96 0F 64
20:12:12.163 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:12:12.166 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 01 06 96 0F 64
20:12:12.167 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 05 01 06 96 0F 64
20:12:12.170 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SerialApiSetTimeouts[0x06], type=Response[0x01], priority=High, dest=255, callback=0, payload=96 0F
20:12:12.171 [DEBUG] [age.SerialApiSetTimeoutsMessageClass] - Got SerialApiSetTimeouts response. ACK=150, BYTE=15
20:12:12.174 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SerialApiSet Timeouts[0x06], type=Request[0x00], priority=High, dest=255, callback=0, payload=96 0F
20:12:12.176 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SerialApiSet Timeouts[0x06], type=Response[0x01], priority=High, dest=255, callback=0, payload=96 0F
20:12:12.178 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SerialApiSetTimeouts, call back id=0, expected=SerialApiSetTimeouts, cancelled=false transaction complete!
20:12:12.178 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
20:12:12.180 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 21ms/165ms.
20:12:12.180 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 1
20:12:12.181 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 56 AA
20:12:12.181 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 56 AA
20:12:12.183 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 56 00 AC
20:12:12.184 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:12:12.185 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 56 00 AC
20:12:12.187 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 56 00 AC
20:12:12.189 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=GetSucNodeId[0x56], type=Response[0x01], priorit y=High, dest=255, callback=0, payload=00
20:12:12.191 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - Got SUC NodeID response.
20:12:12.192 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - No SUC Node is set
20:12:12.193 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=GetSucNodeId [0x56], type=Request[0x00], priority=High, dest=255, callback=0, payload=
20:12:12.196 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=GetSucNodeId [0x56], type=Response[0x01], priority=High, dest=255, callback=0, payload=00
20:12:12.197 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=GetSucNodeId, callback id= 0, expected=GetSucNodeId, cancelled=false transaction complete!
20:12:12.198 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
20:12:12.201 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 18ms/165ms.
20:12:12.201 [DEBUG] [etControllerCapabilitiesMessageClass] - Creating GET_CONTROLLER_CAPABILITIES message
20:12:12.201 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
20:12:12.202 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 02 FE
20:12:12.203 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 02 FE
20:12:12.203 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
20:12:12.298 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 25 01 02 05 00 1D 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 C7
20:12:12.301 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:12:12.302 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 25 01 02 05 00 1D 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 C7
20:12:12.303 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 25 01 02 05 00 1D 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 C7
20:12:12.304 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SerialApiGetInitData[0x02], type=Response[0x01], priority=High, dest=255, callback=0, payload=05 00 1D 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0 0 00 00 00 00 00 05 00
20:12:12.307 [DEBUG] [age.SerialApiGetInitDataMessageClass] - Got MessageSerialApiGetInitData response.
20:12:12.309 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 1: Node found
20:12:12.311 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 2: Node found
20:12:12.312 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API
20:12:12.315 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller
20:12:12.316 [INFO ] [age.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controlle r------------
20:12:12.320 [INFO ] [age.SerialApiGetInitDataMessageClass] - # Nodes = 2
20:12:12.321 [INFO ] [age.SerialApiGetInitDataMessageClass] - --------------------------------------------------------------- -------------
20:12:12.324 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SerialApiGet InitData[0x02], type=Request[0x00], priority=High, dest=255, callback=0, payload=
20:12:12.327 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SerialApiGet InitData[0x02], type=Response[0x01], priority=High, dest=255, callback=0, payload=05 00 1D 03 00 00 00 00 00 00 00 00 00 00 0 0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00
20:12:12.331 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SerialApiGetInitData, call back id=0, expected=SerialApiGetInitData, cancelled=false transaction complete!
20:12:12.334 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
20:12:12.334 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 131ms/165ms.
20:12:12.335 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
20:12:12.335 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 05 F9
20:12:12.335 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 05 F9
20:12:12.337 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 05 08 F7
20:12:12.343 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
20:12:12.358 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
20:12:12.361 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 1: Init node thread start
20:12:12.367 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 2: Init node thread start
20:12:12.382 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:12:12.383 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 05 08 F7
20:12:12.383 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 05 08 F7
20:12:12.383 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=GetControllerCapabilities[0x05], type=Response[0 x01], priority=High, dest=255, callback=0, payload=08
20:12:12.388 [DEBUG] [etControllerCapabilitiesMessageClass] - Controller is secondary = false
20:12:12.389 [DEBUG] [etControllerCapabilitiesMessageClass] - Controller is on other network = false
20:12:12.389 [DEBUG] [etControllerCapabilitiesMessageClass] - Node ID Server is present = false
20:12:12.389 [DEBUG] [etControllerCapabilitiesMessageClass] - Controller is real primary = true
20:12:12.389 [DEBUG] [etControllerCapabilitiesMessageClass] - Controller is SUC = false
20:12:12.389 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=GetControlle rCapabilities[0x05], type=Request[0x00], priority=High, dest=255, callback=0, payload=
20:12:12.390 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=GetControlle rCapabilities[0x05], type=Response[0x01], priority=High, dest=255, callback=0, payload=08
20:12:12.391 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=GetControllerCapabilities, callback id=0, expected=GetControllerCapabilities, cancelled=false transaction complete!
20:12:12.391 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
20:12:12.392 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 56ms/165ms.
20:12:12.393 [DEBUG] [ve.internal.protocol.ZWaveController] - Waiting for init thread Node_1_init
20:12:12.756 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 2: Serializing from file /volume1/@appstore/openHAB2/userd ata/zwave/node2.xml
20:12:12.757 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 1: Serializing from file /volume1/@appstore/openHAB2/userd ata/zwave/node1.xml
20:12:12.764 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 2: Error serializing from file: file does not exist.
20:12:12.811 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 1: Restore from config: Ok.
20:12:12.814 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Starting initialisation from EMPTYNODE
20:12:12.818 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Starting initialisation from EMPTYNODE
20:12:12.818 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - EMPTYNODE: queue length(0), free to sen d(true)
20:12:12.819 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Initialisation retry timer started 5000
20:12:12.819 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: loop - EMPTYNODE try 1: stageAdvanced(fa lse)
20:12:12.820 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: Initialisation starting
20:12:12.820 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - EMPTYNODE: queue length(0), free to sen d(true)
20:12:12.820 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - EMPTYNODE try 1: stageAdvanced(fa lse)
20:12:12.820 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: Initialisation starting
20:12:12.821 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - advancing to PROTOINFO
20:12:12.821 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
20:12:12.821 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - PROTOINFO try 0: stageAdvanced(tr ue)
20:12:12.822 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: PROTOINFO - send IdentifyNode
20:12:12.835 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - queued packet. Queue length is 1
20:12:12.836 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
20:12:12.836 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
20:12:12.836 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 2: Init node thread finished
20:12:12.841 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 02 B8
20:12:12.841 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 02 B8
20:12:12.847 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 53 9C 01 04 07 01 7A
20:12:12.847 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:12:12.848 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to PROTOINFO
20:12:12.848 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
20:12:12.848 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 01 41 53 9C 01 04 07 01 7A
20:12:12.849 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 01 41 53 9C 01 04 07 01 7A
20:12:12.849 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=IdentifyNode[0x41], type=Response[0x01], priorit y=High, dest=255, callback=0, payload=53 9C 01 04 07 01
20:12:12.850 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: ProtocolInfo
20:12:12.848 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: loop - PROTOINFO try 0: stageAdvanced(tr ue)
20:12:12.850 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Listening = false
20:12:12.850 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: PROTOINFO - send IdentifyNode
20:12:12.851 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - queued packet. Queue length is 1
20:12:12.854 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
20:12:12.851 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Routing = true
20:12:12.856 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
20:12:12.856 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Beaming = true
20:12:12.859 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Version = 4
20:12:12.859 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: FLIRS = false
20:12:12.859 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Security = false
20:12:12.859 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Max Baud = 40000
20:12:12.859 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Starting initialisation from EMPTYNODE
20:12:12.859 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Basic = Routing Slave
20:12:12.860 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.init ialization.ZWaveNodeInitStageAdvancer@7d2a3b74 already registered
20:12:12.860 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Generic = Sensor Notification
20:12:12.860 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Specific = Notification Sensor
20:12:12.862 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class NO_OPERATION
20:12:12.863 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - EMPTYNODE: queue length(1), free to sen d(false)
20:12:12.863 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Initialisation retry timer started 5000
20:12:12.864 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - queued packet. Queue length is 1
20:12:12.864 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class NO_OPERATION, endpoint null created
20:12:12.865 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Version = 1, version set. Enabling extra functionality.
20:12:12.866 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class NO_OPERATION to the list of suppor ted command classes.
20:12:12.867 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class BASIC
20:12:12.867 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 2. Queue={}
20:12:12.868 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 1: Init node thread finished
20:12:12.868 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class BASIC, endpoint null created
20:12:12.872 [DEBUG] [ve.internal.protocol.ZWaveController] - Init thread Node_1_init complete
20:12:12.872 [DEBUG] [ve.internal.protocol.ZWaveController] - Waiting for init thread Node_2_init
20:12:12.872 [DEBUG] [ve.internal.protocol.ZWaveController] - Init thread Node_2_init complete
20:12:12.872 [DEBUG] [ve.internal.protocol.ZWaveController] - All init threads complete
20:12:12.873 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveNetworkStateEvent
20:12:12.873 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller: Incoming Network State Event true
20:12:12.875 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Controller status changed to ONLINE.
20:12:12.876 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Controller is ONLINE. Starting device initialisation.
20:12:12.878 [INFO ] [me.event.ThingStatusInfoChangedEvent] - ‘zwave:serial_zstick:984dd667’ changed from OFFLINE (BRIDGE_OFF LINE): Controller is offline to ONLINE
20:12:12.879 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties.
20:12:12.879 [INFO ] [me.event.ThingStatusInfoChangedEvent] - ‘zwave:device:984dd667:node2’ changed from OFFLINE (BRIDGE_OFFL INE): Controller is offline to ONLINE
20:12:12.880 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties. MAN=2147483647
20:12:12.880 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Properties synchronised
20:12:12.881 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class BASIC to the list of supported com mand classes.
20:12:12.885 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising Thing Node…
20:12:12.889 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=IdentifyNode [0x41], type=Request[0x00], priority=High, dest=255, callback=0, payload=02
20:12:12.890 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=IdentifyNode [0x41], type=Response[0x01], priority=High, dest=255, callback=0, payload=53 9C 01 04 07 01
20:12:12.897 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=IdentifyNode, callback id= 0, expected=IdentifyNode, cancelled=false transaction complete!
20:12:12.897 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising channel zwave:device:984dd667:node2:scene_ number
20:12:12.897 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
20:12:12.903 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - PROTOINFO: Transaction complete (Identi fyNode:Request) success(true)

groobie · February 13, 2017, 7:43pm

20:12:12.904 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - checking initialisation queue. Queue si ze 1.
20:12:12.904 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - message removed from queue. Queue size 0.
20:12:12.904 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - PROTOINFO: queue length(0), free to sen d(true)
20:12:12.910 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - PROTOINFO try 1: stageAdvanced(fa lse)
20:12:12.910 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - advancing to INIT_NEIGHBORS
20:12:12.910 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
20:12:12.911 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveInitializationSt ateEvent
20:12:12.912 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - INIT_NEIGHBORS try 0: stageAdvanc ed(true)
20:12:12.912 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: INIT_NEIGHBORS - send RoutingInfo
20:12:12.913 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 2: Request routing info
20:12:12.913 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - queued packet. Queue length is 1
20:12:12.913 [INFO ] [me.event.ThingStatusInfoChangedEvent] - ‘zwave:device:984dd667:node2’ changed from ONLINE to ONLINE: No de initialising: INIT_NEIGHBORS
20:12:12.914 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 3. Queue={}
20:12:12.914 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 72ms/165ms.
20:12:12.915 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 2
20:12:12.915 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 01 BB
20:12:12.915 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 01 BB
20:12:12.917 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 93 16 01 02 02 01 33
20:12:12.919 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:12:12.919 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 01 41 93 16 01 02 02 01 33
20:12:12.920 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 01 41 93 16 01 02 02 01 33
20:12:12.921 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=IdentifyNode[0x41], type=Response[0x01], priorit y=High, dest=255, callback=0, payload=93 16 01 02 02 01
20:12:12.928 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: ProtocolInfo
20:12:12.930 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Listening = true
20:12:12.932 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Routing = false
20:12:12.933 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Beaming = true
20:12:12.934 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Version = 4
20:12:12.935 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: FLIRS = false
20:12:12.936 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Security = false
20:12:12.937 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Max Baud = 40000
20:12:12.937 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Basic = Static Controller
20:12:12.938 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Generic = Static Controller
20:12:12.941 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Specific = PC Controller
20:12:12.942 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class NO_OPERATION
20:12:12.943 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class NO_OPERATION, endpoint null created
20:12:12.946 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Version = 1, version set. Enabling extra functionality.
20:12:12.947 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class BASIC
20:12:12.948 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class BASIC, endpoint null created
20:12:12.950 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=IdentifyNode [0x41], type=Request[0x00], priority=High, dest=255, callback=0, payload=01
20:12:12.953 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=IdentifyNode [0x41], type=Response[0x01], priority=High, dest=255, callback=0, payload=93 16 01 02 02 01
20:12:12.955 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:984dd667:node2:sc ene_number
20:12:12.959 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising poll channel zwave:device:984dd667:node2:s cene_number
20:12:12.961 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:984dd667:node2: scene_number
20:12:12.963 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising channel zwave:device:984dd667:node2:sensor _binary
20:12:12.965 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=IdentifyNode, callback id= 0, expected=IdentifyNode, cancelled=false transaction complete!
20:12:12.965 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
20:12:12.965 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - EMPTYNODE: Transaction complete (Identi fyNode:Request) success(true)
20:12:12.965 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - checking initialisation queue. Queue si ze 1.
20:12:12.966 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - message removed from queue. Queue size 0.
20:12:12.966 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - EMPTYNODE: queue length(0), free to sen d(true)
20:12:12.973 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:984dd667:node2:se nsor_binary
20:12:12.975 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising poll channel zwave:device:984dd667:node2:s ensor_binary
20:12:12.975 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:984dd667:node2: sensor_binary
20:12:12.976 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising channel zwave:device:984dd667:node2:sensor temperature
20:12:12.976 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Initialisation retry timer started 5000
20:12:12.977 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: loop - EMPTYNODE try 1: stageAdvanced(fa lse)
20:12:12.977 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: Initialisation starting
20:12:12.978 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to PROTOINFO
20:12:12.978 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
20:12:12.988 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: loop - PROTOINFO try 0: stageAdvanced(tr ue)
20:12:12.988 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to INIT_NEIGHBORS
20:12:12.990 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
20:12:12.993 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:984dd667:node2:se nsor_temperature
20:12:12.994 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: loop - INIT_NEIGHBORS try 0: stageAdvanc ed(true)
20:12:12.996 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: INIT_NEIGHBORS - send RoutingInfo
20:12:12.997 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 1: Request routing info
20:12:12.997 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising poll channel zwave:device:984dd667:node2:s ensor_temperature
20:12:12.998 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:984dd667:node2: sensor_temperature
20:12:13.000 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - queued packet. Queue length is 1
20:12:13.001 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising channel zwave:device:984dd667:node2:sensor door
20:12:13.003 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 3. Queue={}
20:12:13.006 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 89ms/165ms.
20:12:13.006 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 2
20:12:13.006 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 01 BB
20:12:13.007 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 01 BB
20:12:13.007 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:984dd667:node2:se nsor_door
20:12:13.009 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 93 16 01 02 02 01 33
20:12:13.009 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising poll channel zwave:device:984dd667:node2:s ensor_door
20:12:13.009 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:984dd667:node2: sensor_door
20:12:13.010 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising channel zwave:device:984dd667:node2:alarm tamper
20:12:13.010 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:12:13.010 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 01 41 93 16 01 02 02 01 33
20:12:13.011 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 01 41 93 16 01 02 02 01 33
20:12:13.013 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=IdentifyNode[0x41], type=Response[0x01], priorit y=High, dest=255, callback=0, payload=93 16 01 02 02 01
20:12:13.014 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: ProtocolInfo
20:12:13.014 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Listening = true
20:12:13.022 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Routing = false
20:12:13.022 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Beaming = true
20:12:13.023 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Version = 4
20:12:13.023 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: FLIRS = false
20:12:13.025 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Security = false
20:12:13.025 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Max Baud = 40000
20:12:13.026 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Basic = Static Controller
20:12:13.026 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Generic = Static Controller
20:12:13.027 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:984dd667:node2:al arm_tamper
20:12:13.028 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising poll channel zwave:device:984dd667:node2:a larm_tamper
20:12:13.029 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:984dd667:node2: alarm_tamper
20:12:13.029 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising channel zwave:device:984dd667:node2:batter y-level
20:12:13.030 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:984dd667:node2:ba ttery-level
20:12:13.031 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising poll channel zwave:device:984dd667:node2:b attery-level
20:12:13.031 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:984dd667:node2: battery-level
20:12:13.031 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising channel zwave:device:984dd667:node2:alarm general
20:12:13.034 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Specific = PC Controller
20:12:13.035 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class NO_OPERATION
20:12:13.035 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class NO_OPERATION, endpoint null created
20:12:13.036 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Version = 1, version set. Enabling extra functionality.
20:12:13.036 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:984dd667:node2:al arm_general
20:12:13.037 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising poll channel zwave:device:984dd667:node2:a larm_general
20:12:13.040 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:984dd667:node2: alarm_general
20:12:13.038 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class BASIC
20:12:13.041 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class BASIC, endpoint null created
20:12:13.042 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=IdentifyNode [0x41], type=Request[0x00], priority=High, dest=255, callback=0, payload=01
20:12:13.045 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=IdentifyNode [0x41], type=Response[0x01], priority=High, dest=255, callback=0, payload=93 16 01 02 02 01
20:12:13.046 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=IdentifyNode, callback id= 0, expected=IdentifyNode, cancelled=false transaction complete!
20:12:13.046 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
20:12:13.048 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - INIT_NEIGHBORS: Transaction complete (I dentifyNode:Request) success(true)
20:12:13.049 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - checking initialisation queue. Queue si ze 1.
20:12:13.048 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling intialised at 1800 seconds - start in 1800000 m illiseconds.
20:12:13.052 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 45ms/165ms.
20:12:13.052 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 1
20:12:13.053 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 80 02 00 00 03 79
20:12:13.053 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 07 00 80 02 00 00 03 79
20:12:13.058 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 20 01 80 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 5F
20:12:13.059 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:12:13.060 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 20 01 80 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 5F
20:12:13.060 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 20 01 80 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 5F
20:12:13.063 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=GetRoutingInfo[0x80], type=Response[0x01], prior ity=High, dest=255, callback=0, payload=01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0 0
20:12:13.064 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 2: Got NodeRoutingInfo request.
20:12:13.067 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 2: Neighbor nodes: 1
20:12:13.074 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveNetworkEvent
20:12:13.078 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveNetworkEvent
20:12:13.081 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=GetRoutingIn fo[0x80], type=Request[0x00], priority=High, dest=255, callback=0, payload=02 00 00 03
20:12:13.087 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=GetRoutingIn fo[0x80], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0 0 00 00 00 00 00 00 00 00 00 00 00 00
20:12:13.088 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=GetRoutingInfo, callback i d=0, expected=GetRoutingInfo, cancelled=false transaction complete!
20:12:13.091 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent

groobie · February 13, 2017, 7:44pm

20:12:13.092 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - INIT_NEIGHBORS: Transaction complete (G etRoutingInfo:Request) success(true)
20:12:13.095 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - checking initialisation queue. Queue si ze 1.
20:12:13.097 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - message removed from queue. Queue size 0.
20:12:13.100 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - INIT_NEIGHBORS: queue length(0), free t o send(true)
20:12:13.102 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - INIT_NEIGHBORS try 1: stageAdvanc ed(false)
20:12:13.103 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - advancing to FAILED_CHECK
20:12:13.106 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
20:12:13.107 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveInitializationSt ateEvent
20:12:13.114 [INFO ] [me.event.ThingStatusInfoChangedEvent] - ‘zwave:device:984dd667:node2’ changed from ONLINE: Node initial ising: INIT_NEIGHBORS to ONLINE: Node initialising: FAILED_CHECK
20:12:13.115 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - FAILED_CHECK try 0: stageAdvanced (true)
20:12:13.116 [DEBUG] [rialmessage.IsFailedNodeMessageClass] - NODE 2: Requesting IsFailedNode status from controller.
20:12:13.121 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - queued packet. Queue length is 1
20:12:13.123 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 2. Queue={}

20:12:13.125 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 72ms/165ms.
20:12:13.126 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 1
20:12:13.126 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 80 01 00 00 03 7A
20:12:13.126 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 07 00 80 01 00 00 03 7A
20:12:13.131 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 20 01 80 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 5C
20:12:13.135 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:12:13.136 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 20 01 80 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 5C
20:12:13.137 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 20 01 80 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 5C
20:12:13.139 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=GetRoutingInfo[0x80], type=Response[0x01], prior ity=High, dest=255, callback=0, payload=02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0 0
20:12:13.143 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 1: Got NodeRoutingInfo request.
20:12:13.145 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 1: Neighbor nodes: 2
20:12:13.147 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveNetworkEvent
20:12:13.149 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=GetRoutingIn fo[0x80], type=Request[0x00], priority=High, dest=255, callback=0, payload=01 00 00 03
20:12:13.153 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=GetRoutingIn fo[0x80], type=Response[0x01], priority=High, dest=255, callback=0, payload=02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0 0 00 00 00 00 00 00 00 00 00 00 00 00
20:12:13.157 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=GetRoutingInfo, callback i d=0, expected=GetRoutingInfo, cancelled=false transaction complete!
20:12:13.159 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
20:12:13.162 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - INIT_NEIGHBORS: Transaction complete (G etRoutingInfo:Request) success(true)
20:12:13.163 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - checking initialisation queue. Queue si ze 1.
20:12:13.165 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - message removed from queue. Queue size 0.
20:12:13.167 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - INIT_NEIGHBORS: queue length(0), free t o send(true)
20:12:13.169 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Initialisation retry timer started 5000
20:12:13.171 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: loop - INIT_NEIGHBORS try 1: stageAdvanc ed(false)
20:12:13.174 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to FAILED_CHECK
20:12:13.175 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
20:12:13.178 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: loop - FAILED_CHECK try 0: stageAdvanced (true)
20:12:13.179 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: FAILED_CHECK - Controller - terminating initialisation
20:12:13.181 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: loop - DONE try 0: stageAdvanced(true)
20:12:13.185 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 1: Serializing to file /volume1/@appstore/openHAB2/userdat a/zwave/node1.xml
20:12:13.294 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: Initialisation complete!
20:12:13.296 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
20:12:13.299 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 171ms/171ms.
20:12:13.299 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
20:12:13.299 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 62 02 9B
20:12:13.299 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 62 02 9B
20:12:13.301 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 62 00 98
20:12:13.302 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:12:13.303 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 62 00 98
20:12:13.304 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 62 00 98
20:12:13.304 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=IsFailedNodeID[0x62], type=Response[0x01], prior ity=High, dest=255, callback=0, payload=00
20:12:13.307 [DEBUG] [rialmessage.IsFailedNodeMessageClass] - NODE 2: Is currently marked as healthy by the controller
20:12:13.309 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=IsFailedNode ID[0x62], type=Request[0x00], priority=High, dest=255, callback=0, payload=02
20:12:13.311 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=IsFailedNode ID[0x62], type=Response[0x01], priority=High, dest=255, callback=0, payload=00
20:12:13.312 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=IsFailedNodeID, callback i d=0, expected=IsFailedNodeID, cancelled=false transaction complete!
20:12:13.313 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
20:12:13.315 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - FAILED_CHECK: Transaction complete (IsF ailedNodeID:Request) success(true)
20:12:13.317 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - checking initialisation queue. Queue si ze 1.
20:12:13.319 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - message removed from queue. Queue size 0.
20:12:13.320 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - FAILED_CHECK: queue length(0), free to send(true)
20:12:13.324 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - FAILED_CHECK try 1: stageAdvanced (false)
20:12:13.325 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - advancing to WAIT
20:12:13.328 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
20:12:13.329 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveInitializationSt ateEvent
20:12:13.338 [INFO ] [me.event.ThingStatusInfoChangedEvent] - ‘zwave:device:984dd667:node2’ changed from ONLINE: Node initial ising: FAILED_CHECK to ONLINE: Node initialising: WAIT
20:12:13.338 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - WAIT try 0: stageAdvanced(true)
20:12:13.342 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: WAIT - Listening=false, FrequentlyListen ing=false
20:12:13.344 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: WAIT - Still waiting!
20:12:13.346 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 46ms/171ms.
20:12:52.505 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
20:12:52.507 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:12:52.507 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
20:12:52.508 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
20:12:52.508 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
20:12:52.513 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update request. Node information received.
20:12:52.515 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Node is ALIVE. Init stage is WAIT.
20:12:52.517 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveNodeStatusEvent
20:12:52.518 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Status event during initialisation - Node is ALIVE
20:12:52.519 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - WAIT: queue length(0), free to send(true)
20:12:52.520 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - WAIT try 1: stageAdvanced(false)
20:12:52.520 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: WAIT - Listening=false, FrequentlyListening=false
20:12:52.521 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: WAIT - Still waiting!
20:12:52.522 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveNodeStatusEvent
20:12:52.522 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Setting ONLINE
20:12:52.527 [INFO ] [me.event.ThingStatusInfoChangedEvent] - ‘zwave:device:984dd667:node2’ changed from ONLINE: Node initialising: WAIT to ONLINE
20:12:52.527 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 2: Node Status event - Node is ALIVE
20:12:52.529 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class ZWAVE_PLUS_INFO
20:12:52.530 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class ZWAVE_PLUS_INFO, endpoint null created
20:12:52.531 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class ZWAVE_PLUS_INFO.
20:12:52.532 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class ZWAVE_PLUS_INFO to the list of supported command classes.
20:12:52.532 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class ASSOCIATION_GROUP_INFO
20:12:52.534 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class ASSOCIATION_GROUP_INFO, endpoint null created
20:12:52.535 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class ASSOCIATION_GROUP_INFO.
20:12:52.535 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class ASSOCIATION_GROUP_INFO to the list of supported command classes.
20:12:52.536 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class APPLICATION_STATUS
20:12:52.536 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class APPLICATION_STATUS, endpoint null created
20:12:52.537 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class APPLICATION_STATUS.
20:12:52.538 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class APPLICATION_STATUS to the list of supported command classes.
20:12:52.539 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class BATTERY
20:12:52.539 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class BATTERY, endpoint null created
20:12:52.540 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class BATTERY.
20:12:52.541 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class BATTERY to the list of supported command classes.
20:12:52.541 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class CRC_16_ENCAP
20:12:52.542 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class CRC_16_ENCAP, endpoint null created
20:12:52.543 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class CRC_16_ENCAP.
20:12:52.545 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class CRC_16_ENCAP to the list of supported command classes.
20:12:52.546 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class FIRMWARE_UPDATE_MD
20:12:52.547 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class FIRMWARE_UPDATE_MD, endpoint null created
20:12:52.547 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class FIRMWARE_UPDATE_MD.
20:12:52.548 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class FIRMWARE_UPDATE_MD to the list of supported command classes.
20:12:52.549 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class MANUFACTURER_SPECIFIC
20:12:52.549 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class MANUFACTURER_SPECIFIC, endpoint null created
20:12:52.550 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class MANUFACTURER_SPECIFIC.
20:12:52.551 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class MANUFACTURER_SPECIFIC to the list of supported command classes.
20:12:52.551 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class POWERLEVEL
20:12:52.552 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class POWERLEVEL, endpoint null created
20:12:52.553 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class POWERLEVEL.
20:12:52.553 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class POWERLEVEL to the list of supported command classes.
20:12:52.554 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class SECURITY
20:12:52.555 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class SECURITY, endpoint null created
20:12:52.559 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: setupNetworkKey useSchemeZero=false
20:12:52.564 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class SECURITY.
20:12:52.565 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class SECURITY to the list of supported command classes.
20:12:52.565 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveSecurityCommandClassWithInitialization@44712b5d already registered
20:12:52.566 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class VERSION
20:12:52.567 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class VERSION, endpoint null created
20:12:52.568 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update is adding command class VERSION.
20:12:52.568 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class VERSION to the list of supported command classes.
20:12:52.569 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=IsFailedNodeID[0x62], type=Request[0x00], priority=High, dest=255, callback=0, payload=02
20:12:52.570 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
20:12:52.571 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationUpdate, callback id=0, expected=IsFailedNodeID, cancelled=false MISMATCH
20:13:11.429 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
20:13:11.431 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:13:11.432 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
20:13:11.432 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
20:13:11.433 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
20:13:11.433 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update request. Node information received.
20:13:11.433 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=IsFailedNodeID[0x62], type=Request[0x00], priority=High, dest=255, callback=0, payload=02
20:13:11.434 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
20:13:11.434 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationUpdate, callback id=0, expected=IsFailedNodeID, cancelled=false MISMATCH
20:13:17.929 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
20:13:17.931 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
20:13:17.931 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
20:13:17.932 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 13 00 49 84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86 BA
20:13:17.932 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
20:13:17.933 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update request. Node information received.
20:13:17.933 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=IsFailedNodeID[0x62], type=Request[0x00], priority=High, dest=255, callback=0, payload=02
20:13:17.933 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 02 0D 04 07 01 5E 59 22 80 56 7A 72 73 98 86
20:13:17.934 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationUpdate, callback id=0, expected=IsFailedNodeID, cancelled=false MISMATCH
20:14:16.535 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - ZWave product zwave:serial_zstick has no references!