[Solved] Z-wave Bridge OFFLINE - Normal with no Devices?

I recently acquired a Silicon Labs / ACC-UZB3-U-STA Z-wave stick and plan to try out Z-wave as an alternative to the wifi connected devices I am currently using with OpenHAB 3.0.1 on a Pi4B running OpenHABian 2.5.11-1.

After installing the stick and the binding, I added the bridge Thing manually using the UI. OpenHAB shows that it the bridge Thing is OFFLINE.

I don’t yet have any Z-wave devices to connect to the network. The first one is arriving later this week.
My question is whether the OFFLINE means there is something wrong with my installation of the stick, or it it just telling me that since I don’t have any Z-wave devices yet, that the bridge has nothing to connect to.

If the former, any suggestions for troubleshoot?

Here is the log following an activation of the Thing.

2021-06-06 19:23:06.688 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - Creating ZWave discovery service for zwave:serial_zstick:d55bff6cef with scan time of 60

2021-06-06 19:23:06.690 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Active zwave:serial_zstick:d55bff6cef

2021-06-06 19:23:06.691 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null

2021-06-06 19:23:06.726 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller.

2021-06-06 19:23:06.727 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:d55bff6cef.

==> /var/log/openhab/events.log <==

2021-06-06 19:23:06.719 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zwave:serial_zstick:d55bff6cef' changed from UNINITIALIZED (DISABLED) to INITIALIZING

2021-06-06 19:23:06.728 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zwave:serial_zstick:d55bff6cef' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab/openhab.log <==

2021-06-06 19:23:11.730 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyAMA0'

2021-06-06 19:23:11.738 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Starting receive thread

2021-06-06 19:23:11.740 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized

2021-06-06 19:23:11.740 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive

2021-06-06 19:23:11.741 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller

2021-06-06 19:23:11.743 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller

2021-06-06 19:23:11.743 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2021-06-06 19:23:11.744 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2021-06-06 19:23:11.744 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.

2021-06-06 19:23:11.746 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.

2021-06-06 19:23:11.749 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.

2021-06-06 19:23:11.750 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 7 hours time.

2021-06-06 19:23:14.746 [DEBUG] [.ZWaveController$InitializeDelayTask] - Initialising network

2021-06-06 19:23:14.751 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 19 to queue - size 1

2021-06-06 19:23:14.752 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2021-06-06 19:23:14.753 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9 

2021-06-06 19:23:14.754 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9 

2021-06-06 19:23:14.784 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2021-06-06 19:23:14.785 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 19: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2021-06-06 19:23:14.786 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 20 to queue - size 1

2021-06-06 19:23:14.787 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2021-06-06 19:23:14.787 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 21 to queue - size 2

2021-06-06 19:23:14.788 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2021-06-06 19:23:14.789 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 22 to queue - size 3

2021-06-06 19:23:14.789 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2021-06-06 19:23:14.790 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID

2021-06-06 19:23:14.791 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 23 to queue - size 4

2021-06-06 19:23:14.791 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2021-06-06 19:23:16.786 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 19: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2021-06-06 19:23:16.787 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 19: Transaction is current transaction, so clearing!!!!!

2021-06-06 19:23:16.788 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 19: Transaction CANCELLED

2021-06-06 19:23:16.789 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:19 CANCELLED

2021-06-06 19:23:16.790 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2021-06-06 19:23:16.800 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 20 DC 

2021-06-06 19:23:16.801 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 20 DC 

2021-06-06 19:23:16.824 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2021-06-06 19:23:16.825 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 20: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2021-06-06 19:23:18.825 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 20: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2021-06-06 19:23:18.826 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 20: Transaction is current transaction, so clearing!!!!!

2021-06-06 19:23:18.826 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 20: Transaction CANCELLED

2021-06-06 19:23:18.827 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:20 CANCELLED

2021-06-06 19:23:18.828 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2021-06-06 19:23:18.832 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 07 FB 

2021-06-06 19:23:18.833 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 07 FB 

2021-06-06 19:23:18.854 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2021-06-06 19:23:18.855 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 21: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2021-06-06 19:23:20.855 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 21: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2021-06-06 19:23:20.855 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 21: Transaction is current transaction, so clearing!!!!!

2021-06-06 19:23:20.856 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 21: Transaction CANCELLED

2021-06-06 19:23:20.856 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:21 CANCELLED

2021-06-06 19:23:20.857 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2021-06-06 19:23:20.859 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 06 96 0F 65 

2021-06-06 19:23:20.860 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 06 96 0F 65 

2021-06-06 19:23:20.894 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2021-06-06 19:23:20.896 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 22: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2021-06-06 19:23:22.896 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 22: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2021-06-06 19:23:22.897 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 22: Transaction is current transaction, so clearing!!!!!

2021-06-06 19:23:22.897 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 22: Transaction CANCELLED

2021-06-06 19:23:22.898 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:22 CANCELLED

2021-06-06 19:23:22.899 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2021-06-06 19:23:22.904 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 56 AA 

2021-06-06 19:23:22.905 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 56 AA 

2021-06-06 19:23:22.934 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2021-06-06 19:23:22.935 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 23: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2021-06-06 19:23:24.936 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 23: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2021-06-06 19:23:24.937 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 23: Transaction is current transaction, so clearing!!!!!

2021-06-06 19:23:24.937 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 23: Transaction CANCELLED

2021-06-06 19:23:24.938 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:23 CANCELLED

2021-06-06 19:23:24.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

No - this is not normal. The queue size is also increasing so there appears to be something wrong somewhere I’m afraid. It looks like the device is not responding as there doesn’t appear to be any data being received.

Thanks for pointing me in the right direction.

After searching the forum and reading this and other threads:

I determined that I had the incorrect serial address in the bridge set up. I used the dmesg | grep tty on my Pi4B, which showed the correct serial address, in my case

 openhabian@openhab:~$ dmesg | grep tty
[    0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1  smsc95xx.macaddr=DC:A6:32:82:41:2E vc_mem.mem_base=0x3f000000 vc_mem.mem_size=0x3f600000  console=ttyS0,115200 console=tty1 root=PARTUUID=0522baae-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
[    0.001812] printk: console [tty1] enabled
[    1.438687] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 36, base_baud = 0) is a PL011 rev2
[    3.177768] systemd[1]: Created slice system-getty.slice.
[    5.933131] cdc_acm 1-1.2:1.0: ttyACM0: USB ACM device
[606792.874156] cdc_acm 1-1.1:1.0: ttyACM0: USB ACM device
[606879.778072] cdc_acm 1-1.2:1.0: ttyACM0: USB ACM device

Now I’m ready to try my first Z-Waze device when it arrives later this week.

1 Like