[SOLVED] [ZWAVE] Device not showing when Searching for Things

mjeshurun · September 14, 2019, 4:34pm

Node 3 is the other switchbox we worked on with 2lights + 2blinds buttons.

And yes, once I pressed Search for Thing in OpenHAB, I also put the 4lights switchbox into inclusion mode.

chris · September 14, 2019, 4:36pm

Ok, then I’m not really sure. The controller is not reporting any new devices during the minute that inclusion is open.

mjeshurun · September 14, 2019, 4:39pm

That’s exactly the problem.
And that’s why it’s weird that Domoticz is able to see it

chris · September 14, 2019, 4:40pm

Sorry - I don’t really know. As I said, this isn’t related to openHAB - it’s only between the controller and the joining device once the controller has inclusion enabled (which looks find from this log).

mjeshurun · September 14, 2019, 4:45pm

OK. Thanks
I’ll try to browse the web for this. Maybe someone else reported a similar issue in the past.

Bruce_Osborne · September 14, 2019, 5:03pm

I think you said that was with the same controller. For a workaround, you should be able to include it with Domoticz and then the binding should see it when you restart OpenHAB. OPenHAB does not need to see the device inclusion to recognize it.

chris · September 14, 2019, 5:24pm

Domoticz will be doing exactly the same as openHAB - it’s just the standard call to put the controller into inclusion mode which is clearly working.

What is node 2? Is that a real node, or was this device excluded already?

mjeshurun · September 14, 2019, 5:34pm

Good idea. I’ll try adding the node to the controller with Domoticz and then check again in OpenHAB if it’s visible.

mjeshurun · September 14, 2019, 5:36pm

It was a real node, but I did a hard reset of the controller a few days ago and now I’m trying to re include them

chris · September 14, 2019, 5:51pm

That doesn’t really make sense.

If you hard reset the controller, then the first node added will always be node 2. Given that the device that works is node 3, there must have been a node 2 - or maybe there still is.

Can you provide the debug log from binding startup?

mjeshurun · September 14, 2019, 7:13pm

For the sake of a “clean” test, I hard reset the controller again, and then re-added the 2lights + 2blinds switchbox as Node 2.

After that I tried to add the 4light switchbox as a new thing in Inbox. Same as before, it wasn’t recognized as a node.

Here is the log. Please remember the 2+2 switchbox is now Node 2.

2019-09-14 22:06:49.328 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:dea8ca97
2019-09-14 22:06:49.329 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do
2019-09-14 22:06:49.331 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:dea8ca97
2019-09-14 22:06:49.331 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2
2019-09-14 22:06:49.333 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2019-09-14 22:06:49.333 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion
2019-09-14 22:06:49.333 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true.
2019-09-14 22:06:49.334 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 178 to queue - size 1
2019-09-14 22:06:49.334 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-14 22:06:49.334 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 AF DE 
2019-09-14 22:06:49.334 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 AF DE 
2019-09-14 22:06:49.335 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-09-14 22:06:49.335 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 178: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 175
2019-09-14 22:06:49.335 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-09-14 22:06:49.336 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-14 22:06:49.336 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-14 22:06:49.336 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 178: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 175
2019-09-14 22:06:49.336 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-09-14 22:06:49.336 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-14 22:06:49.336 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-14 22:06:49.338 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A AF 01 00 00 1C 
2019-09-14 22:06:49.338 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=175, payload=AF 01 00 00 
2019-09-14 22:06:49.338 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=175, payload=AF 01 00 00 
2019-09-14 22:06:49.339 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 178: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 175
2019-09-14 22:06:49.339 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-09-14 22:06:49.342 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 178: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 175
2019-09-14 22:06:49.342 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 178: (Callback 175)
2019-09-14 22:06:49.342 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-09-14 22:06:49.343 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 178: callback 175
2019-09-14 22:06:49.343 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=175, payload=AF 01 00 00 
2019-09-14 22:06:49.343 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready.
2019-09-14 22:06:49.343 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart
2019-09-14 22:06:49.343 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 178: Transaction COMPLETED
2019-09-14 22:06:49.344 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 9ms
2019-09-14 22:06:49.344 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 178: Transaction completed
2019-09-14 22:06:49.344 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:178 DONE
2019-09-14 22:06:49.344 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-14 22:06:49.344 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-14 22:06:51.341 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery completed
2019-09-14 22:06:51.342 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery resolved to thingType zwave:hogar_lmsxzwcl_00_000
2019-09-14 22:07:49.335 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:dea8ca97
2019-09-14 22:07:49.336 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeStart
2019-09-14 22:07:49.336 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2019-09-14 22:07:49.336 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 179 to queue - size 1
2019-09-14 22:07:49.337 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-14 22:07:49.337 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 B0 05 
2019-09-14 22:07:49.337 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 B0 05 
2019-09-14 22:07:49.337 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-09-14 22:07:49.338 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 179: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 176
2019-09-14 22:07:49.342 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-09-14 22:07:49.348 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-14 22:07:49.348 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-14 22:07:49.350 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 179: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 176
2019-09-14 22:07:49.351 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-09-14 22:07:49.351 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-14 22:07:49.352 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-14 22:07:49.395 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A B0 06 02 00 06 
2019-09-14 22:07:49.395 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=176, payload=B0 06 02 00 
2019-09-14 22:07:49.396 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=176, payload=B0 06 02 00 
2019-09-14 22:07:49.396 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 179: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 176
2019-09-14 22:07:49.396 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-09-14 22:07:49.396 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 179: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 176
2019-09-14 22:07:49.396 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 179: (Callback 176)
2019-09-14 22:07:49.397 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-09-14 22:07:49.397 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 179: callback 176
2019-09-14 22:07:49.397 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=176, payload=B0 06 02 00 
2019-09-14 22:07:49.397 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.
2019-09-14 22:07:49.397 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovered
2019-09-14 22:07:49.398 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveInclusionEvent
2019-09-14 22:07:49.398 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeDone, new event IncludeDone
2019-09-14 22:07:49.398 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2019-09-14 22:07:49.398 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 180 to queue - size 1
2019-09-14 22:07:49.398 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-14 22:07:49.398 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion
2019-09-14 22:07:49.398 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done
2019-09-14 22:07:49.398 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 179: Advanced to DONE
2019-09-14 22:07:49.398 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 60ms
2019-09-14 22:07:49.399 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 179: Transaction completed
2019-09-14 22:07:49.399 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:179 DONE
2019-09-14 22:07:49.399 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-14 22:07:49.399 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-14 22:07:49.399 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 00 B5 
2019-09-14 22:07:49.399 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5 
2019-09-14 22:07:49.399 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-09-14 22:07:49.399 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 180: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2019-09-14 22:07:49.400 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-09-14 22:07:49.401 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-14 22:07:49.401 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-14 22:07:49.401 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 180: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2019-09-14 22:07:49.401 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-09-14 22:07:49.401 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-14 22:07:49.401 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-14 22:07:54.406 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 180: Timeout at state WAIT_REQUEST. 3 retries remaining.
2019-09-14 22:07:54.406 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 180: Transaction is current transaction, so clearing!!!!!
2019-09-14 22:07:54.406 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 180: Transaction CANCELLED
2019-09-14 22:07:54.406 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:180 CANCELLED
2019-09-14 22:07:54.407 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

Bruce_Osborne · September 14, 2019, 7:28pm

That only shows node 2 added to the network.

mjeshurun · September 14, 2019, 7:41pm

yup, OpenHAB wasn’t able to recognize the 4light switch.

mjeshurun · September 14, 2019, 8:06pm

Seems like this workaround helped. After including the 4lights switchbox as a node in Domoticz, OpenHAB was able to automatically see the node in Inbox
However, the node is showing as Unknown Device, even though we added the device settings for the Lumi 2+2 switch to @chris 's database.
Does it means we need to define the 4lights switch as a separate device in the ZWave binding?

Bruce_Osborne · September 14, 2019, 8:10pm

Either that or discovery is not yet complete. Since this is mains powered, we likely need to add it to the database.
OoenHAB should have created an xml file in the zwave folder under userdata.,
If you could post that it would help determine the next steps.

mjeshurun · September 14, 2019, 8:13pm

Here is the file for node 3
network_ecead95f__node_3.xml (23.1 KB)

Bruce_Osborne · September 14, 2019, 8:23pm

Looks like we do not already have this. We do have a similar one though with a socket too.
Do you have a link to the user manual? A link to a sales site showing a product image would be helpful too.
After all the issues you have handles I am not going to add learning the database (yet).

EDIT: IT looks like it is in the database but has some issues. Checking it out now.
https://www.cd-jackson.com/index.php/zwave/zwave-device-database/zwave-device-list/devicesummary/1112

mjeshurun · September 14, 2019, 8:31pm

Thank you for sparing me the need to learn how to code and add the device to the database myself. I appreciate all your help with these issues

Externally, this device looks exactly the same as the 2+2 switch we added a few days ago. Lumi manufactures both devices.
Lumi

I only got one manual from the seller. Their IT guy said that, as far as he knows, the manual should be relevant to both devices.
User_Manual_Switch4_V1.0.pdf (535.5 KB)

Bruce_Osborne · September 14, 2019, 8:35pm

Thanks. That is a much better inage than I found.
@chris please change the image on device 1112 to the one labeled new.

mjeshurun · September 14, 2019, 8:38pm

I updated the device description for 1112 to better describe this particular switch:
Device Description Z-Wave Switch with 4 on/off light switches