Z-stick Gen5 not finding dimmer

  • Platform information:
    • Hardware: Banana Pro
    • OS: Armbian Bookworm Headless
    • Java Runtime Environment: OpenJDK 17
    • openHAB version: 4.1.1

I had a Banana Pro setup running OH with Insteon controllers for years but over time, one by one, the Insteon controllers died. I decided to try Z-Wave. I’ve had an older Aoetec Z-Stick Gen5 sitting new in box for a while now as well as a GE Enbrighten Z-Wave dimmer (model ZW3104).

I could use a sanity check because I can’t get the z-stick to pair with the smart dimmer. I’m not sure if I’m missing something or this stuff is old and not compatible.

I connected the Z-stick to my PC and used the Aoetec software to upgrade the firmware to v1.0.2. There was also a test utility to validate SUC - I think the purpose of this test was to give you some verbose logging during inclusion… exception nothing happened for me as I hit but button on the dimmer. OH aside, I tried unplugging the z-stick and hitting the button for inclusion mode and placing it directly next to the smart dimmer and nothing happened as I hit the button on the dimmer. Per the z-stick instructions, “The blue LED on Z-Stick will blink fast during a network neighbor discovery and stay solid for 2 seconds to indicate successful inclusion of the device into the network.)” Per the dimmer instructions, a single press of the button adds to the z-wave network.

With the z-stick plugged into my Banana Pro, I was able to setup OH binding and it says it’s online. By the way, I verified the BPro sees the device at /dev/ttyACM0. When I scan, nothing happens as I hit the button on the dimmer. I confirmed the dimmer works as a dimmer and I can manually turn on a light and dim it.

The openhab.log file doesn’t show anything out of the ordinary. I have an INFO line that says starting Zwave controller, then another line that says the timeout is 5000ms, Soft reset is false. I did not change any of the advanced binding settings. I’ve tried to factory reset both the z-stick and the dimmer… made no difference.

Am I missing any other troubleshooting steps? Try Azul Zulu instead?

Thanks!

Those components should work together. My guess is you’re not really getting the dimmer into inclusion mode.

I would increase the z-wave logging level to DEBUG and watch the OH log when you start SCAN mode. The log will show the stick is getting into Inclusion mode.

I’m suspicious that one click will put the dimmer into Inclusion. I would try several rapid clicks in the ON direction and then in the OFF direction.

What is the distance from the stick to the dimmer? It might help to bring them within a few feet of each other. Later when you have a z-wave network you can set the stick for network-wide inclusion, but you don’t have a network yet. For now, set the stick for high power inclusion in the Advanced settings.

OH aside, I tried unplugging the z-stick and hitting the button for inclusion mode and placing it directly next to the smart dimmer and nothing happened as I hit the button on the dimmer. Per the z-stick instructions, “The blue LED on Z-Stick will blink fast during a network neighbor discovery and stay solid for 2 seconds to indicate successful inclusion of the device into the network.)” Per the dimmer instructions, a single press of the button adds to the z-wave network.

Including into the bare stick will work but it needs to be connected to OH to find the DB and complete the device initialization.

If none of this works I would try to reset the dimmer by excluding it. For this you can use the bare stick. Put it in Exclusion by first going to Inclusion (blue flashing) and then holding the button for a few seconds until you get yellow flashing. Then exclude the dimmer using rapid clicks until you see a response on the stick.

Am I missing any other troubleshooting steps? Try Azul Zulu instead?

Changing Java versions is a waste of time IMHO.

I’m no z-wave expert, so others may chime in with better advice.

I’d agree with excluding it first to make sure it’s fully reset. I’m not a fan of the inclusion button on Aeotec sticks. It’s fine when it works, but it sometimes causes confusion with an already confusing process. In my opinion, it’s best to always do inclusion and exclusion from the software.

I would have thought the same, but that’s actually in the instructions.

Once the controller is ready to add your smart dimmer, singlepress and release the manual/program button on the smartdimmer to add it in the network.

And in this video.

what do you see in the log during inclusion?

Thank you @brianlay and @rpwong for your replies. I set the zwave binding log level to DEBUG, cleared the logs, did a Hard Reset from OH, then did a factory reset of the dimmer. Starting with a clean slate, here is what I observed:

2024-03-04 13:50:26.555 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller hard reset
2024-03-04 13:50:27.193 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:12b2eed3a2
2024-03-04 13:50:27.966 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 00 42 0B B2 
2024-03-04 13:50:27.980 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 11<>117 : Message: class=SetDefault[66], type=Request[0], dest=178, callback=11, payload=0B 
2024-03-04 13:50:31.518 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 20: Timeout at state WAIT_REQUEST. 3 retries remaining.
2024-03-04 13:50:31.528 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 20: Transaction is current transaction, so clearing!!!!!
2024-03-04 13:50:31.537 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 20: Transaction CANCELLED
2024-03-04 13:50:31.548 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:20 CANCELLED
2024-03-04 13:50:31.558 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-03-04 13:50:31.571 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 02 FE 
2024-03-04 13:50:31.581 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 02 FE 
2024-03-04 13:50:31.596 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2024-03-04 13:50:31.600 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2024-03-04 13:50:31.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 12<>116 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-03-04 13:50:31.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 21: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2024-03-04 13:50:31.697 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 25 01 02 08 00 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 00 05 00 C8 
2024-03-04 13:50:31.723 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 13<>115 : Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payl
oad=08 00 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00
2024-03-04 13:50:33.622 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 21: Timeout at state WAIT_RESPONSE. 3 retries remaining.
2024-03-04 13:50:33.633 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 21: Transaction is current transaction, so clearing!!!!!
2024-03-04 13:50:33.641 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 21: Transaction CANCELLED
2024-03-04 13:50:33.652 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:21 CANCELLED
2024-03-04 13:50:33.665 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-03-04 13:51:48.949 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:12b2eed3a2
2024-03-04 13:51:48.960 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeDone
2024-03-04 13:51:48.979 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion
2024-03-04 13:51:48.990 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done
2024-03-04 13:51:49.002 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:12b2eed3a2
2024-03-04 13:51:49.012 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2
2024-03-04 13:51:49.024 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2024-03-04 13:51:49.043 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion
2024-03-04 13:51:49.061 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true.
2024-03-04 13:51:49.077 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 22 to queue - size 1
2024-03-04 13:51:49.087 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-03-04 13:51:49.098 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 0C 7D 
2024-03-04 13:51:49.109 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 0C 7D 
2024-03-04 13:51:49.124 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2024-03-04 13:51:49.121 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2024-03-04 13:51:49.145 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 14<>114 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-03-04 13:51:49.157 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 0C 01 00 00 BF 
2024-03-04 13:51:49.160 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 22: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 12
2024-03-04 13:51:49.173 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 15<>113 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=12, payload=0
C 01 00 00
2024-03-04 13:51:54.184 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 22: Timeout at state WAIT_REQUEST. 3 retries remaining.
2024-03-04 13:51:54.193 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 22: Transaction is current transaction, so clearing!!!!!
2024-03-04 13:51:54.204 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 22: Transaction CANCELLED
2024-03-04 13:51:54.216 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:22 CANCELLED
2024-03-04 13:51:54.260 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-03-04 13:52:49.002 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:12b2eed3a2
2024-03-04 13:52:49.016 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeSent
2024-03-04 13:52:49.026 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2024-03-04 13:52:49.037 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 23 to queue - size 1
2024-03-04 13:52:49.047 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-03-04 13:52:49.057 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 0D B8 
2024-03-04 13:52:49.069 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 0D B8 
2024-03-04 13:52:49.079 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2024-03-04 13:52:49.088 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2024-03-04 13:52:49.089 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 23: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 13
2024-03-04 13:52:49.108 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 16<>112 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-03-04 13:52:49.135 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 0D 06 02 00 BB 
2024-03-04 13:52:49.148 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 17<>111 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=13, payload=0
D 06 02 00 
2024-03-04 13:52:54.104 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 23: Timeout at state WAIT_REQUEST. 3 retries remaining.
2024-03-04 13:52:54.137 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 23: Transaction is current transaction, so clearing!!!!!
2024-03-04 13:52:54.175 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 23: Transaction CANCELLED
2024-03-04 13:52:54.209 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:23 CANCELLED
2024-03-04 13:52:54.240 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-03-04 13:53:04.104 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion timer at IncludeDone

I hit the button on the dimmer twice while scanning from OH. I see “AddNodeToNetwork[74]” twice in the logs. However, nothing happened after the scan. No things found by OH.

The log snippet does confirm that the button press on the device is not getting picked up.
Of some concern is the incoming message “stack” processReceiveMessage input 12<>116
Could you capture a debug from a zwave (or system restart) just to see what is happening before inclusion. You do have the controller set as sis node “1”.

This is the log from a system restart:

A couple odd observations, hopefully you can explain:
2024-03-05 09:55:18.085 [DEBUG] [l.initialization.ZWaveNodeSerializer]
NODE 1: Serializing from file /var/lib/openhab/zwave/network_d127c7b6__node_1.xml
NODE 1: Error serializing from file: file does not exist.
I checked this folder and I have several xml files here with the same contents. It it normal to create a new file every time the binding is initialized?

A little further down:
2024-03-05 09:55:18.338 [WARN ] [.core.thing.binding.BaseThingHandler]
Attempt to apply invalid configuration ‘Configuration[{key=controller_softreset; type=Boolean; value=false}, {key=security_networkkey; type=String; value=56 FE A4 06 6B 91 FA 5A D1 F9 53 79 FE 90 4A 51}, {key=security_inclusionmode; type=BigDecimal; value=0}, {key=controller_sisnode; type=BigDecimal; value=0}, {key=controller_maxawakeperiod; type=BigDecimal; value=10}, {key=controller_sync; type=Boolean; value=false}, {key=controller_master; type=Boolean; value=true}, {key=inclusion_mode; type=BigDecimal; value=2}, {key=port; type=String; value=/dev/ttyACM0}, {key=controller_wakeupperiod; type=BigDecimal; value=3600}, {key=controller_exclude; type=Boolean; value=false}, {key=heal_time; type=BigDecimal; value=2}, {key=controller_inclusiontimeout; type=BigDecimal; value=30}, {key=controller_hardreset; type=Boolean; value=false}]’ on thing ‘zwave:serial_zstick:12b2eed3a2’ blocked. This is most likely a bug: {controller_sisnode=The value must not be less than 1.}

Thanks for your insights!

By the way, if I go into the Advanced Binding Settings, SIS Node is set to 1.

Well this is very likely the problem, so we need to get this picked up by the binding as a first step. See this other thread (that is why I asked about it).

Anyway try this; go to the Controller UI page, then click on the “code” Is sisnode “1”? If not, change and hit save. May need to restart. If it is 1, change the max awake period to 11 and hit save. It should get picked up.

I’ll review the logs for anything else. EDIT: there is nothing else.

One step further! sisnode was already set to 1, I set max awake period to 11, saved, and rebooted. This time around, when I scanned, I had a new Thing in my Inbox!

2024-03-05 14:41:10.165 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=2, payload=02 06 02 00 
2024-03-05 14:41:10.169 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.
2024-03-05 14:41:10.174 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovered
2024-03-05 14:41:10.211 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:12b2eed3a2:node2' to inbox.
2024-03-05 14:41:10.222 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeDone, new event IncludeDone
2024-03-05 14:41:10.292 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.

If you go by the debug log, things seem OK

2024-03-05 14:52:56.523 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:12b2eed3a2:node2.
2024-03-05 14:52:56.543 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: MANUFACTURER not set
2024-03-05 14:52:56.552 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Controller status changed to ONLINE.
2024-03-05 14:52:56.557 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Controller is ONLINE. Starting device initialisation.
2024-03-05 14:52:56.568 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2024-03-05 14:52:56.572 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising Thing Node...
2024-03-05 14:52:56.582 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling initialised at 86400 seconds - start in 39484800 milliseconds.
2024-03-05 14:52:56.587 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Device initialisation complete.

However, the dimmer is offline in the UI.
Screenshot 2024-03-05 3.25.14 PM

Thing Type says Unknown. Given the DEBUG log says initialization is complete, does this mean it’s not in the device db?

What I deduced from the logs was that the sisnode was set to 1 AFTER it was too late and it was not in a SAVED state. Doing the trick with the max awake period was to get it saved, so progress.

Now the problem is that Node 2 was partially included before the sisnode fix and so it stuck. One thing to try would be to put zwave in inclusion mode and hit the button and maybe it will pick up where it left off. Another thing to try would be to try to exclude the node using the controller UI page “exclude nodes” and do the button push on the dimmer. Debug will show if this worked. Another is to just do the factory reset on the dimmer, then try inclusion again. I’m pretty sure the device is in the DB, but we need to get past the MANUFACTURER not set stage.

This appears to have worked! I excluded, then included again and watched the logs and success! When I went to the Inbox, the actual name of the Dimmer appeared. When I added the new thing, I got the ONLINE status! Thank you for your help, @apella12!

Since you are so knowledgeable of Z-Wave, are there any brand of controllers or sensors that you recommend? My Insteon gear slowly died over time and I read that they used bad capacitors. I’d like to avoid problems like that with my z-wave implementation!

I would stick with the major brands Aeotec, Zooz, Fibaro, GE (that is what I have). Zooz and Aeotec product support seem particular good. Most of my gear is Zooz (from the smartest house) and Aeotec.

Separately, I’m not a huge fan of the sensors with coin batteries, the older ones with the bigger Cr123 last at lot longer. It is more wires, but have also favored dual battery/USB sensors. On USB power they act as repeaters. Good luck.

All my GE wall switches failed after a few years. I’m completely Zooz now

GE/Jasco wall switches have been okay for me. I’ve had one or two fail, but I have them in an area where there are frequent power glitches and interruptions, so that’s probably not surprising. The newer wall switches from Jasco are smaller and easier to fit in the wall box than the older ones.

I have a Zooz controller and a dual wall switch which works well. Zooz battery powered devices have been terrible for me. Poor battery life, weird falling off the network, etc. Maybe it’s just my bad luck. I’ve updated firmware which didn’t help, so now when as each battery runs out, I get rid of them and replace with something more reliable. The controller and wall switch are fine.

For me at least the Zigbee battery powered sensors are longer lasting and more reliable than Z-wave. They have fewer features, but they work well. Again, maybe just luck for me.