Z-Wave not working w/ Raspbian, Rpi4

Raspberry Pi 4 Model B Rev 1.1 (4GB)
Raspbian GNU/Linux 10 (buster) (2/13/20)
Java Runtime Environment: (Zulu8.40.0.178-CA-linux_aarch32hf) (build 1.8.0_222-b178)
OpenHab 2.5.2
Z-Wave Binding 2.5.2

I’m getting a new hub set up and I’m at my wits end on this one. I can’t seem to make the Z-Wave Binding function with OpenHab2 installed on Raspbian. I’ve tried a few things, including flashing to Openhabian. The Z-Wave Binding (installed via PaperUI) works fine - but, when I switch back to Raspbian I’m met issues.

I am able to create a Z-Wave controller Thing and connect to my HUSBZB-1 Z-Stick. Upon scanning for Z-Wave Nodes, I find “Node 002” which, after adding, never updates and shows as Unable to communicate w/ controller.

Since I’m transitioning between Hubs, I can plug my Z-Stick into my old Pi and see that Node 002 is a dimmer switch I have. It’s discoverable, I’m able to add it, use it, and it stays connected. At this point I know the issue isn’t the Z-Stick.

Other troubleshooting steps I’ve taken:

  • I’ve confirmed that all bundles (including Z-wave) are Active in Karaf

  • Waited for several days for discovery

  • I’ve tried other Z-Wave Snapshots - 2.5.1 and 2.5.0

  • I’ve tried other OpenHab Snapshots

  • Z-Wave Manual installation script

I reloaded my pi several times throughout this process too. I’m inclined to think that some upstream dependency isn’t working right and perhaps it isn’t necessarily the Z-Wave binding at all. I’m at the end of my rope on this one though. Not sure where to look next.

Here’s my latest log file via > log:set debug org.openhab.binding.zwave. Sorry if it’s a bit messy. I’ve been trying all sorts of things. Thanks!

2020-03-14 12:41:18.775 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-14 12:41:18.775 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 10: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 4
2020-03-14 12:41:18.778 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 04 01 00 00 B7 
2020-03-14 12:41:18.778 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-14 12:41:18.780 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 10: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 4
2020-03-14 12:41:18.782 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-03-14 12:41:18.782 [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-03-14 12:41:18.784 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=4, payload=04 01 00 00 
2020-03-14 12:41:18.786 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 10: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 4
2020-03-14 12:41:18.787 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-14 12:41:18.789 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 10: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 4
2020-03-14 12:41:18.790 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 10: (Callback 4)
2020-03-14 12:41:18.792 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-03-14 12:41:18.794 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 10: callback 4
2020-03-14 12:41:18.796 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=4, payload=04 01 00 00 
2020-03-14 12:41:18.797 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready.
2020-03-14 12:41:18.800 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart
2020-03-14 12:41:18.802 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 10: Transaction COMPLETED
2020-03-14 12:41:18.804 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 28ms
2020-03-14 12:41:18.805 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 10: Transaction completed
2020-03-14 12:41:18.807 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:10 DONE
2020-03-14 12:41:18.810 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-14 12:41:18.812 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-14 12:41:20.261 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: ZWaveCommandClassTransactionPayload - send to node
2020-03-14 12:41:20.262 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2020-03-14 12:41:20.264 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Command Class COMMAND_CLASS_NO_OPERATION is NOT required to be secured
2020-03-14 12:41:20.266 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@d4eb5d
2020-03-14 12:41:20.267 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2020-03-14 12:41:20.269 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 11 to queue - size 1
2020-03-14 12:41:20.270 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-14 12:41:20.272 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 13 02 01 00 25 05 C7 
2020-03-14 12:41:20.274 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 08 00 13 02 01 00 25 05 C7 
2020-03-14 12:41:20.277 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-03-14 12:41:20.277 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-03-14 12:41:20.279 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-14 12:41:20.279 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 11: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 5
2020-03-14 12:41:20.281 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-14 12:41:20.284 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2020-03-14 12:41:20.285 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 11: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 5
2020-03-14 12:41:20.286 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-03-14 12:41:20.288 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-14 12:41:20.288 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:20.289 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-14 12:41:20.292 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:20.293 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 11: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 5
2020-03-14 12:41:20.295 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-14 12:41:20.297 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 11: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 5
2020-03-14 12:41:20.298 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:20.300 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2020-03-14 12:41:20.302 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 11: Advanced to WAIT_REQUEST
2020-03-14 12:41:20.303 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 11: Transaction not completed
2020-03-14 12:41:20.304 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-14 12:41:20.306 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-14 12:41:24.410 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 05 01 ED 
2020-03-14 12:41:24.414 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=5, payload=05 01 
2020-03-14 12:41:24.416 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=5, payload=05 01 
2020-03-14 12:41:24.417 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 11: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 5
2020-03-14 12:41:24.419 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-14 12:41:24.421 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 11: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 5
2020-03-14 12:41:24.423 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 11: (Callback 5)
2020-03-14 12:41:24.424 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-03-14 12:41:24.426 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 11: callback 5
2020-03-14 12:41:24.427 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=5, payload=05 01 
2020-03-14 12:41:24.430 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 5, Status = Transmission complete, no ACK received(1)
2020-03-14 12:41:24.431 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 11: Transaction CANCELLED
2020-03-14 12:41:24.433 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: CANCEL while sending message. Requeueing - 2 attempts left!
2020-03-14 12:41:24.435 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 11: Transaction RESET with 2 retries remaining.
2020-03-14 12:41:24.437 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2020-03-14 12:41:24.438 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 11 to queue - size 1
2020-03-14 12:41:24.440 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-14 12:41:24.442 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 13 02 01 00 25 06 C4 
2020-03-14 12:41:24.444 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 08 00 13 02 01 00 25 06 C4 
2020-03-14 12:41:24.448 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-03-14 12:41:24.449 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-14 12:41:24.450 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-03-14 12:41:24.454 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2020-03-14 12:41:24.453 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 11: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 6
2020-03-14 12:41:24.459 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 11: Transaction not completed
2020-03-14 12:41:24.459 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:24.463 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (1): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-14 12:41:24.465 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 11: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 6
2020-03-14 12:41:24.467 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-03-14 12:41:24.469 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:24.471 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 11: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 6
2020-03-14 12:41:24.473 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-14 12:41:24.475 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 11: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 6
2020-03-14 12:41:24.477 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:24.479 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2020-03-14 12:41:24.481 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 11: Advanced to WAIT_REQUEST
2020-03-14 12:41:24.483 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 11: Transaction not completed
2020-03-14 12:41:24.485 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-14 12:41:24.487 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-14 12:41:26.561 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:1989101b:node2.
2020-03-14 12:41:26.566 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: MANUFACTURER not set
2020-03-14 12:41:26.568 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Controller status changed to ONLINE.
2020-03-14 12:41:26.569 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Controller is ONLINE. Starting device initialisation.
2020-03-14 12:41:26.578 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties.
2020-03-14 12:41:26.582 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties. MAN=2147483647
2020-03-14 12:41:26.583 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Properties synchronised
2020-03-14 12:41:26.588 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2020-03-14 12:41:26.589 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising Thing Node...
2020-03-14 12:41:26.593 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling initialised at 1800 seconds - start in 324000 milliseconds.
2020-03-14 12:41:26.594 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Device initialisation complete.
2020-03-14 12:41:28.564 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 06 01 EE 
2020-03-14 12:41:28.569 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=6, payload=06 01 
2020-03-14 12:41:28.571 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=6, payload=06 01 
2020-03-14 12:41:28.572 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 11: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 6
2020-03-14 12:41:28.574 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-14 12:41:28.575 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 11: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 6
2020-03-14 12:41:28.577 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 11: (Callback 6)
2020-03-14 12:41:28.579 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-03-14 12:41:28.580 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 11: callback 6
2020-03-14 12:41:28.582 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=6, payload=06 01 
2020-03-14 12:41:28.584 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 6, Status = Transmission complete, no ACK received(1)
2020-03-14 12:41:28.585 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 11: Transaction CANCELLED
2020-03-14 12:41:28.587 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2020-03-14 12:41:28.588 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: CANCEL while sending message. Requeueing - 1 attempts left!
2020-03-14 12:41:28.590 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 11: Transaction RESET with 1 retries remaining.
2020-03-14 12:41:28.591 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2020-03-14 12:41:28.593 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 11 to queue - size 1
2020-03-14 12:41:28.594 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-14 12:41:28.596 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 13 02 01 00 25 07 C5 
2020-03-14 12:41:28.598 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 08 00 13 02 01 00 25 07 C5 
2020-03-14 12:41:28.601 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-03-14 12:41:28.601 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-03-14 12:41:28.603 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 11: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 7
2020-03-14 12:41:28.603 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-14 12:41:28.604 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 11: Transaction not completed
2020-03-14 12:41:28.605 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-14 12:41:28.606 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 11: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 7
2020-03-14 12:41:28.607 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-03-14 12:41:28.608 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2020-03-14 12:41:28.608 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-14 12:41:28.609 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-14 12:41:28.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:28.613 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:28.614 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 11: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 7
2020-03-14 12:41:28.615 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-14 12:41:28.616 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 11: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 7
2020-03-14 12:41:28.617 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:28.619 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2020-03-14 12:41:28.620 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 11: Advanced to WAIT_REQUEST
2020-03-14 12:41:28.621 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 11: Transaction not completed
2020-03-14 12:41:28.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-14 12:41:28.623 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-14 12:41:32.748 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 07 01 EF 
2020-03-14 12:41:32.752 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=7, payload=07 01 
2020-03-14 12:41:32.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=7, payload=07 01 
2020-03-14 12:41:32.756 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 11: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 7
2020-03-14 12:41:32.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-14 12:41:32.759 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 11: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 7
2020-03-14 12:41:32.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 11: (Callback 7)
2020-03-14 12:41:32.762 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-03-14 12:41:32.764 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 11: callback 7
2020-03-14 12:41:32.766 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=7, payload=07 01 
2020-03-14 12:41:32.768 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 7, Status = Transmission complete, no ACK received(1)
2020-03-14 12:41:32.769 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 11: Transaction CANCELLED
2020-03-14 12:41:32.771 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2020-03-14 12:41:32.773 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Retry count exceeded. Discarding message: TID 11: [CANCELLED] priority=Poll, requiresResponse=true, callback: 7
2020-03-14 12:41:32.774 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 11: Transaction completed
2020-03-14 12:41:32.776 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:11 CANCELLED
2020-03-14 12:41:32.778 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2020-03-14 12:41:32.779 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 11: Transaction event listener: DONE: CANCELLED -> 
2020-03-14 12:41:32.780 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-14 12:41:32.781 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@bbac01
2020-03-14 12:41:32.782 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-14 12:41:36.500 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: ZWaveCommandClassTransactionPayload - send to node
2020-03-14 12:41:36.502 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2020-03-14 12:41:36.503 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Command Class COMMAND_CLASS_NO_OPERATION is NOT required to be secured
2020-03-14 12:41:36.504 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@d4eb5d
2020-03-14 12:41:36.506 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2020-03-14 12:41:36.507 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 12 to queue - size 1
2020-03-14 12:41:36.509 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-14 12:41:36.511 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 13 02 01 00 25 08 CA 
2020-03-14 12:41:36.513 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 08 00 13 02 01 00 25 08 CA 
2020-03-14 12:41:36.516 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-03-14 12:41:36.517 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-14 12:41:36.519 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-14 12:41:36.520 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-03-14 12:41:36.522 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-03-14 12:41:36.523 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2020-03-14 12:41:36.523 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-14 12:41:36.531 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-03-14 12:41:36.533 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 12: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 8
2020-03-14 12:41:36.534 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:36.536 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-14 12:41:36.539 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:36.540 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 12: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 8
2020-03-14 12:41:36.541 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-14 12:41:36.543 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 12: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 8
2020-03-14 12:41:36.544 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:36.546 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2020-03-14 12:41:36.548 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 12: Advanced to WAIT_REQUEST
2020-03-14 12:41:36.549 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 12: Transaction not completed
2020-03-14 12:41:36.550 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-14 12:41:36.552 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-14 12:41:40.632 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 08 01 E0 
2020-03-14 12:41:40.635 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=8, payload=08 01 
2020-03-14 12:41:40.637 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=8, payload=08 01 
2020-03-14 12:41:40.639 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 12: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 8
2020-03-14 12:41:40.641 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-14 12:41:40.642 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 12: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 8
2020-03-14 12:41:40.643 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 12: (Callback 8)
2020-03-14 12:41:40.645 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-03-14 12:41:40.646 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 12: callback 8
2020-03-14 12:41:40.648 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=8, payload=08 01 
2020-03-14 12:41:40.649 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 8, Status = Transmission complete, no ACK received(1)
2020-03-14 12:41:40.650 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 12: Transaction CANCELLED
2020-03-14 12:41:40.652 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2020-03-14 12:41:40.653 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: CANCEL while sending message. Requeueing - 2 attempts left!
2020-03-14 12:41:40.654 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 12: Transaction RESET with 2 retries remaining.
2020-03-14 12:41:40.656 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2020-03-14 12:41:40.657 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 12 to queue - size 1
2020-03-14 12:41:40.658 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-14 12:41:40.660 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 13 02 01 00 25 09 CB 
2020-03-14 12:41:40.662 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 08 00 13 02 01 00 25 09 CB 
2020-03-14 12:41:40.665 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-03-14 12:41:40.666 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-14 12:41:40.666 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-03-14 12:41:40.668 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 12: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 9
2020-03-14 12:41:40.670 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 12: Transaction not completed
2020-03-14 12:41:40.672 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-14 12:41:40.672 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2020-03-14 12:41:40.673 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 12: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 9
2020-03-14 12:41:40.675 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-03-14 12:41:40.676 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-14 12:41:40.676 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:40.678 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-14 12:41:40.680 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:40.681 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 12: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 9
2020-03-14 12:41:40.683 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-14 12:41:40.684 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 12: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 9
2020-03-14 12:41:40.686 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:40.688 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2020-03-14 12:41:40.690 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 12: Advanced to WAIT_REQUEST
2020-03-14 12:41:40.691 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 12: Transaction not completed
2020-03-14 12:41:40.693 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-14 12:41:40.695 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-14 12:41:44.768 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 09 01 E1 
2020-03-14 12:41:44.774 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=9, payload=09 01 
2020-03-14 12:41:44.776 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=9, payload=09 01 
2020-03-14 12:41:44.777 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 12: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 9
2020-03-14 12:41:44.779 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-14 12:41:44.781 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 12: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 9
2020-03-14 12:41:44.782 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 12: (Callback 9)
2020-03-14 12:41:44.784 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-03-14 12:41:44.786 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 12: callback 9
2020-03-14 12:41:44.787 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=9, payload=09 01 
2020-03-14 12:41:44.789 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 9, Status = Transmission complete, no ACK received(1)
2020-03-14 12:41:44.791 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 12: Transaction CANCELLED
2020-03-14 12:41:44.793 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2020-03-14 12:41:44.814 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: CANCEL while sending message. Requeueing - 1 attempts left!
2020-03-14 12:41:44.815 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 12: Transaction RESET with 1 retries remaining.
2020-03-14 12:41:44.817 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2020-03-14 12:41:44.818 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 12 to queue - size 1
2020-03-14 12:41:44.819 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-14 12:41:44.821 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 13 02 01 00 25 0A C8 
2020-03-14 12:41:44.823 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 08 00 13 02 01 00 25 0A C8 
2020-03-14 12:41:44.826 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-03-14 12:41:44.826 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-03-14 12:41:44.827 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 12: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 10
2020-03-14 12:41:44.827 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-14 12:41:44.829 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 12: Transaction not completed
2020-03-14 12:41:44.831 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-14 12:41:44.832 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 12: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 10
2020-03-14 12:41:44.832 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2020-03-14 12:41:44.833 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-03-14 12:41:44.836 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-14 12:41:44.837 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-14 12:41:44.843 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:44.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:44.846 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 12: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 10
2020-03-14 12:41:44.848 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-14 12:41:44.849 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 12: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 10
2020-03-14 12:41:44.851 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:44.852 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2020-03-14 12:41:44.854 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 12: Advanced to WAIT_REQUEST
2020-03-14 12:41:44.855 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 12: Transaction not completed
2020-03-14 12:41:44.857 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-14 12:41:44.858 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-14 12:41:48.943 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 0A 01 E2 
2020-03-14 12:41:48.947 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=10, payload=0A 01 
2020-03-14 12:41:48.950 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=10, payload=0A 01 
2020-03-14 12:41:48.952 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 12: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 10
2020-03-14 12:41:48.954 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-14 12:41:48.956 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 12: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 10
2020-03-14 12:41:48.959 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 12: (Callback 10)
2020-03-14 12:41:48.961 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-03-14 12:41:48.963 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 12: callback 10
2020-03-14 12:41:48.968 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=10, payload=0A 01 
2020-03-14 12:41:48.971 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 10, Status = Transmission complete, no ACK received(1)
2020-03-14 12:41:48.973 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 12: Transaction CANCELLED
2020-03-14 12:41:48.975 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2020-03-14 12:41:48.977 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Retry count exceeded. Discarding message: TID 12: [CANCELLED] priority=Poll, requiresResponse=true, callback: 10
2020-03-14 12:41:48.978 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 12: Transaction completed
2020-03-14 12:41:48.980 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:12 CANCELLED
2020-03-14 12:41:48.982 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2020-03-14 12:41:48.982 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 12: Transaction event listener: DONE: CANCELLED -> 
2020-03-14 12:41:48.986 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-14 12:41:48.986 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1e75a0a
2020-03-14 12:41:48.988 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-14 12:41:56.728 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: ZWaveCommandClassTransactionPayload - send to node
2020-03-14 12:41:56.730 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2020-03-14 12:41:56.732 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Command Class COMMAND_CLASS_NO_OPERATION is NOT required to be secured
2020-03-14 12:41:56.733 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@d4eb5d
2020-03-14 12:41:56.735 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2020-03-14 12:41:56.737 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 13 to queue - size 1
2020-03-14 12:41:56.738 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-14 12:41:56.741 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 13 02 01 00 25 0B C9 
2020-03-14 12:41:56.743 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 08 00 13 02 01 00 25 0B C9 
2020-03-14 12:41:56.747 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-03-14 12:41:56.748 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-14 12:41:56.751 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-14 12:41:56.754 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2020-03-14 12:41:56.752 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-03-14 12:41:56.756 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-03-14 12:41:56.758 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-14 12:41:56.762 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-03-14 12:41:56.763 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 13: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 11
2020-03-14 12:41:56.765 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-14 12:41:56.765 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:56.767 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:56.768 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 13: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 11
2020-03-14 12:41:56.769 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-14 12:41:56.770 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 13: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 11
2020-03-14 12:41:56.772 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-14 12:41:56.773 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2020-03-14 12:41:56.774 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 13: Advanced to WAIT_REQUEST
2020-03-14 12:41:56.776 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 13: Transaction not completed
2020-03-14 12:41:56.778 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-14 12:41:56.780 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

Of course, as soon as I post to the forum, I find the answer.

The issue ended up being some issue with the Rpi4 USB architecture. Plugging the Z-Stick into a USB 2.0 Hub fixed my issue.

The issue is with the stick & USB3 compatibility. The stick is responding incorrectly.