Aeotec ZW130 Wall Switch not saving configuration

prokhor · April 25, 2021, 5:05am

Hello,

Recently added an Aeotec ZW130 Wall Switch. I included it successfully, and can operate a few lights via rules based on the Scene Number channel, but does not seem like the configuration saves to the wall switch device.

In particular, cannot turn off the beep (by setting config_1_1 to 0) or change the light colors. This makes me suspect that the z-wave associations are also not saving (they do not work, but not certain if this is the reason why).

Running milestone (3.1.0.M3) via openhabian on a pi4.

Below is the log when I try to save the configuration from the openhab thing UI. In the log, the ZW130 switch is node 29 (configuration save is right near the end).

2021-04-24 21:48:01.970 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 17: Got a value event from Z-Wave network, endpoint=2, command class=COMMAND_CLASS_ALARM, value=255
2021-04-24 21:48:01.970 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 17: Alarm converter processing NOTIFICATION
2021-04-24 21:48:01.971 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 17: Alarm converter NOTIFICATION event is 0, type OnOffType
2021-04-24 21:48:01.972 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 17: Updating channel state zwave:device:c3f88d21c6:node17:alarm_motion2 to OFF [OnOffType]
2021-04-24 21:48:01.973 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 17: Commands processed 1.
2021-04-24 21:48:01.973 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 17: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1f9248c.
2021-04-24 21:48:01.974 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2021-04-24 21:48:01.975 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2021-04-24 21:48:01.975 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 21:48:01.976 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-04-24 21:48:53.901 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 12 02 98 40 3B 
2021-04-24 21:48:53.903 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=18, callback=0, payload=00 12 02 98 40 
2021-04-24 21:48:53.904 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=18, callback=0, payload=00 12 02 98 40 
2021-04-24 21:48:53.905 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2021-04-24 21:48:53.905 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Application Command Request (ALIVE:REQUEST_NIF)
2021-04-24 21:48:53.906 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 18: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0
2021-04-24 21:48:53.906 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 18: SECURITY check internal
2021-04-24 21:48:53.907 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 18: Received COMMAND_CLASS_SECURITY V0 SECURITY_NONCE_GET
2021-04-24 21:48:53.907 [DEBUG] [andclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_REPORT version 1
2021-04-24 21:48:53.909 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Added to secure queue - size 1
2021-04-24 21:48:53.910 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Commands processed 1.
2021-04-24 21:48:53.911 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@e3baca.
2021-04-24 21:48:53.911 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2021-04-24 21:48:53.912 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2021-04-24 21:48:53.912 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 21:48:53.913 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-04-24 21:48:53.914 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 11 00 13 12 0A 98 80 94 7B 74 2D 5D F7 F5 B1 25 71 F1 
2021-04-24 21:48:53.916 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 18: Sending REQUEST Message = 01 11 00 13 12 0A 98 80 94 7B 74 2D 5D F7 F5 B1 25 71 F1 
2021-04-24 21:48:53.917 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2021-04-24 21:48:53.917 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 5106: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 113
2021-04-24 21:48:53.918 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2021-04-24 21:48:53.919 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-04-24 21:48:53.920 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-04-24 21:48:53.921 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5106: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 113
2021-04-24 21:48:53.921 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2021-04-24 21:48:53.922 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 21:48:53.922 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-04-24 21:48:53.925 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2021-04-24 21:48:53.926 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2021-04-24 21:48:53.926 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2021-04-24 21:48:53.926 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5106: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 113
2021-04-24 21:48:53.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2021-04-24 21:48:53.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 5106: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 113
2021-04-24 21:48:53.927 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2021-04-24 21:48:53.928 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 18: sentData successfully placed on stack.
2021-04-24 21:48:53.929 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 5106: Advanced to WAIT_REQUEST
2021-04-24 21:48:53.929 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: TID 5106: Transaction not completed
2021-04-24 21:48:53.929 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 21:48:53.930 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-04-24 21:48:53.942 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 71 00 00 02 98 
2021-04-24 21:48:53.943 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=113, payload=71 00 00 02 
2021-04-24 21:48:53.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=113, payload=71 00 00 02 
2021-04-24 21:48:53.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5106: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 113
2021-04-24 21:48:53.945 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2021-04-24 21:48:53.945 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 5106: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 113
2021-04-24 21:48:53.945 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 5106: (Callback 113)
2021-04-24 21:48:53.946 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2021-04-24 21:48:53.947 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 5106: callback 113
2021-04-24 21:48:53.947 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=113, payload=71 00 00 02 
2021-04-24 21:48:53.948 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 18: SendData Request. CallBack ID = 113, Status = Transmission complete and ACK received(0)
2021-04-24 21:48:53.949 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 5106: Transaction COMPLETED
2021-04-24 21:48:53.950 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Response processed after 33ms
2021-04-24 21:48:53.950 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: TID 5106: Transaction completed
2021-04-24 21:48:53.950 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: notifyTransactionResponse TID:5106 DONE
2021-04-24 21:48:53.951 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2021-04-24 21:48:53.952 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 21:48:53.953 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-04-24 21:48:53.959 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1C 00 04 00 12 16 98 81 BC 40 82 60 D6 30 1F EA 93 ED 64 94 EF B8 07 C5 D1 3C 3B 02 38 
2021-04-24 21:48:53.960 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=18, callback=0, payload=00 12 16 98 81 BC 40 82 60 D6 30 1F EA 93 ED 64 94 EF B8 07 C5 D1 3C 3B 02 
2021-04-24 21:48:53.961 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=18, callback=0, payload=00 12 16 98 81 BC 40 82 60 D6 30 1F EA 93 ED 64 94 EF B8 07 C5 D1 3C 3B 02 
2021-04-24 21:48:53.962 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2021-04-24 21:48:53.962 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Application Command Request (ALIVE:REQUEST_NIF)
2021-04-24 21:48:53.963 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 18: Decapsulating COMMAND_CLASS_SECURITY
2021-04-24 21:48:53.963 [ERROR] [mmandclass.ZWaveSecurityCommandClass] - NODE 18: Error decapsulating security message
java.security.InvalidKeyException: No installed provider supports this key: (null)
	at javax.crypto.Cipher.chooseProvider(Cipher.java:930) ~[?:?]
	at javax.crypto.Cipher.init(Cipher.java:1286) ~[?:?]
	at javax.crypto.Cipher.init(Cipher.java:1223) ~[?:?]
	at org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveSecurityCommandClass.generateMAC(ZWaveSecurityCommandClass.java:528) ~[bundleFile:?]
	at org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveSecurityCommandClass.getSecurityMessageDecapsulation(ZWaveSecurityCommandClass.java:319) [bundleFile:?]
	at org.openhab.binding.zwave.internal.protocol.ZWaveNode.processCommand(ZWaveNode.java:1238) [bundleFile:?]
	at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager$ZWaveReceiveThread.run(ZWaveTransactionManager.java:532) [bundleFile:?]
2021-04-24 21:48:53.966 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 21:48:53.967 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-04-24 21:49:13.482 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 13 00 04 00 11 0D 60 0D 02 01 71 05 00 00 00 FF 07 08 00 1E 
2021-04-24 21:49:13.484 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 0D 60 0D 02 01 71 05 00 00 00 FF 07 08 00 
2021-04-24 21:49:13.485 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 0D 60 0D 02 01 71 05 00 00 00 FF 07 08 00 
2021-04-24 21:49:13.486 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2021-04-24 21:49:13.486 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 17: Application Command Request (ALIVE:DONE)
2021-04-24 21:49:13.487 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 17: resetResendCount initComplete=true isDead=false
2021-04-24 21:49:13.488 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 17: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2021-04-24 21:49:13.488 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 17: Incoming command class COMMAND_CLASS_ALARM, endpoint 2
2021-04-24 21:49:13.489 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY not supported
2021-04-24 21:49:13.489 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 17: Received COMMAND_CLASS_ALARM V4 NOTIFICATION_REPORT
2021-04-24 21:49:13.490 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 17: NOTIFICATION report - 0 = 0, event=8, status=255, plen=0
2021-04-24 21:49:13.490 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 17: Alarm Type = BURGLAR (0)
2021-04-24 21:49:13.491 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 17: Got an event from Z-Wave network: ZWaveAlarmValueEvent
2021-04-24 21:49:13.491 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 17: Got a value event from Z-Wave network, endpoint=2, command class=COMMAND_CLASS_ALARM, value=255
2021-04-24 21:49:13.492 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 17: Alarm converter processing NOTIFICATION
2021-04-24 21:49:13.493 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 17: Alarm converter NOTIFICATION event is 8, type OnOffType
2021-04-24 21:49:13.493 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 17: Updating channel state zwave:device:c3f88d21c6:node17:alarm_motion2 to ON [OnOffType]
2021-04-24 21:49:13.495 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 17: Commands processed 1.
2021-04-24 21:49:13.496 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 17: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@16e8684.
2021-04-24 21:49:13.496 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2021-04-24 21:49:13.497 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2021-04-24 21:49:13.498 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 21:49:13.498 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-04-24 21:49:35.120 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 13 00 04 00 11 0D 60 0D 02 01 71 05 00 00 00 FF 07 00 00 16 
2021-04-24 21:49:35.122 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 0D 60 0D 02 01 71 05 00 00 00 FF 07 00 00 
2021-04-24 21:49:35.123 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 0D 60 0D 02 01 71 05 00 00 00 FF 07 00 00 
2021-04-24 21:49:35.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2021-04-24 21:49:35.125 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 17: Application Command Request (ALIVE:DONE)
2021-04-24 21:49:35.125 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 17: resetResendCount initComplete=true isDead=false
2021-04-24 21:49:35.125 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 17: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2021-04-24 21:49:35.126 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 17: Incoming command class COMMAND_CLASS_ALARM, endpoint 2
2021-04-24 21:49:35.126 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY not supported
2021-04-24 21:49:35.127 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 17: Received COMMAND_CLASS_ALARM V4 NOTIFICATION_REPORT
2021-04-24 21:49:35.127 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 17: NOTIFICATION report - 0 = 0, event=0, status=255, plen=0
2021-04-24 21:49:35.128 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 17: Alarm Type = BURGLAR (0)
2021-04-24 21:49:35.128 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 17: Got an event from Z-Wave network: ZWaveAlarmValueEvent
2021-04-24 21:49:35.129 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 17: Got a value event from Z-Wave network, endpoint=2, command class=COMMAND_CLASS_ALARM, value=255
2021-04-24 21:49:35.129 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 17: Alarm converter processing NOTIFICATION
2021-04-24 21:49:35.130 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 17: Alarm converter NOTIFICATION event is 0, type OnOffType
2021-04-24 21:49:35.130 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 17: Updating channel state zwave:device:c3f88d21c6:node17:alarm_motion2 to OFF [OnOffType]
2021-04-24 21:49:35.132 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 17: Commands processed 1.
2021-04-24 21:49:35.133 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 17: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@6bcb5c.
2021-04-24 21:49:35.134 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2021-04-24 21:49:35.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2021-04-24 21:49:35.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 21:49:35.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-04-24 21:50:00.618 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 0E 02 84 07 7C 
2021-04-24 21:50:00.619 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=14, callback=0, payload=00 0E 02 84 07 
2021-04-24 21:50:00.621 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=14, callback=0, payload=00 0E 02 84 07 
2021-04-24 21:50:00.621 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2021-04-24 21:50:00.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Application Command Request (ALIVE:DONE)
2021-04-24 21:50:00.622 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: resetResendCount initComplete=true isDead=false
2021-04-24 21:50:00.623 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: Is awake with 0 messages in the queue
2021-04-24 21:50:00.624 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: Start sleep timer at 1000ms
2021-04-24 21:50:00.625 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2021-04-24 21:50:00.630 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 14: Node Status event - Node is AWAKE
2021-04-24 21:50:00.631 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Commands processed 1.
2021-04-24 21:50:00.631 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@ac41d9.
2021-04-24 21:50:00.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2021-04-24 21:50:00.634 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2021-04-24 21:50:00.635 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 21:50:00.635 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-04-24 21:50:01.125 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: WakeupTimerTask 0 Messages waiting, state DONE
2021-04-24 21:50:01.625 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: WakeupTimerTask 0 Messages waiting, state DONE
2021-04-24 21:50:01.626 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: No more messages, go back to sleep
2021-04-24 21:50:01.627 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 14: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
2021-04-24 21:50:01.628 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: SECURITY not supported
2021-04-24 21:50:01.630 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: Command Class COMMAND_CLASS_WAKE_UP is NOT required to be secured
2021-04-24 21:50:01.631 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@e54574
2021-04-24 21:50:01.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Bump transaction 5107 priority from Immediate to Immediate
2021-04-24 21:50:01.635 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Adding to device queue
2021-04-24 21:50:01.637 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Added 5107 to queue - size 13
2021-04-24 21:50:01.637 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-04-24 21:50:01.638 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 0E 02 84 08 25 72 32 
2021-04-24 21:50:01.639 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 14: Sending REQUEST Message = 01 09 00 13 0E 02 84 08 25 72 32 
2021-04-24 21:50:01.640 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2021-04-24 21:50:01.641 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 5107: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 114
2021-04-24 21:50:01.641 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2021-04-24 21:50:01.642 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-04-24 21:50:01.643 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-04-24 21:50:01.643 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5107: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 114
2021-04-24 21:50:01.644 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2021-04-24 21:50:01.644 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 21:50:01.645 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-04-24 21:50:01.647 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2021-04-24 21:50:01.648 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2021-04-24 21:50:01.649 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2021-04-24 21:50:01.649 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5107: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 114
2021-04-24 21:50:01.649 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2021-04-24 21:50:01.650 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 5107: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 114
2021-04-24 21:50:01.650 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2021-04-24 21:50:01.651 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 14: sentData successfully placed on stack.
2021-04-24 21:50:01.651 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 5107: Advanced to WAIT_REQUEST
2021-04-24 21:50:01.651 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: TID 5107: Transaction not completed
2021-04-24 21:50:01.652 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 21:50:01.652 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-04-24 21:50:01.664 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 72 00 00 03 9A 
2021-04-24 21:50:01.665 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=114, payload=72 00 00 03 
2021-04-24 21:50:01.666 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=114, payload=72 00 00 03 
2021-04-24 21:50:01.666 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5107: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 114
2021-04-24 21:50:01.667 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2021-04-24 21:50:01.667 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 5107: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 114
2021-04-24 21:50:01.667 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 5107: (Callback 114)
2021-04-24 21:50:01.668 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2021-04-24 21:50:01.668 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 5107: callback 114
2021-04-24 21:50:01.668 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=114, payload=72 00 00 03 
2021-04-24 21:50:01.669 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 14: SendData Request. CallBack ID = 114, Status = Transmission complete and ACK received(0)
2021-04-24 21:50:01.669 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: resetResendCount initComplete=true isDead=false
2021-04-24 21:50:01.670 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 5107: Transaction COMPLETED
2021-04-24 21:50:01.670 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Response processed after 29ms
2021-04-24 21:50:01.670 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: TID 5107: Transaction completed
2021-04-24 21:50:01.671 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: notifyTransactionResponse TID:5107 DONE
2021-04-24 21:50:01.671 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2021-04-24 21:50:01.672 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 5107: Transaction event listener: DONE: DONE -> 
2021-04-24 21:50:01.672 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 21:50:01.672 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-04-24 21:50:01.675 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: Went to sleep COMPLETE
2021-04-24 21:50:53.609 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update received
2021-04-24 21:50:53.630 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored binding_cmdrepollperiod to 15000 (BigDecimal)
2021-04-24 21:50:53.631 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored group_8 to [node_30] (ArrayList)
2021-04-24 21:50:53.632 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored group_4 to [node_27] (ArrayList)
2021-04-24 21:50:53.632 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored wakeup_interval to 3600.0 (BigDecimal)
2021-04-24 21:50:53.633 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored config_255_4_wo to 0 (BigDecimal)
2021-04-24 21:50:53.633 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored group_1 to controller (String)
2021-04-24 21:50:53.634 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored group_2 to [node_21, node_22] (ArrayList)
2021-04-24 21:50:53.634 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update set config_1_1 to 1 (BigDecimal)
2021-04-24 21:50:53.634 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Error getting configurationCommandClass
2021-04-24 21:50:53.635 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored config_2_1 to 1 (BigDecimal)
2021-04-24 21:50:53.635 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored wakeup_node to 1.0 (BigDecimal)
2021-04-24 21:50:53.636 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored config_5_4 to 9145088 (BigDecimal)
2021-04-24 21:50:53.636 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored config_39_1 to 20 (BigDecimal)
2021-04-24 21:50:53.636 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored config_3_1 to 1 (BigDecimal)
2021-04-24 21:50:53.637 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored config_4_1 to 1 (BigDecimal)
2021-04-24 21:50:53.637 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored node_id to 29 (BigDecimal)
2021-04-24 21:51:20.446 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update received
2021-04-24 21:51:20.448 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored binding_cmdrepollperiod to 15000 (BigDecimal)
2021-04-24 21:51:20.448 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored group_8 to [node_30] (ArrayList)
2021-04-24 21:51:20.449 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored group_4 to [node_27] (ArrayList)
2021-04-24 21:51:20.450 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored wakeup_interval to 3600.0 (BigDecimal)
2021-04-24 21:51:20.450 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored config_255_4_wo to 0 (BigDecimal)
2021-04-24 21:51:20.451 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored group_1 to controller (String)
2021-04-24 21:51:20.451 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored group_2 to [node_21, node_22] (ArrayList)
2021-04-24 21:51:20.452 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored config_1_1 to 0 (BigDecimal)
2021-04-24 21:51:20.452 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored config_2_1 to 1 (BigDecimal)
2021-04-24 21:51:20.453 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored wakeup_node to 1.0 (BigDecimal)
2021-04-24 21:51:20.453 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored config_5_4 to 9145088 (BigDecimal)
2021-04-24 21:51:20.454 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored config_39_1 to 20 (BigDecimal)
2021-04-24 21:51:20.454 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored config_3_1 to 1 (BigDecimal)
2021-04-24 21:51:20.455 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored config_4_1 to 1 (BigDecimal)
2021-04-24 21:51:20.455 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Configuration update ignored node_id to 29 (BigDecimal)

chris · April 25, 2021, 5:31am

It looks like there might be something wrong with the initialisation of the device. I’d suggest to reinitialise it so that the binding downloads all the device information again…

prokhor · April 25, 2021, 6:02am

Thought it may be helpful to try to get debug logs during a full inclusion; attempted just now but no success yet. Here is the logs. This time it is Node 32.

2021-04-24 22:25:05.706 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=216, payload=D8 02 00 00 
2021-04-24 22:25:05.707 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5264: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 219
2021-04-24 22:25:05.707 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2021-04-24 22:25:05.708 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 5264: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 219
2021-04-24 22:25:05.708 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 5264: (Callback 219)
2021-04-24 22:25:05.709 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - NO callback match! (219 <> 216)
2021-04-24 22:25:05.709 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=216, payload=D8 02 00 00 
2021-04-24 22:25:05.710 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: New node found.
2021-04-24 22:25:05.710 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 22:25:05.711 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-04-24 22:25:05.955 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1C 00 4A D8 03 20 15 04 18 01 5E 85 59 8E 60 86 70 72 5A 73 84 80 5B 71 7A EF 25 26 23 
2021-04-24 22:25:05.958 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=3, callback=216, payload=D8 03 20 15 04 18 01 5E 85 59 8E 60 86 70 72 5A 73 84 80 5B 71 7A EF 25 26 
2021-04-24 22:25:05.959 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=3, callback=216, payload=D8 03 20 15 04 18 01 5E 85 59 8E 60 86 70 72 5A 73 84 80 5B 71 7A EF 25 26 
2021-04-24 22:25:05.960 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5264: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 219
2021-04-24 22:25:05.960 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2021-04-24 22:25:05.961 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 5264: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 219
2021-04-24 22:25:05.962 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 5264: (Callback 219)
2021-04-24 22:25:05.962 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - NO callback match! (219 <> 216)
2021-04-24 22:25:05.963 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=3, callback=216, payload=D8 03 20 15 04 18 01 5E 85 59 8E 60 86 70 72 5A 73 84 80 5B 71 7A EF 25 26 
2021-04-24 22:25:05.964 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - NODE 32: Adding slave.
2021-04-24 22:25:05.964 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeStart, new event IncludeSlaveFound
2021-04-24 22:25:05.966 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Including node.
2021-04-24 22:25:05.967 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 22:25:05.967 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-04-24 22:25:05.993 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 DB 01 00 C2 F3 
2021-04-24 22:25:05.994 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=219, payload=DB 01 00 C2 
2021-04-24 22:25:05.995 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=219, payload=DB 01 00 C2 
2021-04-24 22:25:05.995 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5264: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 219
2021-04-24 22:25:05.996 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2021-04-24 22:25:05.996 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 5264: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 219
2021-04-24 22:25:05.996 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 5264: (Callback 219)
2021-04-24 22:25:05.997 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2021-04-24 22:25:05.997 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 5264: callback 219
2021-04-24 22:25:05.998 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=219, payload=DB 01 00 C2 
2021-04-24 22:25:05.998 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 26: SendData Request. CallBack ID = 219, Status = Transmission complete, no ACK received(1)
2021-04-24 22:25:05.999 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 5264: Transaction CANCELLED
2021-04-24 22:25:05.999 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 26: Retry count exceeded. Discarding message: TID 5264: [CANCELLED] priority=Poll, requiresResponse=true, callback: 219
2021-04-24 22:25:05.999 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 26: TID 5264: Transaction completed
2021-04-24 22:25:06.000 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 26: notifyTransactionResponse TID:5264 CANCELLED
2021-04-24 22:25:06.001 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 22:25:06.001 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 5264: Transaction event listener: DONE: CANCELLED -> 
2021-04-24 22:25:06.001 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-04-24 22:25:06.005 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 26: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@10feaf3
2021-04-24 22:25:06.939 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A D8 05 20 00 4F 
2021-04-24 22:25:06.941 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=5, callback=216, payload=D8 05 20 00 
2021-04-24 22:25:06.943 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=5, callback=216, payload=D8 05 20 00 
2021-04-24 22:25:06.943 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2021-04-24 22:25:06.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
2021-04-24 22:25:06.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null
2021-04-24 22:25:06.945 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=5, callback=216, payload=D8 05 20 00 
2021-04-24 22:25:06.946 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - NODE 32: Add Node: Protocol done.
2021-04-24 22:25:06.946 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSlaveFound, new event IncludeProtocolDone
2021-04-24 22:25:06.947 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2021-04-24 22:25:06.947 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 5265 to queue - size 1
2021-04-24 22:25:06.948 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-04-24 22:25:06.949 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 DC 69 
2021-04-24 22:25:06.950 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 DC 69 
2021-04-24 22:25:06.950 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2021-04-24 22:25:06.951 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2021-04-24 22:25:06.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 5265: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 220
2021-04-24 22:25:06.952 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Inclusion protocol completed.
2021-04-24 22:25:06.952 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-04-24 22:25:06.953 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_NO_OPERATION
2021-04-24 22:25:06.954 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created
2021-04-24 22:25:06.954 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Version = 1, version set. Enabling extra functionality.
2021-04-24 22:25:06.955 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes.
2021-04-24 22:25:06.956 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_BASIC
2021-04-24 22:25:06.956 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_BASIC, endpoint 0 created
2021-04-24 22:25:06.957 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes.
2021-04-24 22:25:06.958 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_ZWAVEPLUS_INFO
2021-04-24 22:25:06.958 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_ZWAVEPLUS_INFO, endpoint 0 created
2021-04-24 22:25:06.959 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Inclusion is adding command class COMMAND_CLASS_ZWAVEPLUS_INFO.
2021-04-24 22:25:06.960 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_ZWAVEPLUS_INFO to the list of supported command classes.
2021-04-24 22:25:06.960 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_ASSOCIATION
2021-04-24 22:25:06.961 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_ASSOCIATION, endpoint 0 created
2021-04-24 22:25:06.962 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Inclusion is adding command class COMMAND_CLASS_ASSOCIATION.
2021-04-24 22:25:06.962 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_ASSOCIATION to the list of supported command classes.
2021-04-24 22:25:06.963 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_ASSOCIATION_GRP_INFO
2021-04-24 22:25:06.963 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_ASSOCIATION_GRP_INFO, endpoint 0 created
2021-04-24 22:25:06.963 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Inclusion is adding command class COMMAND_CLASS_ASSOCIATION_GRP_INFO.
2021-04-24 22:25:06.964 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_ASSOCIATION_GRP_INFO to the list of supported command classes.
2021-04-24 22:25:06.964 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION
2021-04-24 22:25:06.964 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION, endpoint 0 created
2021-04-24 22:25:06.965 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Inclusion is adding command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION.
2021-04-24 22:25:06.965 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION to the list of supported command classes.
2021-04-24 22:25:06.965 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_MULTI_CHANNEL
2021-04-24 22:25:06.966 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_MULTI_CHANNEL, endpoint 0 created
2021-04-24 22:25:06.966 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Inclusion is adding command class COMMAND_CLASS_MULTI_CHANNEL.
2021-04-24 22:25:06.966 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_MULTI_CHANNEL to the list of supported command classes.
2021-04-24 22:25:06.967 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_VERSION
2021-04-24 22:25:06.967 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_VERSION, endpoint 0 created
2021-04-24 22:25:06.967 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Inclusion is adding command class COMMAND_CLASS_VERSION.
2021-04-24 22:25:06.968 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_VERSION to the list of supported command classes.
2021-04-24 22:25:06.968 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_CONFIGURATION
2021-04-24 22:25:06.968 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_CONFIGURATION, endpoint 0 created
2021-04-24 22:25:06.969 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Inclusion is adding command class COMMAND_CLASS_CONFIGURATION.
2021-04-24 22:25:06.969 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_CONFIGURATION to the list of supported command classes.
2021-04-24 22:25:06.969 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_MANUFACTURER_SPECIFIC
2021-04-24 22:25:06.969 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_MANUFACTURER_SPECIFIC, endpoint 0 created
2021-04-24 22:25:06.970 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Inclusion is adding command class COMMAND_CLASS_MANUFACTURER_SPECIFIC.
2021-04-24 22:25:06.970 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_MANUFACTURER_SPECIFIC to the list of supported command classes.
2021-04-24 22:25:06.970 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_DEVICE_RESET_LOCALLY
2021-04-24 22:25:06.971 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_DEVICE_RESET_LOCALLY, endpoint 0 created
2021-04-24 22:25:06.971 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Inclusion is adding command class COMMAND_CLASS_DEVICE_RESET_LOCALLY.
2021-04-24 22:25:06.972 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_DEVICE_RESET_LOCALLY to the list of supported command classes.
2021-04-24 22:25:06.972 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_POWERLEVEL
2021-04-24 22:25:06.972 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_POWERLEVEL, endpoint 0 created
2021-04-24 22:25:06.973 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Inclusion is adding command class COMMAND_CLASS_POWERLEVEL.
2021-04-24 22:25:06.973 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_POWERLEVEL to the list of supported command classes.
2021-04-24 22:25:06.973 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_WAKE_UP
2021-04-24 22:25:06.974 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_WAKE_UP, endpoint 0 created
2021-04-24 22:25:06.974 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Inclusion is adding command class COMMAND_CLASS_WAKE_UP.
2021-04-24 22:25:06.974 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_WAKE_UP to the list of supported command classes.
2021-04-24 22:25:06.974 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_BATTERY
2021-04-24 22:25:06.975 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_BATTERY, endpoint 0 created
2021-04-24 22:25:06.975 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Inclusion is adding command class COMMAND_CLASS_BATTERY.
2021-04-24 22:25:06.975 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_BATTERY to the list of supported command classes.
2021-04-24 22:25:06.976 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_CENTRAL_SCENE
2021-04-24 22:25:06.976 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_CENTRAL_SCENE, endpoint 0 created
2021-04-24 22:25:06.976 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Inclusion is adding command class COMMAND_CLASS_CENTRAL_SCENE.
2021-04-24 22:25:06.977 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_CENTRAL_SCENE to the list of supported command classes.
2021-04-24 22:25:06.977 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_ALARM
2021-04-24 22:25:06.977 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_ALARM, endpoint 0 created
2021-04-24 22:25:06.978 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Inclusion is adding command class COMMAND_CLASS_ALARM.
2021-04-24 22:25:06.978 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_ALARM to the list of supported command classes.
2021-04-24 22:25:06.978 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_FIRMWARE_UPDATE_MD
2021-04-24 22:25:06.979 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_FIRMWARE_UPDATE_MD, endpoint 0 created
2021-04-24 22:25:06.979 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Inclusion is adding command class COMMAND_CLASS_FIRMWARE_UPDATE_MD.
2021-04-24 22:25:06.979 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_FIRMWARE_UPDATE_MD to the list of supported command classes.
2021-04-24 22:25:06.980 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_SWITCH_BINARY
2021-04-24 22:25:06.980 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_SWITCH_BINARY, endpoint 0 created
2021-04-24 22:25:06.981 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Inclusion is adding command class COMMAND_CLASS_SWITCH_BINARY.
2021-04-24 22:25:06.981 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_SWITCH_BINARY to the list of supported command classes.
2021-04-24 22:25:06.981 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_SWITCH_MULTILEVEL
2021-04-24 22:25:06.982 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0 created
2021-04-24 22:25:06.982 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 32: Inclusion is adding command class COMMAND_CLASS_SWITCH_MULTILEVEL.
2021-04-24 22:25:06.983 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_SWITCH_MULTILEVEL to the list of supported command classes.
2021-04-24 22:25:06.983 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 32: ZWaveController include node
2021-04-24 22:25:06.983 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 32: Starting initialisation from INCLUSION_START
2021-04-24 22:25:06.984 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-04-24 22:25:06.984 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 32: Node advancer: Node just included (1137366)
2021-04-24 22:25:06.984 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5265: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 220
2021-04-24 22:25:06.984 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 32: Node advancer - advancing to IDENTIFY_NODE
2021-04-24 22:25:06.985 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2021-04-24 22:25:06.985 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 32: Node advancer: Initialisation starting from inclusion
2021-04-24 22:25:06.985 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 22:25:06.985 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1d806f6
2021-04-24 22:25:06.985 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-04-24 22:25:06.986 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 5266 to queue - size 1
2021-04-24 22:25:06.986 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-04-24 22:25:07.103 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A DC 06 20 00 48 
2021-04-24 22:25:07.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=220, payload=DC 06 20 00 
2021-04-24 22:25:07.106 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=220, payload=DC 06 20 00 
2021-04-24 22:25:07.106 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5265: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 220
2021-04-24 22:25:07.107 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2021-04-24 22:25:07.108 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 5265: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 220
2021-04-24 22:25:07.108 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 5265: (Callback 220)
2021-04-24 22:25:07.109 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2021-04-24 22:25:07.109 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 5265: callback 220
2021-04-24 22:25:07.110 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=220, payload=DC 06 20 00 
2021-04-24 22:25:07.111 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.
2021-04-24 22:25:07.111 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 32: Device discovered
2021-04-24 22:25:07.114 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:c3f88d21c6:node32' to inbox.
2021-04-24 22:25:07.115 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeProtocolDone, new event IncludeDone
2021-04-24 22:25:07.117 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2021-04-24 22:25:07.118 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 5267 to queue - size 2
2021-04-24 22:25:07.119 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-04-24 22:25:07.120 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion
2021-04-24 22:25:07.120 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done
2021-04-24 22:25:07.121 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 5265: Advanced to DONE
2021-04-24 22:25:07.122 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 171ms
2021-04-24 22:25:07.123 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 5265: Transaction completed
2021-04-24 22:25:07.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:5265 DONE
2021-04-24 22:25:07.125 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 22:25:07.126 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-04-24 22:25:07.127 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 20 9A 
2021-04-24 22:25:07.127 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 20 9A 
2021-04-24 22:25:07.128 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2021-04-24 22:25:07.128 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 5266: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2021-04-24 22:25:07.129 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2021-04-24 22:25:07.129 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-04-24 22:25:07.130 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-04-24 22:25:07.130 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5266: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2021-04-24 22:25:07.130 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 53 9C 01 04 18 01 65 
2021-04-24 22:25:07.131 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2021-04-24 22:25:07.131 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 22:25:07.131 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 18 01 
2021-04-24 22:25:07.132 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-04-24 22:25:07.132 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 18 01 
2021-04-24 22:25:07.133 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5266: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2021-04-24 22:25:07.133 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2021-04-24 22:25:07.134 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 5266: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2021-04-24 22:25:07.134 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 18 01 
2021-04-24 22:25:07.135 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 32: ProtocolInfo
2021-04-24 22:25:07.135 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 32: Listening = false
2021-04-24 22:25:07.136 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 32: Routing   = true
2021-04-24 22:25:07.136 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 32: Beaming   = true
2021-04-24 22:25:07.137 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 32: Version   = 4
2021-04-24 22:25:07.137 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 32: FLIRS     = false
2021-04-24 22:25:07.137 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 32: Security  = false
2021-04-24 22:25:07.138 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 32: Max Baud  = 40000
2021-04-24 22:25:07.138 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 32: Basic    = BASIC_TYPE_ROUTING_SLAVE
2021-04-24 22:25:07.138 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 32: Generic  = GENERIC_TYPE_WALL_CONTROLLER
2021-04-24 22:25:07.139 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 32: Specific = SPECIFIC_TYPE_BASIC_WALL_CONTROLLER
2021-04-24 22:25:07.139 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_NO_OPERATION
2021-04-24 22:25:07.139 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created
2021-04-24 22:25:07.140 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Version = 1, version set. Enabling extra functionality.
2021-04-24 22:25:07.140 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes.
2021-04-24 22:25:07.141 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Creating new instance of command class COMMAND_CLASS_BASIC
2021-04-24 22:25:07.141 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 32: Command class COMMAND_CLASS_BASIC, endpoint 0 created
2021-04-24 22:25:07.142 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes.
2021-04-24 22:25:07.142 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 5266: Transaction COMPLETED
2021-04-24 22:25:07.142 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 14ms
2021-04-24 22:25:07.143 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 5266: Transaction completed
2021-04-24 22:25:07.143 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:5266 DONE
2021-04-24 22:25:07.144 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 22:25:07.144 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 5266: Transaction event listener: DONE: DONE -> 
2021-04-24 22:25:07.144 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-04-24 22:25:07.144 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 32: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@11fe13d
2021-04-24 22:25:07.145 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 00 B5 
2021-04-24 22:25:07.145 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 32: Node Init transaction completed with response COMPLETE
2021-04-24 22:25:07.145 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5 
2021-04-24 22:25:07.146 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2021-04-24 22:25:07.146 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 5267: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2021-04-24 22:25:07.147 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2021-04-24 22:25:07.147 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-04-24 22:25:07.148 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-04-24 22:25:07.148 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5267: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2021-04-24 22:25:07.148 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2021-04-24 22:25:07.148 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 22:25:07.149 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-04-24 22:25:08.146 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-04-24 22:25:08.148 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Is awake with 0 messages in the queue
2021-04-24 22:25:08.154 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Start sleep timer at 5000ms
2021-04-24 22:25:08.155 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 32: Node Status event - Node is AWAKE
2021-04-24 22:25:08.156 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 32: Node advancer - advancing to SECURITY_REPORT
2021-04-24 22:25:08.157 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 32: SECURE command class not supported
2021-04-24 22:25:08.158 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 32: Node advancer - advancing to MANUFACTURER
2021-04-24 22:25:08.158 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 32: Node advancer: MANUFACTURER - send ManufacturerSpecific
2021-04-24 22:25:08.159 [DEBUG] [WaveManufacturerSpecificCommandClass] - NODE 32: Creating new message for command MANUFACTURER_SPECIFIC_GET
2021-04-24 22:25:08.160 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 32: ZWaveCommandClassTransactionPayload - send to node
2021-04-24 22:25:08.160 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: SECURITY not supported
2021-04-24 22:25:08.161 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: Command Class COMMAND_CLASS_MANUFACTURER_SPECIFIC is NOT required to be secured
2021-04-24 22:25:08.162 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 32: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@1206d86
2021-04-24 22:25:08.163 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 32: Bump transaction 5268 priority from Config to Immediate
2021-04-24 22:25:08.164 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 32: Adding to device queue
2021-04-24 22:25:08.164 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 32: Added 5268 to queue - size 11
2021-04-24 22:25:08.165 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-04-24 22:25:09.609 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 04 20 02 84 07 56 
2021-04-24 22:25:09.610 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=32, callback=4, payload=04 20 02 84 07 
2021-04-24 22:25:09.611 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=32, callback=4, payload=04 20 02 84 07 
2021-04-24 22:25:09.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5267: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2021-04-24 22:25:09.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 32: Application Command Request (ALIVE:MANUFACTURER)
2021-04-24 22:25:09.613 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 32: Commands processed 1.
2021-04-24 22:25:09.613 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 32: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@828b2f.
2021-04-24 22:25:09.614 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2021-04-24 22:25:09.614 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2021-04-24 22:25:09.615 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 22:25:09.615 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-04-24 22:25:10.655 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 32: WakeupTimerTask 1 Messages waiting, state MANUFACTURER
2021-04-24 22:25:12.146 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 5267: Timeout at state WAIT_REQUEST. 3 retries remaining.
2021-04-24 22:25:12.150 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 5267: Transaction is current transaction, so clearing!!!!!
2021-04-24 22:25:12.151 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 5267: Transaction CANCELLED
2021-04-24 22:25:12.152 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:5267 CANCELLED
2021-04-24 22:25:12.153 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-04-24 22:25:12.154 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 20 02 72 04 25 DE 4A 
2021-04-24 22:25:12.155 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 32: Sending REQUEST Message = 01 09 00 13 20 02 72 04 25 DE 4A 
2021-04-24 22:25:12.155 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2021-04-24 22:25:12.156 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 5268: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 222
2021-04-24 22:25:12.157 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2021-04-24 22:25:12.157 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-04-24 22:25:12.158 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-04-24 22:25:12.159 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5268: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 222
2021-04-24 22:25:12.159 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2021-04-24 22:25:12.160 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 22:25:12.160 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-04-24 22:25:12.166 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2021-04-24 22:25:12.167 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2021-04-24 22:25:12.168 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2021-04-24 22:25:12.169 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5268: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 222
2021-04-24 22:25:12.169 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2021-04-24 22:25:12.170 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 5268: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 222
2021-04-24 22:25:12.170 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2021-04-24 22:25:12.171 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 32: sentData successfully placed on stack.
2021-04-24 22:25:12.171 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 5268: Advanced to WAIT_REQUEST
2021-04-24 22:25:12.172 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 32: TID 5268: Transaction not completed
2021-04-24 22:25:12.172 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-04-24 22:25:12.172 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-04-24 22:25:12.183 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 DE 00 00 03 36 
2021-04-24 22:25:12.183 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=222, payload=DE 00 00 03 
2021-04-24 22:25:12.184 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=222, payload=DE 00 00 03 
2021-04-24 22:25:12.184 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5268: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 222
2021-04-24 22:25:12.185 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2021-04-24 22:25:12.185 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 5268: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 222
2021-04-24 22:25:12.185 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 5268: (Callback 222)
2021-04-24 22:25:12.185 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2021-04-24 22:25:12.186 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 5268: callback 222
2021-04-24 22:25:12.186 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=222, payload=DE 00 00 03 
2021-04-24 22:25:12.186 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 32: SendData Request. CallBack ID = 222, Status = Transmission complete and ACK received(0)
2021-04-24 22:25:12.187 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 5268: Advanced to WAIT_DATA
2021-04-24 22:25:12.187 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 32: TID 5268: Transaction not completed
2021-04-24 22:25:12.187 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

prokhor · April 25, 2021, 6:03am

Should it download itself fully within a few minutes, or is it something I should wait a few hours/days to see if gets better?

chris · April 25, 2021, 6:11am

This doesn’t seem to have the interview phase, so doesn’t really show what is happening with the discovery.

Do you still have the same error when updating configuration?

prokhor · April 25, 2021, 5:57pm

Yea, I did at that moment. Will try again later today.

prokhor · June 25, 2021, 7:02pm

Hello,

Been a while since I looked at this again, but issue is still occurring even after the last milestone build. I think I captured everything after I clicked inclusion this time. I embedded up to when node 39 is mentioned, but attached the longer log.

2021-05-28 10:16:40.132 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave inclusion controller finalised
2021-05-28 10:16:42.384 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:c3f88d21c6
2021-05-28 10:16:42.385 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do
2021-05-28 10:16:42.386 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:c3f88d21c6
2021-05-28 10:16:42.387 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2
2021-05-28 10:16:42.388 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2021-05-28 10:16:42.389 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion
2021-05-28 10:16:42.390 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true.
2021-05-28 10:16:42.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 30099 to queue - size 1
2021-05-28 10:16:42.391 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-05-28 10:16:42.392 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 02 73 
2021-05-28 10:16:42.392 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 02 73 
2021-05-28 10:16:42.393 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2021-05-28 10:16:42.394 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 30099: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 2
2021-05-28 10:16:42.394 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2021-05-28 10:16:42.394 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-05-28 10:16:42.395 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-05-28 10:16:42.396 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 02 01 00 00 B1 
2021-05-28 10:16:42.396 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 30099: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 2
2021-05-28 10:16:42.397 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=2, payload=02 01 00 00 
2021-05-28 10:16:42.397 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2021-05-28 10:16:42.398 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=2, payload=02 01 00 00 
2021-05-28 10:16:42.398 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 30099: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 2
2021-05-28 10:16:42.399 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2021-05-28 10:16:42.399 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 30099: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 2
2021-05-28 10:16:42.400 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 30099: (Callback 2)
2021-05-28 10:16:42.400 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2021-05-28 10:16:42.400 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 30099: callback 2
2021-05-28 10:16:42.401 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=2, payload=02 01 00 00 
2021-05-28 10:16:42.401 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready.
2021-05-28 10:16:42.402 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart
2021-05-28 10:16:42.402 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 30099: Transaction COMPLETED
2021-05-28 10:16:42.403 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 10ms
2021-05-28 10:16:42.403 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 30099: Transaction completed
2021-05-28 10:16:42.403 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:30099 DONE
2021-05-28 10:16:42.404 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-05-28 10:16:42.405 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-05-28 10:16:44.395 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 32: Device discovery completed
2021-05-28 10:16:44.403 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 32: Device discovery could not resolve to a thingType! Manufacturer data not known.
2021-05-28 10:16:44.405 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 34: Device discovery completed
2021-05-28 10:16:44.411 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 34: Device discovery resolved to thingType zwave:aeon_zw132_02_000
2021-05-28 10:16:44.416 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 35: Device discovery completed
2021-05-28 10:16:44.421 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 35: Device discovery resolved to thingType zwave:aeotec_zwa023_00_000
2021-05-28 10:16:44.423 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 4: Device discovery completed
2021-05-28 10:16:44.426 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 4: Device discovery resolved to thingType zwave:aeon_zw100_01_010
2021-05-28 10:16:44.429 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 36: Device discovery completed
2021-05-28 10:16:44.432 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 36: Device discovery resolved to thingType zwave:nietech_mp21z_00_000
2021-05-28 10:16:44.435 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 6: Device discovery completed
2021-05-28 10:16:44.437 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 6: Device discovery resolved to thingType zwave:vision_zg8101_00_000
2021-05-28 10:16:44.439 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 8: Device discovery completed
2021-05-28 10:16:44.440 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 8: Device discovery resolved to thingType zwave:vision_zd2102_00_000
2021-05-28 10:16:44.442 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 10: Device discovery completed
2021-05-28 10:16:44.445 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 10: Device discovery could not resolve to a thingType! Manufacturer data not known.
2021-05-28 10:16:44.447 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 13: Device discovery completed
2021-05-28 10:16:44.448 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 13: Device discovery resolved to thingType zwave:vision_zp3102_08_000
2021-05-28 10:16:44.450 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 14: Device discovery completed
2021-05-28 10:16:44.451 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 14: Device discovery resolved to thingType zwave:vision_zp3102_00_000
2021-05-28 10:16:44.453 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 17: Device discovery completed
2021-05-28 10:16:44.455 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 17: Device discovery resolved to thingType zwave:ge_zw4006_00_000
2021-05-28 10:16:44.457 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 18: Device discovery completed
2021-05-28 10:16:44.460 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 18: Device discovery could not resolve to a thingType! Manufacturer data not known.
2021-05-28 10:16:44.461 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 19: Device discovery completed
2021-05-28 10:16:44.463 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 19: Device discovery resolved to thingType zwave:ge_14291_00_000
2021-05-28 10:16:44.464 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 21: Device discovery completed
2021-05-28 10:16:44.465 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 21: Device discovery resolved to thingType zwave:vision_pid11994_00_000
2021-05-28 10:16:44.466 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 22: Device discovery completed
2021-05-28 10:16:44.466 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 22: Device discovery resolved to thingType zwave:vision_pid11994_00_000
2021-05-28 10:16:44.467 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 23: Device discovery completed
2021-05-28 10:16:44.469 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 23: Device discovery resolved to thingType zwave:vision_zd2102_00_000
2021-05-28 10:16:44.471 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 25: Device discovery completed
2021-05-28 10:16:44.473 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 25: Device discovery resolved to thingType zwave:aeotec_zwa023_00_000
2021-05-28 10:16:44.475 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 27: Device discovery completed
2021-05-28 10:16:44.476 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 27: Device discovery resolved to thingType zwave:linear_fs20z_00_000
2021-05-28 10:16:44.478 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 28: Device discovery completed
2021-05-28 10:16:44.481 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 28: Device discovery could not resolve to a thingType! Manufacturer data not known.
2021-05-28 10:16:50.171 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 02 02 00 00 B2 
2021-05-28 10:16:50.172 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=2, payload=02 02 00 00 
2021-05-28 10:16:50.173 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=2, payload=02 02 00 00 
2021-05-28 10:16:50.174 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2021-05-28 10:16:50.174 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
2021-05-28 10:16:50.175 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null
2021-05-28 10:16:50.176 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=2, payload=02 02 00 00 
2021-05-28 10:16:50.177 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: New node found.
2021-05-28 10:16:50.177 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-05-28 10:16:50.178 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-05-28 10:16:50.459 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1C 00 4A 02 03 27 15 04 18 01 5E 85 59 8E 60 86 70 72 5A 73 84 80 5B 71 7A EF 25 26 FE 
2021-05-28 10:16:50.461 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=3, callback=2, payload=02 03 27 15 04 18 01 5E 85 59 8E 60 86 70 72 5A 73 84 80 5B 71 7A EF 25 26 
2021-05-28 10:16:50.463 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=3, callback=2, payload=02 03 27 15 04 18 01 5E 85 59 8E 60 86 70 72 5A 73 84 80 5B 71 7A EF 25 26 
2021-05-28 10:16:50.463 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2021-05-28 10:16:50.464 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
2021-05-28 10:16:50.464 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null
2021-05-28 10:16:50.466 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=3, callback=2, payload=02 03 27 15 04 18 01 5E 85 59 8E 60 86 70 72 5A 73 84 80 5B 71 7A EF 25 26 
2021-05-28 10:16:50.466 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - NODE 39: Adding slave.
2021-05-28 10:16:50.467 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeStart, new event IncludeSlaveFound
2021-05-28 10:16:50.470 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Including node.
2021-05-28 10:16:50.471 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-05-28 10:16:50.471 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-05-28 10:16:51.016 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 13 00 04 10 11 0D 60 0D 02 01 71 05 00 00 00 FF 07 08 00 0E 
2021-05-28 10:16:51.019 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=16, payload=10 11 0D 60 0D 02 01 71 05 00 00 00 FF 07 08 00 
2021-05-28 10:16:51.020 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=16, payload=10 11 0D 60 0D 02 01 71 05 00 00 00 FF 07 08 00 
2021-05-28 10:16:51.020 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2021-05-28 10:16:51.021 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 17: Application Command Request (ALIVE:DELETE_ROUTES)
2021-05-28 10:16:51.022 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 17: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2021-05-28 10:16:51.022 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 17: Incoming command class COMMAND_CLASS_ALARM, endpoint 2
2021-05-28 10:16:51.023 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY not supported
2021-05-28 10:16:51.024 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 17: Received COMMAND_CLASS_ALARM V4 NOTIFICATION_REPORT
2021-05-28 10:16:51.024 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 17: NOTIFICATION report - 0 = 0, event=8, status=255, plen=0
2021-05-28 10:16:51.025 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 17: Alarm Type = BURGLAR (0)
2021-05-28 10:16:51.026 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 17: Got an event from Z-Wave network: ZWaveAlarmValueEvent
2021-05-28 10:16:51.026 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 17: Got a value event from Z-Wave network, endpoint=2, command class=COMMAND_CLASS_ALARM, value=255
2021-05-28 10:16:51.027 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 17: Alarm converter processing NOTIFICATION
2021-05-28 10:16:51.028 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 17: Alarm converter NOTIFICATION event is 8, type OnOffType
2021-05-28 10:16:51.028 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 17: Updating channel state zwave:device:c3f88d21c6:node17:alarm_motion2 to ON [OnOffType]
2021-05-28 10:16:51.031 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 17: Commands processed 1.
2021-05-28 10:16:51.032 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 17: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1704409.
2021-05-28 10:16:51.032 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2021-05-28 10:16:51.035 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2021-05-28 10:16:51.036 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-05-28 10:16:51.036 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-05-28 10:16:51.073 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 13 00 04 10 11 0D 60 0D 02 01 71 05 00 00 00 FF 07 08 00 0E 
2021-05-28 10:16:51.074 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=16, payload=10 11 0D 60 0D 02 01 71 05 00 00 00 FF 07 08 00 
2021-05-28 10:16:51.075 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=16, payload=10 11 0D 60 0D 02 01 71 05 00 00 00 FF 07 08 00 
2021-05-28 10:16:51.075 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2021-05-28 10:16:51.075 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 17: Application Command Request (ALIVE:DELETE_ROUTES)
2021-05-28 10:16:51.076 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 17: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2021-05-28 10:16:51.076 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 17: Incoming command class COMMAND_CLASS_ALARM, endpoint 2
2021-05-28 10:16:51.076 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY not supported
2021-05-28 10:16:51.077 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 17: Received COMMAND_CLASS_ALARM V4 NOTIFICATION_REPORT
2021-05-28 10:16:51.077 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 17: NOTIFICATION report - 0 = 0, event=8, status=255, plen=0
2021-05-28 10:16:51.077 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 17: Alarm Type = BURGLAR (0)
2021-05-28 10:16:51.078 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 17: Got an event from Z-Wave network: ZWaveAlarmValueEvent
2021-05-28 10:16:51.078 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 17: Got a value event from Z-Wave network, endpoint=2, command class=COMMAND_CLASS_ALARM, value=255
2021-05-28 10:16:51.079 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 17: Alarm converter processing NOTIFICATION
2021-05-28 10:16:51.079 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 17: Alarm converter NOTIFICATION event is 8, type OnOffType
2021-05-28 10:16:51.079 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 17: Updating channel state zwave:device:c3f88d21c6:node17:alarm_motion2 to ON [OnOffType]
2021-05-28 10:16:51.081 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 17: Commands processed 1.
2021-05-28 10:16:51.081 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 17: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@775b01.
2021-05-28 10:16:51.082 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2021-05-28 10:16:51.082 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2021-05-28 10:16:51.082 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-05-28 10:16:51.082 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-05-28 10:16:51.583 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 02 05 27 00 92 
2021-05-28 10:16:51.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=5, callback=2, payload=02 05 27 00 
2021-05-28 10:16:51.585 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=5, callback=2, payload=02 05 27 00 
2021-05-28 10:16:51.586 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2021-05-28 10:16:51.587 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
2021-05-28 10:16:51.587 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null
2021-05-28 10:16:51.588 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=5, callback=2, payload=02 05 27 00 
2021-05-28 10:16:51.589 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - NODE 39: Add Node: Protocol done.
2021-05-28 10:16:51.590 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSlaveFound, new event IncludeProtocolDone
2021-05-28 10:16:51.590 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2021-05-28 10:16:51.591 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 30100 to queue - size 1
2021-05-28 10:16:51.592 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-05-28 10:16:51.592 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 03 B6 
2021-05-28 10:16:51.593 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 03 B6 
2021-05-28 10:16:51.594 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2021-05-28 10:16:51.594 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 30100: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 3
2021-05-28 10:16:51.594 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2021-05-28 10:16:51.595 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-05-28 10:16:51.595 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Inclusion protocol completed.
2021-05-28 10:16:51.596 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_NO_OPERATION
2021-05-28 10:16:51.598 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created
2021-05-28 10:16:51.599 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Version = 1, version set. Enabling extra functionality.
2021-05-28 10:16:51.600 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes.
2021-05-28 10:16:51.600 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_BASIC
2021-05-28 10:16:51.601 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_BASIC, endpoint 0 created
2021-05-28 10:16:51.602 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes.
2021-05-28 10:16:51.602 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_ZWAVEPLUS_INFO
2021-05-28 10:16:51.603 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_ZWAVEPLUS_INFO, endpoint 0 created
2021-05-28 10:16:51.604 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Inclusion is adding command class COMMAND_CLASS_ZWAVEPLUS_INFO.
2021-05-28 10:16:51.605 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_ZWAVEPLUS_INFO to the list of supported command classes.
2021-05-28 10:16:51.605 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_ASSOCIATION
2021-05-28 10:16:51.606 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_ASSOCIATION, endpoint 0 created
2021-05-28 10:16:51.607 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Inclusion is adding command class COMMAND_CLASS_ASSOCIATION.
2021-05-28 10:16:51.607 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_ASSOCIATION to the list of supported command classes.
2021-05-28 10:16:51.608 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_ASSOCIATION_GRP_INFO
2021-05-28 10:16:51.609 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_ASSOCIATION_GRP_INFO, endpoint 0 created
2021-05-28 10:16:51.609 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Inclusion is adding command class COMMAND_CLASS_ASSOCIATION_GRP_INFO.
2021-05-28 10:16:51.610 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_ASSOCIATION_GRP_INFO to the list of supported command classes.
2021-05-28 10:16:51.610 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION
2021-05-28 10:16:51.611 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION, endpoint 0 created
2021-05-28 10:16:51.612 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Inclusion is adding command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION.
2021-05-28 10:16:51.612 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION to the list of supported command classes.
2021-05-28 10:16:51.613 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_MULTI_CHANNEL
2021-05-28 10:16:51.613 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_MULTI_CHANNEL, endpoint 0 created
2021-05-28 10:16:51.614 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Inclusion is adding command class COMMAND_CLASS_MULTI_CHANNEL.
2021-05-28 10:16:51.614 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_MULTI_CHANNEL to the list of supported command classes.
2021-05-28 10:16:51.614 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_VERSION
2021-05-28 10:16:51.615 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_VERSION, endpoint 0 created
2021-05-28 10:16:51.615 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Inclusion is adding command class COMMAND_CLASS_VERSION.
2021-05-28 10:16:51.615 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_VERSION to the list of supported command classes.
2021-05-28 10:16:51.616 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_CONFIGURATION
2021-05-28 10:16:51.616 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_CONFIGURATION, endpoint 0 created
2021-05-28 10:16:51.617 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Inclusion is adding command class COMMAND_CLASS_CONFIGURATION.
2021-05-28 10:16:51.617 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_CONFIGURATION to the list of supported command classes.
2021-05-28 10:16:51.617 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_MANUFACTURER_SPECIFIC
2021-05-28 10:16:51.618 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_MANUFACTURER_SPECIFIC, endpoint 0 created
2021-05-28 10:16:51.618 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Inclusion is adding command class COMMAND_CLASS_MANUFACTURER_SPECIFIC.
2021-05-28 10:16:51.619 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_MANUFACTURER_SPECIFIC to the list of supported command classes.
2021-05-28 10:16:51.619 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_DEVICE_RESET_LOCALLY
2021-05-28 10:16:51.619 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_DEVICE_RESET_LOCALLY, endpoint 0 created
2021-05-28 10:16:51.620 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Inclusion is adding command class COMMAND_CLASS_DEVICE_RESET_LOCALLY.
2021-05-28 10:16:51.620 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_DEVICE_RESET_LOCALLY to the list of supported command classes.
2021-05-28 10:16:51.620 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_POWERLEVEL
2021-05-28 10:16:51.621 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_POWERLEVEL, endpoint 0 created
2021-05-28 10:16:51.621 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Inclusion is adding command class COMMAND_CLASS_POWERLEVEL.
2021-05-28 10:16:51.622 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_POWERLEVEL to the list of supported command classes.
2021-05-28 10:16:51.622 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_WAKE_UP
2021-05-28 10:16:51.623 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_WAKE_UP, endpoint 0 created
2021-05-28 10:16:51.623 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Inclusion is adding command class COMMAND_CLASS_WAKE_UP.
2021-05-28 10:16:51.623 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_WAKE_UP to the list of supported command classes.
2021-05-28 10:16:51.624 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_BATTERY
2021-05-28 10:16:51.624 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_BATTERY, endpoint 0 created
2021-05-28 10:16:51.625 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Inclusion is adding command class COMMAND_CLASS_BATTERY.
2021-05-28 10:16:51.625 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_BATTERY to the list of supported command classes.
2021-05-28 10:16:51.625 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_CENTRAL_SCENE
2021-05-28 10:16:51.626 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_CENTRAL_SCENE, endpoint 0 created
2021-05-28 10:16:51.626 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Inclusion is adding command class COMMAND_CLASS_CENTRAL_SCENE.
2021-05-28 10:16:51.626 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_CENTRAL_SCENE to the list of supported command classes.
2021-05-28 10:16:51.627 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_ALARM
2021-05-28 10:16:51.627 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_ALARM, endpoint 0 created
2021-05-28 10:16:51.628 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Inclusion is adding command class COMMAND_CLASS_ALARM.
2021-05-28 10:16:51.628 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_ALARM to the list of supported command classes.
2021-05-28 10:16:51.628 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_FIRMWARE_UPDATE_MD
2021-05-28 10:16:51.629 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_FIRMWARE_UPDATE_MD, endpoint 0 created
2021-05-28 10:16:51.629 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Inclusion is adding command class COMMAND_CLASS_FIRMWARE_UPDATE_MD.
2021-05-28 10:16:51.630 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_FIRMWARE_UPDATE_MD to the list of supported command classes.
2021-05-28 10:16:51.630 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_SWITCH_BINARY
2021-05-28 10:16:51.630 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_SWITCH_BINARY, endpoint 0 created
2021-05-28 10:16:51.631 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Inclusion is adding command class COMMAND_CLASS_SWITCH_BINARY.
2021-05-28 10:16:51.631 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_SWITCH_BINARY to the list of supported command classes.
2021-05-28 10:16:51.631 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Creating new instance of command class COMMAND_CLASS_SWITCH_MULTILEVEL
2021-05-28 10:16:51.632 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 39: Command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0 created
2021-05-28 10:16:51.633 [DEBUG] [al.protocol.ZWaveInclusionController] - NODE 39: Inclusion is adding command class COMMAND_CLASS_SWITCH_MULTILEVEL.
2021-05-28 10:16:51.633 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 39: Adding command class COMMAND_CLASS_SWITCH_MULTILEVEL to the list of supported command classes.
2021-05-28 10:16:51.633 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 39: ZWaveController include node
2021-05-28 10:16:51.633 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 39: Starting initialisation from INCLUSION_START
2021-05-28 10:16:51.634 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-05-28 10:16:51.634 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 39: Node advancer: Node just included (1152993)
2021-05-28 10:16:51.635 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 30100: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 3
2021-05-28 10:16:51.635 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 39: Node advancer - advancing to IDENTIFY_NODE
2021-05-28 10:16:51.635 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2021-05-28 10:16:51.635 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-05-28 10:16:51.635 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 39: Node advancer: Initialisation starting from inclusion```

[openhab_includeaetecquad_debug.log|attachment](upload://pvcG06PF5ogQ5pZ2YZvRzLSV2Yn.log) (457.3 KB)