Issue adding new zwave things

Hello all,

I just upgraded to version 3.4.0 snapshot build#3082 and now I am running into an interested issue. I am trying to add a new Honeywell T6 thermostat, while going through the inclusion process the thermostat show as it was successfully included but openhab does not show any new device being found.
Any ideas?

Have you looked to see if it created an XML file? I have seen once before it was creating the XML file but needed to restart openhab to load it. Also, since you are on a snapshot build maybe try a different build version incase its a bug.

No XML file created. Tried uninstalling the binding and re-installing but not luck. I also tried flipping to openhab3 instead of main branch but the version did not change.

There was a zwave Scan issue with the latest binding (a file was renamed) with a work around noted here. However, this does not seem to be your problem and switching to the 3.3 release should have fixed it

I did run into that issue also, but the work around got me to the scan page but my issue is that the thermostat thinks it was added to the network while openhad does not log anything.

So there was nothing on the scan page? It is a long shot, but does show ignored show anything?

Nothing new on the ignored page.

My suggestion would be to “exclude devices” from the UI controller page then try again.

Are you on battery or a “c” wire?

It is using C wire, I have 2 other thermostat of the same model. I did try to exclude and include.

Maybe it is the device?

Did you try the exclude/include with the zwave binding in Debug? There might be a message there that provides a clue.

1 Like

The device seems to be working, I was able to reset to factory default and go through the inclusion process again, this time the node id changed from 25 to 26 on the device but nothing show us up on the UI.
I did find these entries in the logs but not sure if I am catching the whole handshake.

2022-09-12 19:35:36.958 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A F9 02 00 00 49 

2022-09-12 19:35:36.988 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=249, payload=F9 02 00 00 

2022-09-12 19:35:36.988 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=249, payload=F9 02 00 00 

2022-09-12 19:35:36.989 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2022-09-12 19:35:36.989 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0

2022-09-12 19:35:36.990 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null

2022-09-12 19:35:36.990 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=249, payload=F9 02 00 00 

2022-09-12 19:35:36.991 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: New node found.

2022-09-12 19:35:36.992 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2022-09-12 19:35:36.992 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2022-09-12 19:35:37.881 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A F9 07 00 00 4C 

2022-09-12 19:35:37.908 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=249, payload=F9 07 00 00 

2022-09-12 19:35:37.909 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=249, payload=F9 07 00 00 

2022-09-12 19:35:37.909 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2022-09-12 19:35:37.910 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0

2022-09-12 19:35:37.910 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null

2022-09-12 19:35:37.911 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=249, payload=F9 07 00 00 

2022-09-12 19:35:37.911 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Failed.

2022-09-12 19:35:37.912 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeStart, new event IncludeFail

2022-09-12 19:35:37.912 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.

2022-09-12 19:35:37.913 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 271 to queue - size 1

2022-09-12 19:35:37.913 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2022-09-12 19:35:37.914 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 FA 4F 

2022-09-12 19:35:37.915 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 FA 4F 

2022-09-12 19:35:37.916 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06

2022-09-12 19:35:37.917 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2022-09-12 19:35:37.937 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2022-09-12 19:35:37.938 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 271: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 250

2022-09-12 19:35:37.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2022-09-12 19:35:37.940 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 271: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 250

2022-09-12 19:35:37.940 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK

2022-09-12 19:35:37.941 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2022-09-12 19:35:37.941 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2022-09-12 19:35:37.969 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A FA 06 00 00 4E 

2022-09-12 19:35:37.998 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=250, payload=FA 06 00 00 

2022-09-12 19:35:37.999 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=250, payload=FA 06 00 00 

2022-09-12 19:35:37.999 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 271: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 250

2022-09-12 19:35:38.000 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2022-09-12 19:35:38.000 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 271: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 250

2022-09-12 19:35:38.001 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 271: (Callback 250)

2022-09-12 19:35:38.001 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!

2022-09-12 19:35:38.002 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 271: callback 250

2022-09-12 19:35:38.002 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=250, payload=FA 06 00 00 

2022-09-12 19:35:38.003 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.

2022-09-12 19:35:38.003 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeFail, new event IncludeDone

2022-09-12 19:35:38.004 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.

Not a lot to go on. The debug level of a successful inclusion is typically 600KB. There is a log viewer here. What the above shows is this;

. The key being add node status failed.

Once the scan is started (Discovery) a successful inclusion looks like this;


Note the added node should show up in yellow. Whatever is failing is happening before the section of the log you posted. EDIT: on closer look it seems the controller (zstick- that mostly handles the communication between the device and the binding) is telling the binding the add node merssage failed. How close is the device to the controller? What type of controller do you have? How and to what is the controller attached to the server running OH? Is it a Rpi?

Also how are you getting the Node ID, if nothing is showing up in the UI. Also the comment “the device seems to be working” is confusing. How do you know?

I’ve uploaded my whole log and here is a screenshot of the inclusion.



Interesting enough all my are listed in the inclusion process. Not sure if that is expected. To clarify my statement regarding the device, I think the thermostat is not the problem because it acquired a node id 26 which I can see on its LCD screen. I am using a RaZberry hat on a Rpi 4. Thermostat is 2 floors away from the Rpi, there is another thermostat on the 2nd floor not far from the new thermostat which is working properly.

Sorry for the 20 questions, but I haven’t encountered the “Add Node Status Failed” in over 100 inclusions, so I’m just casting a wide net. Usually NWI inclusion at least gets to “Unknown Device” (if the device is not in the DB). Anyway, thanks for the details. Listing all the device is normal. I picked an example from my files that was just one device I was using for testing. It is also normal after a factory reset for the device to have a higher node number. That tells me the factory reset was successful.

It could still be a communication issue the “Add Node” operation with a new device versus a well-established working node (with defined routes). Looking at Zniffer output of an inclusion, the first command is a NOP and then some commands to get the initial routing. If those are not getting Ack’ed maybe that is leading to failure.
initialization

With a portable zstick I would suggest getting closer or using the Silabs PC Controller, but with a hat those options aren’t available (or at least very complicated).

My only other thought is the security, although I thought this comes later (after discovery). On your controller UI “show Advanced” is security set for entry control devices only? Conversely maybe the device expects security? Also OH only supports S0 and S2 is supposed to fall back to S0, but that may not be working.

I definitely appreciate your feedback. Not sure if the thermostat is expecting security, I have 2 other thermostats of the same model and did not have an issue when I installed them. The security on the controller is set for entry control only. I am going to swap the my thermostats around this weekend and see how it behaves when closer to the controller where I was able to add my first thermostat. I would hate to have to rebuild this network again. It has been solid for over an year.

I just haven’t seen a failed inclusion message, so am only guessing at the cause :frowning_face:. One last check, does the controller UI, Advanced, show SIS as node 1?

Relocating is a good idea.

As far as i can tell no reason for failure on the logs, while the thermostat thinks it was added. I will try moving it closer and see.

Finally got around to moving the thermostat closer to the controller. I was then able to exclude and include the thermostat into the network. Moved it back to its original place and it continues to work. I can only assume something is funky with my network wide inclusion.

1 Like