Hi,
I’m really stuck in trying to use the Z-Wave binding.
My setup:
Raspi 3, openHABian running openHAB 2.5.0-1, Nortek HUSBZB-1 Z-Wave/Zigbee combo stick
The Zigbee part is running sucessfully, I’m controlling my Philips HUE bulbs.
When searching for Z-Wave devices (Inclusion mode), nothing ever shows up in the inbox.
I have tried ajusting the Inclusion mode (Low power, High power, Network Wide), no difference. I have tried ajusting the security mode, no difference. I have tried to initiate the scan from PaperUI as well as HABmin, no difference.
First I tried to add two MT02650 Devolo Thermostats without luck.
https://www.openhab.org/addons/bindings/zwave/thing.html?manufacturer=danfoss&file=mt02650_0_0.html
I wonder if the thermostats could be the issue, so tried to order a Fibrao FGS213 Single Switch 2.
https://www.openhab.org/addons/bindings/zwave/thing.html?manufacturer=fibaro&file=fgs213_0_0.html
Unfortunately the behave was exactly the same.
All devices have been very close to the Nortek stick when trying to pair.
A lot shows up in the log during the search / pairing process, but I’m unsure what to conclude from that. (pasted in the Bottom)
Can I be sure, that my thing configuration is set correct (USB / COM etc.) when the Z-Wave appears as online form Configuration->Things?
Any help really appreciated, I don’t know where “to dig” anymore.
Best regards Ole.
2020-02-10 21:03:04.447 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - ZWave product zwave:device has no references!
2020-02-10 21:03:04.469 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - ZWave product zwave:serial_zstick has no references!
2020-02-10 21:03:04.589 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - ZWave product zwave:device has no references!
2020-02-10 21:03:04.663 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - ZWave product zwave:serial_zstick has no references!
2020-02-10 21:03:44.933 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:6cf548a6
2020-02-10 21:03:44.938 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do
2020-02-10 21:03:44.946 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:6cf548a6
2020-02-10 21:03:44.950 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 1
2020-02-10 21:03:44.957 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2020-02-10 21:03:44.961 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion
2020-02-10 21:03:44.968 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:false.
2020-02-10 21:03:44.971 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 8 to queue - size 1
2020-02-10 21:03:44.973 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-10 21:03:44.977 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 81 01 30
2020-02-10 21:03:44.980 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 81 01 30
2020-02-10 21:03:44.986 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-02-10 21:03:44.988 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-10 21:03:44.991 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-10 21:03:44.993 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-02-10 21:03:44.993 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 01 01 00 00 B2
2020-02-10 21:03:44.995 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-02-10 21:03:44.998 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-10 21:03:45.001 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-02-10 21:03:45.004 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 8: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 1
2020-02-10 21:03:45.007 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=1, payload=01 01 00 00
2020-02-10 21:03:45.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-02-10 21:03:45.013 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=1, payload=01 01 00 00
2020-02-10 21:03:45.014 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 8: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 1
2020-02-10 21:03:45.017 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-02-10 21:03:45.018 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 8: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 1
2020-02-10 21:03:45.021 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 8: (Callback 1)
2020-02-10 21:03:45.023 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-02-10 21:03:45.025 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 8: callback 1
2020-02-10 21:03:45.027 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=1, payload=01 01 00 00
2020-02-10 21:03:45.030 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready.
2020-02-10 21:03:45.033 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart
2020-02-10 21:03:45.036 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 8: Transaction COMPLETED
2020-02-10 21:03:45.037 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 34ms
2020-02-10 21:03:45.040 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 8: Transaction completed
2020-02-10 21:03:45.042 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:8 DONE
2020-02-10 21:03:45.049 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-10 21:03:45.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-10 21:04:44.946 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:6cf548a6
2020-02-10 21:04:44.950 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeStart
2020-02-10 21:04:44.954 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2020-02-10 21:04:44.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 9 to queue - size 1
2020-02-10 21:04:44.973 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-10 21:04:44.978 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 02 B7
2020-02-10 21:04:44.983 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 02 B7
2020-02-10 21:04:44.992 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-02-10 21:04:44.995 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-10 21:04:44.998 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-10 21:04:45.001 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-02-10 21:04:45.001 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-02-10 21:04:45.006 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-02-10 21:04:45.006 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 9: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 2
2020-02-10 21:04:45.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-10 21:04:45.022 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-02-10 21:04:45.045 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 02 06 00 00 B6
2020-02-10 21:04:45.052 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=2, payload=02 06 00 00
2020-02-10 21:04:45.055 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=2, payload=02 06 00 00
2020-02-10 21:04:45.058 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 9: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 2
2020-02-10 21:04:45.060 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-02-10 21:04:45.061 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 9: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 2
2020-02-10 21:04:45.064 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 9: (Callback 2)
2020-02-10 21:04:45.066 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-02-10 21:04:45.068 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 9: callback 2
2020-02-10 21:04:45.070 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=2, payload=02 06 00 00
2020-02-10 21:04:45.073 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.
2020-02-10 21:04:45.074 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeDone, new event IncludeDone
2020-02-10 21:04:45.077 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2020-02-10 21:04:45.078 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 10 to queue - size 1
2020-02-10 21:04:45.081 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-02-10 21:04:45.083 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion
2020-02-10 21:04:45.085 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done
2020-02-10 21:04:45.087 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 9: Advanced to DONE
2020-02-10 21:04:45.090 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 85ms
2020-02-10 21:04:45.091 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 9: Transaction completed
2020-02-10 21:04:45.094 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:9 DONE
2020-02-10 21:04:45.102 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-10 21:04:45.103 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-10 21:04:45.106 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 00 B5
2020-02-10 21:04:45.108 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5
2020-02-10 21:04:45.111 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-02-10 21:04:45.113 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-10 21:04:45.131 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-02-10 21:04:45.132 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 10: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2020-02-10 21:04:45.134 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-10 21:04:45.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 10: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2020-02-10 21:04:45.137 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-02-10 21:04:45.138 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-10 21:04:45.141 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-02-10 21:04:48.945 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:6cf548a6
2020-02-10 21:04:48.950 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do
2020-02-10 21:04:48.956 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:6cf548a6
2020-02-10 21:04:48.961 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 1
2020-02-10 21:04:48.984 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2020-02-10 21:04:48.989 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion
2020-02-10 21:04:48.995 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:false.
2020-02-10 21:04:49.000 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 11 to queue - size 1
2020-02-10 21:04:49.005 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-02-10 21:04:50.134 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 10: Timeout at state WAIT_REQUEST. 3 retries remaining.
2020-02-10 21:04:50.136 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 10: Transaction is current transaction, so clearing!!!!!
2020-02-10 21:04:50.139 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 10: Transaction CANCELLED
2020-02-10 21:04:50.142 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:10 CANCELLED
2020-02-10 21:04:50.153 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-10 21:04:50.201 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 81 04 35
2020-02-10 21:04:50.206 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 81 04 35
2020-02-10 21:04:50.223 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-02-10 21:04:50.226 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-10 21:04:50.228 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-10 21:04:50.230 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-02-10 21:04:50.230 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 04 01 00 00 B7
2020-02-10 21:04:50.231 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-02-10 21:04:50.233 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-10 21:04:50.240 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-02-10 21:04:50.243 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 11: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 4
2020-02-10 21:04:50.244 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=4, payload=04 01 00 00
2020-02-10 21:04:50.246 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-02-10 21:04:50.248 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=4, payload=04 01 00 00
2020-02-10 21:04:50.250 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 11: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 4
2020-02-10 21:04:50.252 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-02-10 21:04:50.254 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 11: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 4
2020-02-10 21:04:50.256 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 11: (Callback 4)
2020-02-10 21:04:50.257 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-02-10 21:04:50.259 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 11: callback 4
2020-02-10 21:04:50.261 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=4, payload=04 01 00 00
2020-02-10 21:04:50.264 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready.
2020-02-10 21:04:50.265 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart
2020-02-10 21:04:50.267 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 11: Transaction COMPLETED
2020-02-10 21:04:50.269 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 25ms
2020-02-10 21:04:50.271 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 11: Transaction completed
2020-02-10 21:04:50.272 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:11 DONE
2020-02-10 21:04:50.278 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-10 21:04:50.280 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-10 21:05:48.957 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:6cf548a6
2020-02-10 21:05:48.960 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeStart
2020-02-10 21:05:48.964 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2020-02-10 21:05:48.969 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 12 to queue - size 1
2020-02-10 21:05:48.972 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-10 21:05:48.978 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 05 B0
2020-02-10 21:05:48.983 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 05 B0
2020-02-10 21:05:48.991 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-02-10 21:05:48.994 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-10 21:05:48.998 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-10 21:05:49.001 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-02-10 21:05:49.001 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-02-10 21:05:49.003 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-02-10 21:05:49.005 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-10 21:05:49.005 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 12: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 5
2020-02-10 21:05:49.017 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-02-10 21:05:49.043 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 05 06 00 00 B1
2020-02-10 21:05:49.055 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=5, payload=05 06 00 00
2020-02-10 21:05:49.061 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=5, payload=05 06 00 00
2020-02-10 21:05:49.064 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 12: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 5
2020-02-10 21:05:49.068 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-02-10 21:05:49.071 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 12: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 5
2020-02-10 21:05:49.076 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 12: (Callback 5)
2020-02-10 21:05:49.078 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-02-10 21:05:49.080 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 12: callback 5
2020-02-10 21:05:49.083 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=5, payload=05 06 00 00
2020-02-10 21:05:49.085 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.
2020-02-10 21:05:49.087 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeDone, new event IncludeDone
2020-02-10 21:05:49.090 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2020-02-10 21:05:49.092 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 13 to queue - size 1
2020-02-10 21:05:49.095 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-02-10 21:05:49.097 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion
2020-02-10 21:05:49.099 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done
2020-02-10 21:05:49.101 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 12: Advanced to DONE
2020-02-10 21:05:49.103 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 98ms
2020-02-10 21:05:49.104 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 12: Transaction completed
2020-02-10 21:05:49.106 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:12 DONE
2020-02-10 21:05:49.110 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-10 21:05:49.112 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-10 21:05:49.115 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 00 B5
2020-02-10 21:05:49.117 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5
2020-02-10 21:05:49.121 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-02-10 21:05:49.123 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-10 21:05:49.131 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-02-10 21:05:49.132 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 13: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2020-02-10 21:05:49.134 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-10 21:05:49.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 13: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2020-02-10 21:05:49.137 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-02-10 21:05:49.138 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-10 21:05:49.140 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-02-10 21:05:54.134 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 13: Timeout at state WAIT_REQUEST. 3 retries remaining.
2020-02-10 21:05:54.138 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 13: Transaction is current transaction, so clearing!!!!!
2020-02-10 21:05:54.140 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 13: Transaction CANCELLED
2020-02-10 21:05:54.143 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:13 CANCELLED
2020-02-10 21:05:54.146 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-10 21:06:10.449 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave inclusion controller finalised
2020-02-10 21:06:10.455 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave inclusion controller finalised
2020-02-10 21:06:16.198 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:6cf548a6
2020-02-10 21:06:16.202 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do
2020-02-10 21:06:16.206 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:6cf548a6
2020-02-10 21:06:16.212 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 1
2020-02-10 21:06:16.217 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2020-02-10 21:06:16.222 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion
2020-02-10 21:06:16.226 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:false.
2020-02-10 21:06:16.232 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 14 to queue - size 1
2020-02-10 21:06:16.237 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-10 21:06:16.243 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 81 07 36
2020-02-10 21:06:16.250 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 81 07 36
2020-02-10 21:06:16.259 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-02-10 21:06:16.269 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-10 21:06:16.274 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-10 21:06:16.275 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 07 01 00 00 B4
2020-02-10 21:06:16.277 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-02-10 21:06:16.278 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-02-10 21:06:16.281 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 14: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 7
2020-02-10 21:06:16.284 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-02-10 21:06:16.288 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-10 21:06:16.291 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-02-10 21:06:16.302 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=7, payload=07 01 00 00
2020-02-10 21:06:16.305 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=7, payload=07 01 00 00
2020-02-10 21:06:16.308 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 14: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 7
2020-02-10 21:06:16.310 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-02-10 21:06:16.312 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 14: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 7
2020-02-10 21:06:16.313 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 14: (Callback 7)
2020-02-10 21:06:16.315 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-02-10 21:06:16.317 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 14: callback 7
2020-02-10 21:06:16.319 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=7, payload=07 01 00 00
2020-02-10 21:06:16.320 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready.
2020-02-10 21:06:16.322 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart
2020-02-10 21:06:16.324 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 14: Transaction COMPLETED
2020-02-10 21:06:16.325 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 45ms
2020-02-10 21:06:16.327 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 14: Transaction completed
2020-02-10 21:06:16.328 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:14 DONE
2020-02-10 21:06:16.344 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-10 21:06:16.346 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-10 21:07:16.207 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:6cf548a6
2020-02-10 21:07:16.214 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeStart
2020-02-10 21:07:16.218 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2020-02-10 21:07:16.221 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 15 to queue - size 1
2020-02-10 21:07:16.224 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-10 21:07:16.235 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 08 BD
2020-02-10 21:07:16.239 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 08 BD
2020-02-10 21:07:16.247 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-02-10 21:07:16.250 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-10 21:07:16.253 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-10 21:07:16.255 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-02-10 21:07:16.258 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-02-10 21:07:16.260 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-10 21:07:16.261 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-02-10 21:07:16.266 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 15: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 8
2020-02-10 21:07:16.279 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-02-10 21:07:16.299 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 08 06 00 00 BC
2020-02-10 21:07:16.305 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=8, payload=08 06 00 00
2020-02-10 21:07:16.309 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=8, payload=08 06 00 00
2020-02-10 21:07:16.311 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 8
2020-02-10 21:07:16.314 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-02-10 21:07:16.316 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 8
2020-02-10 21:07:16.318 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 15: (Callback 8)
2020-02-10 21:07:16.321 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-02-10 21:07:16.324 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 15: callback 8
2020-02-10 21:07:16.327 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=8, payload=08 06 00 00
2020-02-10 21:07:16.329 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.
2020-02-10 21:07:16.332 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeDone, new event IncludeDone
2020-02-10 21:07:16.335 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2020-02-10 21:07:16.337 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 16 to queue - size 1
2020-02-10 21:07:16.340 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-02-10 21:07:16.343 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion
2020-02-10 21:07:16.345 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done
2020-02-10 21:07:16.348 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 15: Advanced to DONE
2020-02-10 21:07:16.350 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 84ms
2020-02-10 21:07:16.353 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 15: Transaction completed
2020-02-10 21:07:16.355 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:15 DONE
2020-02-10 21:07:16.362 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-10 21:07:16.364 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-10 21:07:16.368 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 00 B5
2020-02-10 21:07:16.372 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5
2020-02-10 21:07:16.377 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-02-10 21:07:16.379 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-10 21:07:16.391 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-02-10 21:07:16.392 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 16: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2020-02-10 21:07:16.394 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-10 21:07:16.395 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 16: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2020-02-10 21:07:16.397 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-02-10 21:07:16.398 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-10 21:07:16.400 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-02-10 21:07:21.393 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 16: Timeout at state WAIT_REQUEST. 3 retries remaining.
2020-02-10 21:07:21.396 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 16: Transaction is current transaction, so clearing!!!!!
2020-02-10 21:07:21.398 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 16: Transaction CANCELLED
2020-02-10 21:07:21.401 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:16 CANCELLED
2020-02-10 21:07:21.405 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-10 21:07:41.146 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave inclusion controller finalised