Leviton Z-Wave VRCZ1 switch

Hardware Home Automation
1

I have 1 z-wave device I seem to be unable to include in my network. I’ve tried to exclude it, I’ve reset the device, no luck. Debug traces below. From looking at the web, someone in the Home Assistant forums suggested this particular z-wave device is somehow “different”. No clue, but it doesn’t show up as unknown or anything. Suggestions appreciated. Thanks.

At time 09:35:15.067 in the log below I see an add node to network that appears to fail. I put this thru the log viewer but didn’t gain much more knowledge and I’m not quite sure how to include that image here.

2020-02-11 09:35:04.474 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:d1f10b47
2020-02-11 09:35:04.475 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2
2020-02-11 09:35:04.475 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2020-02-11 09:35:04.476 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion
2020-02-11 09:35:04.476 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true.
2020-02-11 09:35:04.476 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 125 to queue - size 1
2020-02-11 09:35:04.477 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-11 09:35:04.477 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 AC DD 
2020-02-11 09:35:04.477 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 AC DD 
2020-02-11 09:35:04.478 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-02-11 09:35:04.478 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 125: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 172
2020-02-11 09:35:04.479 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-02-11 09:35:04.479 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-11 09:35:04.479 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-11 09:35:04.480 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 125: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 172
2020-02-11 09:35:04.480 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-02-11 09:35:04.480 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-11 09:35:04.480 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A AC 01 00 00 1F 
2020-02-11 09:35:04.481 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-02-11 09:35:04.481 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=172, payload=AC 01 00 00 
2020-02-11 09:35:04.482 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=172, payload=AC 01 00 00 
2020-02-11 09:35:04.482 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 125: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 172
2020-02-11 09:35:04.482 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-02-11 09:35:04.482 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 125: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 172
2020-02-11 09:35:04.482 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 125: (Callback 172)
2020-02-11 09:35:04.482 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-02-11 09:35:04.482 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 125: callback 172
2020-02-11 09:35:04.483 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=172, payload=AC 01 00 00 
2020-02-11 09:35:04.483 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready.
2020-02-11 09:35:04.483 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart
2020-02-11 09:35:04.483 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 125: Transaction COMPLETED
2020-02-11 09:35:04.483 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 5ms
2020-02-11 09:35:04.484 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 125: Transaction completed
2020-02-11 09:35:04.484 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:125 DONE
2020-02-11 09:35:04.487 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-11 09:35:04.487 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-11 09:35:06.479 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 9: Device discovery completed
2020-02-11 09:35:06.481 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 9: Device discovery resolved to thingType zwave:leviton_vri06_00_000
2020-02-11 09:35:06.483 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 11: Device discovery completed
2020-02-11 09:35:06.484 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 11: Device discovery resolved to thingType zwave:leviton_vrs15_00_000
2020-02-11 09:35:12.157 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A AC 02 00 00 1C 
2020-02-11 09:35:12.157 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=172, payload=AC 02 00 00 
2020-02-11 09:35:12.158 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=172, payload=AC 02 00 00 
2020-02-11 09:35:12.158 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-02-11 09:35:12.158 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
2020-02-11 09:35:12.158 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null
2020-02-11 09:35:12.159 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=172, payload=AC 02 00 00 
2020-02-11 09:35:12.159 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: New node found.
2020-02-11 09:35:12.159 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-11 09:35:12.159 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-11 09:35:15.065 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A AC 07 0B 00 12 
2020-02-11 09:35:15.066 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=172, payload=AC 07 0B 00 
2020-02-11 09:35:15.066 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=172, payload=AC 07 0B 00 
2020-02-11 09:35:15.066 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-02-11 09:35:15.067 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
2020-02-11 09:35:15.067 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null
2020-02-11 09:35:15.067 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=172, payload=AC 07 0B 00 
2020-02-11 09:35:15.067 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Failed.
2020-02-11 09:35:15.067 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeStart, new event IncludeFail
2020-02-11 09:35:15.068 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2020-02-11 09:35:15.068 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 126 to queue - size 1
2020-02-11 09:35:15.068 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-11 09:35:15.068 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 AD 18 
2020-02-11 09:35:15.068 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 AD 18 
2020-02-11 09:35:15.069 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-02-11 09:35:15.069 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 126: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 173
2020-02-11 09:35:15.070 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-11 09:35:15.070 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-02-11 09:35:15.070 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-02-11 09:35:15.070 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-11 09:35:15.070 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-11 09:35:15.071 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 126: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 173
2020-02-11 09:35:15.071 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-02-11 09:35:15.071 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-11 09:35:15.071 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-02-11 09:35:15.120 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A AD 06 0B 00 12 
2020-02-11 09:35:15.121 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=173, payload=AD 06 0B 00 
2020-02-11 09:35:15.121 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=173, payload=AD 06 0B 00 
2020-02-11 09:35:15.121 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 126: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 173
2020-02-11 09:35:15.121 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-02-11 09:35:15.121 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 126: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 173
2020-02-11 09:35:15.121 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 126: (Callback 173)
2020-02-11 09:35:15.122 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-02-11 09:35:15.122 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 126: callback 173
2020-02-11 09:35:15.122 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=173, payload=AD 06 0B 00 
2020-02-11 09:35:15.122 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.
2020-02-11 09:35:15.122 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 11: Device discovered
2020-02-11 09:35:15.123 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got an event from Z-Wave network: ZWaveInclusionEvent
2020-02-11 09:35:15.123 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeFail, new event IncludeDone
2020-02-11 09:35:15.123 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2020-02-11 09:35:15.123 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 127 to queue - size 1
2020-02-11 09:35:15.123 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-02-11 09:35:15.124 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion
2020-02-11 09:35:15.124 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done
2020-02-11 09:35:15.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 126: Advanced to DONE
2020-02-11 09:35:15.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 55ms
2020-02-11 09:35:15.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 126: Transaction completed
2020-02-11 09:35:15.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:126 DONE
2020-02-11 09:35:15.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-11 09:35:15.125 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-11 09:35:15.125 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 00 B5 
2020-02-11 09:35:15.125 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5 
2020-02-11 09:35:15.125 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-02-11 09:35:15.126 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 127: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2020-02-11 09:35:15.126 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-02-11 09:35:15.126 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-11 09:35:15.126 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-02-11 09:35:15.127 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 127: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2020-02-11 09:35:15.127 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-02-11 09:35:15.127 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-11 09:35:15.127 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-02-11 09:35:20.127 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 127: Timeout at state WAIT_REQUEST. 3 retries remaining.
2020-02-11 09:35:20.127 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 127: Transaction is current transaction, so clearing!!!!!
2020-02-11 09:35:20.127 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 127: Transaction CANCELLED
2020-02-11 09:35:20.127 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:127 CANCELLED
2020-02-11 09:35:20.128 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-11 09:36:04.474 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:d1f10b47
2020-02-11 09:36:04.474 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do
2

I do not see that device listed in our database.

Here is the database guide of you wish to add it.
https://www.cd-jackson.com/index.php/zwave/zwave-device-database/zwave-device-database-guide

Otherwise we need the xml file generated by OH in the userdata/zwave folder and a link to the user guide.

3

But doesn’t OH need to see the device as a thing, even if it is unknown before it can be added to the device database?

4

Yes… you’ll need to add the Thing from the Inbox before the device will be interrogated and the xml will be created. Or does it get interrogated in the Inbox?

1 Like
5

No - that’s not correct. The interview is not dependant on the device being a thing - the protocol and OH parts of the binding are pretty much separate.

The XML file should be generated even it it’s not a thing.

2 Likes
6

Well, I’ll check when I’m home and see if there is an XML. But given it doesn’t show after I attempt to include… Do we think adding it to the database will fix not getting an unknown thing when attempting to include it?

7

If you update to a snapshot binding including the changes, yes.

8

Sorry, but in userdata/zwave there are only 3 xml files, one for the controller and 2 for 2 other switches. The switch I attempted to add is not there. So, something else is going on… Any additional debug I can capture?

9

The log you provided shows that the inclusion failed - I’m afraid it’s not possible to tell why, but the controller did not include the device into the network. All I can suggest is to try this again - until the controller includes the device, the binding can’t do anything.

10

Factory reset the device first. I recall some devices that would not include until I did that first.

11

Pilot error. I now have an XML file. This switch of course has a slightly different way of putting into inclusion mode than their VRI06 and VRS15 switches. I’ll work on getting info to database. Thank you all for the help! Next time I read the instructions closer.

1 Like