Zwave troubleshooting Aeotec Gen5+ ERROR:BRIDGE

Setup, Configuration and Use Installation
,
1
  • Platform information:
    • Hardware: Raspberry Pi4 4GB
    • OS: Ubuntu
    • Java Runtime Environment: openjdk version 11.0.14
    • openHAB version: 3.20
  • Issue of the topic: zwave stick cannot communicate
    Freshly installed openhab on Freshly installed Ubuntu. openhab is a member of tty, dialout
    originally started with a Gen5 stick that was working on a previous installation (via USB hub), but in troubleshooting this issue, have replaced that with a Gen5+. Deleted & rediscovered the thing multiple times, removed and readded the binding multiple times. Port occasionally appears in the dropdown box (after deleting the thing). Have this error throug karaf log:tail

    [DEBUG] [ng.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:ab82d8833c

But also this (which suggests that the thing is trying to communicate?)

00:53:36.110 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - Creating ZWave discovery service for zwave:serial_zstick:ab82d8833c with scan time of 60
00:53:36.113 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Active zwave:serial_zstick:ab82d8833c
00:53:36.115 [INFO ] [.zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null
00:53:36.147 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:serial_zstick:ab82d8833c’ changed from UNINITIALIZED to INITIALIZING
00:53:36.154 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller.
00:53:36.156 [DEBUG] [.zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:ab82d8833c.
00:53:36.158 [DEBUG] [.zwave.handler.ZWaveControllerHandler] - No network key set by user - using random value.
00:53:36.170 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:serial_zstick:ab82d8833c’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
00:53:41.173 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Connecting to serial port ‘/dev/ttyAMA0’
00:53:41.183 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Starting receive thread
00:53:41.185 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
00:53:41.186 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive
00:53:41.188 [DEBUG] [.zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller
00:53:41.191 [INFO ] [ave.internal.protocol.ZWaveController] - Starting ZWave controller
00:53:41.191 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
00:53:41.193 [INFO ] [ave.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
00:53:41.194 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
00:53:41.197 [DEBUG] [ave.internal.protocol.ZWaveController] - Event listener added.
00:53:41.199 [DEBUG] [ave.internal.protocol.ZWaveController] - Event listener added.
00:53:41.201 [DEBUG] [.zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 2 hours time.
00:53:44.196 [DEBUG] [l.ZWaveController$InitializeDelayTask] - Initialising network
00:53:44.200 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Added 5 to queue - size 1
00:53:44.202 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
00:53:44.206 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9
00:53:44.208 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9
00:53:44.211 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
00:53:44.212 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 5: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
00:53:44.214 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Added 6 to queue - size 1
00:53:44.216 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
00:53:44.218 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Added 7 to queue - size 2
00:53:44.220 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
00:53:44.221 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Added 8 to queue - size 3
00:53:44.223 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
00:53:44.224 [DEBUG] [erialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID
00:53:44.226 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Added 9 to queue - size 4
00:53:44.228 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
00:53:46.215 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 255: TID 5: Timeout at state WAIT_RESPONSE. 3 retries remaining.
00:53:46.217 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - TID 5: Transaction is current transaction, so clearing!!!
00:53:46.219 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 5: Transaction CANCELLED
00:53:46.221 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:5 CANCELLED
00:53:46.223 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
00:53:46.226 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 20 DC
00:53:46.228 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 20 DC
00:53:46.230 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
00:53:46.232 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 6: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
00:53:48.234 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 255: TID 6: Timeout at state WAIT_RESPONSE. 3 retries remaining.
00:53:48.237 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - TID 6: Transaction is current transaction, so clearing!!!
00:53:48.239 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 6: Transaction CANCELLED
00:53:48.241 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:6 CANCELLED
00:53:48.244 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
00:53:48.247 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 07 FB
00:53:48.249 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 07 FB
00:53:48.251 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
00:53:48.252 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
00:53:50.254 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 255: TID 7: Timeout at state WAIT_RESPONSE. 3 retries remaining.
00:53:50.257 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - TID 7: Transaction is current transaction, so clearing!!!
00:53:50.259 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 7: Transaction CANCELLED
00:53:50.262 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:7 CANCELLED
00:53:50.265 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
00:53:50.268 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 06 96 0F 65
00:53:50.269 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 06 96 0F 65
00:53:50.271 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
00:53:50.273 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 8: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
00:53:52.275 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 255: TID 8: Timeout at state WAIT_RESPONSE. 3 retries remaining.
00:53:52.278 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - TID 8: Transaction is current transaction, so clearing!!!
00:53:52.280 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 8: Transaction CANCELLED
00:53:52.282 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:8 CANCELLED
00:53:52.284 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
00:53:52.288 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 56 AA
00:53:52.290 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 56 AA
00:53:52.292 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
00:53:52.294 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 9: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
00:53:54.296 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 255: TID 9: Timeout at state WAIT_RESPONSE. 3 retries remaining.
00:53:54.299 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - TID 9: Transaction is current transaction, so clearing!!!
00:53:54.302 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 9: Transaction CANCELLED
00:53:54.304 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:9 CANCELLED
00:53:54.307 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

So it seems openhab thinks it is sending, but not getting any replies

Searched here and Google (most issues are about permissions, or the USB hub issue), and I’ve got myself in a knot - any assistance would be appreciated!

Cheers

2

That is what it looks like to me as well. Everything looks normal until the request messages start (TID 5) and do not get a response and are cancelled. These are normally very quick because they are between the binding and the zstick. I do not know why after finding the zstick there is no communication. Have you tried to put the USB hub back?
The “no BridgeUID” message is not an issue.

Bob

3

Thanks for the response Bob,
Yep, tried with the USB hub and without. The Gen5 (working prior to reimaging the Pi) gives the same results (with the hub) as the Gen5+ with or without the hub.
I’ve plugged the stick into a laptop and used a Zensys tool to read the network from it, so I’m convinced that the stick is communicating ‘serially’.
Edit: removed question easily answered by Google!
Biting the bullet & switching to Openhabian

4

I do not know if it matters, but are you using the usb2? (Black). Zwave, at best, is 100kB.

Bob

5

Tried both: no difference. Have reimaged with Openhabian & /dev/ttyACM0 turned up in the dropdown as well as /dev/ttyAMA0 Selected ACM0 & bridge comes online. A bit of Google-fu leads to a comment in Home Assistant forum:

/dev/ttyAMA0 is the [RPi’s UART] Raspberry Pi Documentation - Configuration), it will never belong to an Aeotec Z-Stick plugged into a USB port. The Aeotec will definitely be /dev/ttyACM0, or the preferred /dev/serial/by-id/usb-0658_0200-if00

Under Ubuntu /dev/ttyAMA0 came and went as I unplugged the stick and /dev/ttyACM0 never appeared at all. No idea what the issue was, but going to spend the day working out how to install pihole &c on Openhabian. Thanks for your help