Pi 4 OpenHabian 1.6 stable Razberry2 Z-Wave: Controller is Offline (again)

Fresh OpenHabian install on Raspberry Pi 4.

Image:

openhabian-pi-raspios32-202010031354-git535d54d-crc0cf8e591.img.xz

Module: https://www.amazon.com/Z-Wave-Me-RaZberry2-Plug-Raspberry-frequency/dp/B01M3Q764U

Light is on, fitted properly. Fresh out of the box.

OS

##        Ip = Unable to parse ip . Please debug.
##   Release = Raspbian GNU/Linux 10 (buster)
##    Kernel = Linux 5.4.72-v7l+
##  Platform = Raspberry Pi 4 Model B Rev 1.2
##    Uptime = 0 day(s). 0:0:49
## CPU Usage = 52.28% avg over 4 cpu(s) (4 core(s) x 1 socket(s))
##  CPU Load = 1m: 2.23, 5m: 0.65, 15m: 0.23
##    Memory = Free: 3.30GB (87%), Used: 0.48GB (13%), Total: 3.78GB
##      Swap = Free: 2.58GB (100%), Used: 0.00GB (0%), Total: 2.58GB
##      Root = Free: 23.55GB (84%), Used: 4.29GB (16%), Total: 29.07GB
##   Updates = 0 apt updates available.
##  Sessions = 1 session(s)
## Processes = 128 running processes of 32768 maximum processes

Hardware:

sudo lshw -short
H/W path    Device  Class      Description
==========================================
                    system     Raspberry Pi 4 Model B Rev 1.2
/0                  bus        Motherboard
/0/1                processor  cpu
/0/2                processor  cpu
/0/3                processor  cpu
/0/4                processor  cpu
/0/5                memory     3877MiB System memory
/0/0                bridge     Broadcom Limited
/0/0/0              bus        VL805 USB 3.0 Host Controller
/0/0/0/0    usb1    bus        xHCI Host Controller
/0/0/0/0/1          bus        USB2.0 Hub
/0/0/0/1    usb2    bus        xHCI Host Controller
/1          wlan0   network    Wireless interface
/2          eth0    network    Ethernet interface

Java:

openjdk version "1.8.0_265"
OpenJDK Runtime Environment (Zulu 8.48.3.246-CA-linux_aarch32hf) (build 1.8.0_265-b11)
OpenJDK Client VM (Zulu 8.48.3.246-CA-linux_aarch32hf) (build 25.265-b11, mixed mode)

OpenHab:

openhab-cli info

Version:     2.5.10 (Build)

User:        openhab (Active Process 777)
User Groups: openhab tty dialout audio bluetooth gpio

Directories: Folder Name      | Path                        | User:Group
             -----------      | ----                        | ----------
             OPENHAB_HOME     | /usr/share/openhab2         | openhab:openhab
             OPENHAB_RUNTIME  | /usr/share/openhab2/runtime | openhab:openhab
             OPENHAB_USERDATA | /var/lib/openhab2           | openhab:openhab
             OPENHAB_CONF     | /etc/openhab2               | openhab:openhab
             OPENHAB_LOGDIR   | /var/log/openhab2           | openhab:openhab

URLs:        http://192.168.88.248:8080
             https://192.168.88.248:8443

Serials:

(snipped)
crw--w----  1 root tty       4,   9 Nov  7 17:17 tty9
crw-rw----  1 root dialout 204,  64 Nov  7 17:17 ttyAMA0
crw-------  1 root root      5,   3 Nov  7 17:17 ttyprintk
crw-rw----  1 root dialout   4,  64 Nov  7 17:17 ttyS0
crw-------  1 root root     10, 239 Nov  7 17:17 uhid
dmesg -T | grep tty
[Sat Nov  7 17:17:38 2020] Kernel command line: coherent_pool=1M 8250.nr_uarts=1 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1  smsc95xx.macaddr=DC:A6:32:96:F7:26 vc_mem.mem_base=0x3f000000 vc_mem.mem_size=0x3f600000  console=tty1 root=PARTUUID=1b839919-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
[Sat Nov  7 17:17:38 2020] printk: console [tty1] enabled
[Sat Nov  7 17:17:39 2020] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 29, base_baud = 0) is a PL011 rev2
[Sat Nov  7 17:17:39 2020] fe215040.serial: ttyS0 at MMIO 0x0 (irq = 30, base_baud = 62500000) is a 16550

/etc/default/openhab2:

#########################
## JAVA OPTIONS
## Additional options for the JAVA_OPTS environment variable.
## These will be appended to the execution of the openHAB Java runtime in front of all other options.
## 
## A couple of independent examples:
EXTRA_JAVA_OPTS="-Xms192m -Xmx320m"
EXTRA_JAVA_OPTS="-Xms192m -Xmx320m"
EXTRA_JAVA_OPTS="-Xms192m -Xmx320m"
EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0:/dev/ttyUSB1:/dev/ttyS0:/dev/ttyS2:/dev/ttyACM0:/dev/ttyAMA0"
EXTRA_JAVA_OPTS="-Xms192m -Xmx320m"

Config:

  • openhabian-conflg: both options to disable serial are selected and executed.
  • Z-Wave binding specifies tttyS0 as the port.
  • /dev/ttyAMA0 port doesn’t work either
  • uart=1 is set in /boot/config.txt
  • openhab is part of the dialout group
  • Switching to master branch makes no difference

Logs:

2020-11-07 16:58:50.384 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007

2020-11-07 16:58:52.753 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://192.168.88.248:8080

2020-11-07 16:58:52.759 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://192.168.88.248:8443

2020-11-07 16:58:53.862 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel

2020-11-07 16:58:54.062 [INFO ] [ebuilder.internal.HomeBuilderServlet] - Started Home Builder at /homebuilder

2020-11-07 16:58:54.284 [INFO ] [openhab.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui

2020-11-07 16:59:04.017 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null

2020-11-07 16:59:09.533 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller

2020-11-07 16:59:09.535 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.

2020-11-07 17:13:24.986 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller

2020-11-07 17:13:24.988 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.

2020-11-07 17:13:35.091 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller

2020-11-07 17:13:35.093 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.

2020-11-07 17:18:49.678 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007

2020-11-07 17:18:52.684 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://192.168.88.248:8080

2020-11-07 17:18:52.694 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://192.168.88.248:8443

2020-11-07 17:18:53.854 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel

2020-11-07 17:18:54.051 [INFO ] [ebuilder.internal.HomeBuilderServlet] - Started Home Builder at /homebuilder

2020-11-07 17:18:54.328 [INFO ] [openhab.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui

2020-11-07 17:19:04.067 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null

2020-11-07 17:19:09.585 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller

2020-11-07 17:19:09.587 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.

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

2020-11-08 01:08:11.398 [thome.event.ExtensionEvent] - Extension 'package-standard' has been installed.

2020-11-08 01:08:19.156 [thome.event.ExtensionEvent] - Extension 'ui-homebuilder' has been installed.

2020-11-08 01:08:19.159 [thome.event.ExtensionEvent] - Extension 'ui-basic' has been installed.

2020-11-08 01:08:19.161 [thome.event.ExtensionEvent] - Extension 'ui-habpanel' has been installed.

2020-11-08 01:08:19.163 [thome.event.ExtensionEvent] - Extension 'ui-paper' has been installed.

2020-11-08 01:13:01.547 [thome.event.ExtensionEvent] - Extension 'binding-zwave' has been installed.

2020-11-08 01:14:13.811 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:f4155d95' changed from UNINITIALIZED to INITIALIZING

2020-11-08 01:14:13.911 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:f4155d95' has been updated.

2020-11-08 01:14:13.914 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:f4155d95' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-11-08 01:14:35.785 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:f4155d95' has been updated.

2020-11-08 01:14:59.525 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:f4155d95' has been updated.

2020-11-08 01:24:47.873 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:f4155d95' has been updated.

2020-11-07 16:59:04.410 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:f4155d95' changed from UNINITIALIZED to INITIALIZING

2020-11-07 16:59:04.435 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:f4155d95' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-11-07 17:13:19.692 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:f4155d95' has been updated.

2020-11-07 17:13:29.819 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:f4155d95' has been updated.

2020-11-07 17:19:04.468 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:f4155d95' changed from UNINITIALIZED to INITIALIZING

2020-11-07 17:19:04.490 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:f4155d95' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

After going into CLI and setting log to monitor the Z-Wave binding:

sudo openhab-cli console
log:set DEBUG org.openhab.binding.zwave
2020-11-07 18:39:03.254 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyS0'

2020-11-07 18:39:03.283 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Starting receive thread

2020-11-07 18:39:03.290 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive

2020-11-07 18:39:03.293 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized

2020-11-07 18:39:03.294 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller

2020-11-07 18:39:03.343 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller

2020-11-07 18:39:03.343 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2020-11-07 18:39:03.344 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 18:39:03.345 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.

2020-11-07 18:39:03.347 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.

2020-11-07 18:39:03.350 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.

2020-11-07 18:39:03.353 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 8 hours time.

2020-11-07 18:39:06.347 [DEBUG] [.ZWaveController$InitializeDelayTask] - Initialising network

2020-11-07 18:39:06.374 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 0 to queue - size 1

2020-11-07 18:39:06.375 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 18:39:06.385 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9 

2020-11-07 18:39:06.387 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9 

2020-11-07 18:39:06.390 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-07 18:39:06.392 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-07 18:39:06.398 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 1 to queue - size 1

2020-11-07 18:39:06.399 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-11-07 18:39:06.404 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 2 to queue - size 2

2020-11-07 18:39:06.405 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-11-07 18:39:06.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 3 to queue - size 3

2020-11-07 18:39:06.411 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-11-07 18:39:06.414 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID

2020-11-07 18:39:06.416 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 4 to queue - size 4

2020-11-07 18:39:06.418 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-11-07 18:39:08.395 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 0: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-07 18:39:08.396 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 0: Transaction is current transaction, so clearing!!!!!

2020-11-07 18:39:08.398 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 0: Transaction CANCELLED

2020-11-07 18:39:08.405 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:0 CANCELLED

2020-11-07 18:39:08.426 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 18:39:08.428 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 20 DC 

2020-11-07 18:39:08.430 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 20 DC 

2020-11-07 18:39:08.432 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-07 18:39:08.433 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-07 18:39:10.434 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 1: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-07 18:39:10.436 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 1: Transaction is current transaction, so clearing!!!!!

2020-11-07 18:39:10.437 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1: Transaction CANCELLED

2020-11-07 18:39:10.438 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:1 CANCELLED

2020-11-07 18:39:10.440 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 18:39:10.443 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 07 FB 

2020-11-07 18:39:10.445 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 07 FB 

2020-11-07 18:39:10.446 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-07 18:39:10.448 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-07 18:39:12.449 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 2: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-07 18:39:12.451 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 2: Transaction is current transaction, so clearing!!!!!

2020-11-07 18:39:12.452 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 2: Transaction CANCELLED

2020-11-07 18:39:12.453 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:2 CANCELLED

2020-11-07 18:39:12.455 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 18:39:12.458 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 06 96 0F 65 

2020-11-07 18:39:12.460 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 06 96 0F 65 

2020-11-07 18:39:12.461 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-07 18:39:12.462 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-07 18:39:14.464 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 3: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-07 18:39:14.465 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 3: Transaction is current transaction, so clearing!!!!!

2020-11-07 18:39:14.466 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3: Transaction CANCELLED

2020-11-07 18:39:14.467 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:3 CANCELLED

2020-11-07 18:39:14.469 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 18:39:14.473 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 56 AA 

2020-11-07 18:39:14.474 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 56 AA 

2020-11-07 18:39:14.476 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-07 18:39:14.477 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-07 18:39:16.478 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 4: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-07 18:39:16.480 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 4: Transaction is current transaction, so clearing!!!!!

2020-11-07 18:39:16.481 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 4: Transaction CANCELLED

2020-11-07 18:39:16.483 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:4 CANCELLED

2020-11-07 18:39:16.485 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

After installing Z-Way as an alternative:

Raspberry Pi 4B Detected. Setting up miniUART for Bluetooth
Adding 'dtoverlay=pi3-miniuart-bt' to /boot/config.txt
Usage: ./z-cfg-update <filename>
Starting z-way-server: done.
Setting up webif (1.2) ...
[ ok ] Starting mongoose (via systemctl): mongoose.service.
Setting up zbw (1.2) ...
tail: cannot open '/etc/init.d/zbw_connect' for reading: No such file or directory
chmod: cannot access 'zbw_connect': No such file or directory
zbw_connect patched
/var/lib/dpkg/info/zbw.postinst: 94: /var/lib/dpkg/info/zbw.postinst: /etc/init.d/zbw_connect: Permission denied
--2020-11-07 18:00:03--  https://find.z-wave.me/zbw_new_user
Resolving find.z-wave.me (find.z-wave.me)... 185.25.224.206, 194.190.114.100, 46.20.244.72, ...
Connecting to find.z-wave.me (find.z-wave.me)|185.25.224.206|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: unspecified [application/octet-stream]
Saving to: ‘/tmp/zbw_connect_setup.run’

/tmp/zbw_connect_se     [ <=>                ]   6.09K  --.-KB/s    in 0s      

2020-11-07 18:00:05 (39.6 MB/s) - ‘/tmp/zbw_connect_setup.run’ saved [6240]

Do you want to enable the remote support(y/n)? Remote support NOT enabled
Now you can run zbw_connect with /etc/init.d/zbw_connect start
or simply reboot your system

Your user id: 167066
Your password: [ removed ]
[ ok ] Starting zbw_connect (via systemctl): zbw_connect.service.
zbw_autosetup.service is not a native service, redirecting to systemd-sysv-install.
Executing: /lib/systemd/systemd-sysv-install enable zbw_autosetup
[ ok ] Starting zbw_connect (via systemctl): zbw_connect.service.
Setting up z-way-full (1.0-latest-version) ...
Processing triggers for systemd (241-7~deb10u4+rpi1) ...
Processing triggers for man-db (2.8.5-2) ...
Processing triggers for install-info (6.5.0.dfsg.1-4+b1) ...
Processing triggers for libc-bin (2.28-10+rpi1) ...
Updating FireMotD available updates count ... 
Package configuration files were changes: /etc/zbw/userid /etc/zbw/passwd /etc/zbw/local_port
Keeping your changed configuration files

Endless manual reboots later: Status: OFFLINE - BRIDGE_OFFLINE Controller is offline

Did you disable the blue tooth

Yep. Followed those steps, edited /boot files, no dice. Only thing i can think of is the binding is broken, or the hardware is. Perhaps something similar here: https://github.com/openhab/org.openhab.binding.zwave/issues/1264

2020-11-07 19:43:19.805 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler

2020-11-07 19:43:19.808 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller.

2020-11-07 19:43:19.811 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:2e93f2b9.

2020-11-07 19:43:24.820 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyAMA0'

2020-11-07 19:43:24.828 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Starting receive thread

2020-11-07 19:43:24.830 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized

2020-11-07 19:43:24.830 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive

2020-11-07 19:43:24.832 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller

2020-11-07 19:43:24.835 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller

2020-11-07 19:43:24.836 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.

2020-11-07 19:43:24.839 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2020-11-07 19:43:24.840 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 19:43:24.842 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.

2020-11-07 19:43:24.844 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.

2020-11-07 19:43:24.846 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 7 hours time.

2020-11-07 19:43:27.843 [DEBUG] [.ZWaveController$InitializeDelayTask] - Initialising network

2020-11-07 19:43:27.847 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 15 to queue - size 1

2020-11-07 19:43:27.848 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 19:43:27.850 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9 

2020-11-07 19:43:27.852 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9 

2020-11-07 19:43:27.884 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-07 19:43:27.886 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 15: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-07 19:43:27.888 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 16 to queue - size 1

2020-11-07 19:43:27.889 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-11-07 19:43:27.890 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 17 to queue - size 2

2020-11-07 19:43:27.892 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-11-07 19:43:27.893 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 18 to queue - size 3

2020-11-07 19:43:27.895 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-11-07 19:43:27.896 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID

2020-11-07 19:43:27.898 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 19 to queue - size 4

2020-11-07 19:43:27.899 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-11-07 19:43:29.888 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 15: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-07 19:43:29.890 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 15: Transaction is current transaction, so clearing!!!!!

2020-11-07 19:43:29.891 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 15: Transaction CANCELLED

2020-11-07 19:43:29.893 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:15 CANCELLED

2020-11-07 19:43:29.895 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 19:43:29.900 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 20 DC 

2020-11-07 19:43:29.902 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 20 DC 

2020-11-07 19:43:29.924 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-07 19:43:29.926 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 16: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-07 19:43:31.927 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 16: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-07 19:43:31.929 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 16: Transaction is current transaction, so clearing!!!!!

2020-11-07 19:43:31.930 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 16: Transaction CANCELLED

2020-11-07 19:43:31.932 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:16 CANCELLED

2020-11-07 19:43:31.936 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 19:43:31.938 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 07 FB 

2020-11-07 19:43:31.941 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 07 FB 

2020-11-07 19:43:31.964 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-07 19:43:31.966 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 17: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-07 19:43:33.968 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 17: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-07 19:43:33.971 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 17: Transaction is current transaction, so clearing!!!!!

2020-11-07 19:43:33.972 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 17: Transaction CANCELLED

2020-11-07 19:43:33.975 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:17 CANCELLED

2020-11-07 19:43:33.977 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 19:43:33.980 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 06 96 0F 65 

2020-11-07 19:43:33.983 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 06 96 0F 65 

2020-11-07 19:43:34.014 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-07 19:43:34.016 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 18: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-07 19:43:36.017 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 18: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-07 19:43:36.019 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 18: Transaction is current transaction, so clearing!!!!!

2020-11-07 19:43:36.020 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 18: Transaction CANCELLED

2020-11-07 19:43:36.022 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:18 CANCELLED

2020-11-07 19:43:36.024 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 19:43:36.028 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 56 AA 

2020-11-07 19:43:36.030 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 56 AA 

2020-11-07 19:43:36.054 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-07 19:43:36.056 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 19: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-07 19:43:38.057 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 19: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-07 19:43:38.059 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 19: Transaction is current transaction, so clearing!!!!!

2020-11-07 19:43:38.061 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 19: Transaction CANCELLED

2020-11-07 19:43:38.063 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:19 CANCELLED

2020-11-07 19:43:38.068 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 19:49:18.388 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:2e93f2b9

2020-11-07 19:51:00.890 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007

2020-11-07 19:51:03.964 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://192.168.88.248:8080

2020-11-07 19:51:03.969 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://192.168.88.248:8443

2020-11-07 19:51:05.145 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel

2020-11-07 19:51:05.363 [INFO ] [ebuilder.internal.HomeBuilderServlet] - Started Home Builder at /homebuilder

2020-11-07 19:51:05.600 [INFO ] [openhab.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui

2020-11-07 19:51:15.692 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - Creating ZWave discovery service for zwave:serial_zstick:2e93f2b9 with scan time of 60

2020-11-07 19:51:15.695 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Active zwave:serial_zstick:2e93f2b9

2020-11-07 19:51:15.697 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null

2020-11-07 19:51:16.129 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller.

2020-11-07 19:51:16.132 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:2e93f2b9.

2020-11-07 19:51:21.155 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyAMA0'

2020-11-07 19:51:21.181 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Starting receive thread

2020-11-07 19:51:21.188 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive

2020-11-07 19:51:21.191 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized

2020-11-07 19:51:21.192 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller

2020-11-07 19:51:21.247 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2020-11-07 19:51:21.247 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller

2020-11-07 19:51:21.248 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 19:51:21.248 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.

2020-11-07 19:51:21.251 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.

2020-11-07 19:51:21.254 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.

2020-11-07 19:51:21.259 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 7 hours time.

2020-11-07 19:51:24.252 [DEBUG] [.ZWaveController$InitializeDelayTask] - Initialising network

2020-11-07 19:51:24.276 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 0 to queue - size 1

2020-11-07 19:51:24.278 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 19:51:24.287 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9 

2020-11-07 19:51:24.290 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9 

2020-11-07 19:51:24.318 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-07 19:51:24.320 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-07 19:51:24.326 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 1 to queue - size 1

2020-11-07 19:51:24.328 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-11-07 19:51:24.332 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 2 to queue - size 2

2020-11-07 19:51:24.335 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-11-07 19:51:24.338 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 3 to queue - size 3

2020-11-07 19:51:24.340 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-11-07 19:51:24.344 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID

2020-11-07 19:51:24.346 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 4 to queue - size 4

2020-11-07 19:51:24.348 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-11-07 19:51:26.323 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 0: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-07 19:51:26.325 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 0: Transaction is current transaction, so clearing!!!!!

2020-11-07 19:51:26.326 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 0: Transaction CANCELLED

2020-11-07 19:51:26.332 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:0 CANCELLED

2020-11-07 19:51:26.335 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 19:51:26.339 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 20 DC 

2020-11-07 19:51:26.341 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 20 DC 

2020-11-07 19:51:26.368 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-07 19:51:26.370 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-07 19:51:28.371 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 1: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-07 19:51:28.373 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 1: Transaction is current transaction, so clearing!!!!!

2020-11-07 19:51:28.375 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1: Transaction CANCELLED

2020-11-07 19:51:28.377 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:1 CANCELLED

2020-11-07 19:51:28.378 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 19:51:28.382 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 07 FB 

2020-11-07 19:51:28.387 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 07 FB 

2020-11-07 19:51:28.418 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-07 19:51:28.419 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-07 19:51:30.421 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 2: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-07 19:51:30.422 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 2: Transaction is current transaction, so clearing!!!!!

2020-11-07 19:51:30.424 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 2: Transaction CANCELLED

2020-11-07 19:51:30.425 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:2 CANCELLED

2020-11-07 19:51:30.426 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 19:51:30.430 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 06 96 0F 65 

2020-11-07 19:51:30.432 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 06 96 0F 65 

2020-11-07 19:51:30.458 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-07 19:51:30.459 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-07 19:51:32.461 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 3: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-07 19:51:32.462 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 3: Transaction is current transaction, so clearing!!!!!

2020-11-07 19:51:32.463 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3: Transaction CANCELLED

2020-11-07 19:51:32.465 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:3 CANCELLED

2020-11-07 19:51:32.466 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-07 19:51:32.470 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 56 AA 

2020-11-07 19:51:32.472 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 56 AA 

2020-11-07 19:51:32.498 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-07 19:51:32.499 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-07 19:51:34.501 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 4: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-07 19:51:34.502 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 4: Transaction is current transaction, so clearing!!!!!

2020-11-07 19:51:34.503 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 4: Transaction CANCELLED

2020-11-07 19:51:34.505 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:4 CANCELLED

2020-11-07 19:51:34.506 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

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

2020-11-08 01:08:11.398 [thome.event.ExtensionEvent] - Extension 'package-standard' has been installed.

2020-11-08 01:08:19.156 [thome.event.ExtensionEvent] - Extension 'ui-homebuilder' has been installed.

2020-11-08 01:08:19.159 [thome.event.ExtensionEvent] - Extension 'ui-basic' has been installed.

2020-11-08 01:08:19.161 [thome.event.ExtensionEvent] - Extension 'ui-habpanel' has been installed.

2020-11-08 01:08:19.163 [thome.event.ExtensionEvent] - Extension 'ui-paper' has been installed.

2020-11-08 01:13:01.547 [thome.event.ExtensionEvent] - Extension 'binding-zwave' has been installed.

2020-11-08 01:14:13.811 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:f4155d95' changed from UNINITIALIZED to INITIALIZING

2020-11-08 01:14:13.911 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:f4155d95' has been updated.

2020-11-08 01:14:13.914 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:f4155d95' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-11-08 01:14:35.785 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:f4155d95' has been updated.

2020-11-08 01:14:59.525 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:f4155d95' has been updated.

2020-11-08 01:24:47.873 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:f4155d95' has been updated.

2020-11-07 16:59:04.410 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:f4155d95' changed from UNINITIALIZED to INITIALIZING

2020-11-07 16:59:04.435 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:f4155d95' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-11-07 17:13:19.692 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:f4155d95' has been updated.

2020-11-07 17:13:29.819 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:f4155d95' has been updated.

2020-11-07 17:19:04.468 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:f4155d95' changed from UNINITIALIZED to INITIALIZING

2020-11-07 17:19:04.490 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:f4155d95' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-11-07 18:05:17.318 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:f4155d95' changed from UNINITIALIZED to INITIALIZING

2020-11-07 18:05:17.341 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:f4155d95' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-11-07 18:14:41.431 [thome.event.ExtensionEvent] - Extension 'binding-zway' has been installed.

2020-11-07 18:15:35.495 [home.event.InboxAddedEvent] - Discovery Result with UID 'zway:zwayServer:192_168_88_248' has been added.

2020-11-07 18:15:43.454 [me.event.InboxRemovedEvent] - Discovery Result with UID 'zway:zwayServer:192_168_88_248' has been removed.

2020-11-07 18:15:43.486 [hingStatusInfoChangedEvent] - 'zway:zwayServer:192_168_88_248' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_CONFIGURATION_PENDING)

2020-11-07 18:18:02.533 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:f4155d95' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to UNINITIALIZED

2020-11-07 18:18:02.844 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:f4155d95' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2020-11-07 18:18:07.238 [thome.event.ExtensionEvent] - Extension 'binding-zwave' has been uninstalled.

2020-11-07 18:19:12.938 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:f4155d95' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to REMOVING

2020-11-07 18:19:15.712 [hingStatusInfoChangedEvent] - 'zway:zwayServer:192_168_88_248' changed from UNINITIALIZED (HANDLER_CONFIGURATION_PENDING) to REMOVING

2020-11-07 18:19:15.725 [hingStatusInfoChangedEvent] - 'zway:zwayServer:192_168_88_248' changed from REMOVING to REMOVED

2020-11-07 18:19:15.743 [hingStatusInfoChangedEvent] - 'zway:zwayServer:192_168_88_248' changed from REMOVED to UNINITIALIZED

2020-11-07 18:19:15.800 [hingStatusInfoChangedEvent] - 'zway:zwayServer:192_168_88_248' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2020-11-07 18:22:21.379 [thome.event.ExtensionEvent] - Extension 'binding-zwave' has been installed.

2020-11-07 18:38:58.174 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:2e93f2b9' changed from UNINITIALIZED to INITIALIZING

2020-11-07 18:38:58.246 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:2e93f2b9' has been updated.

2020-11-07 18:38:58.248 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:2e93f2b9' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-11-07 19:19:11.811 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:2e93f2b9' has been updated.

2020-11-07 19:38:58.467 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:2e93f2b9' changed from UNINITIALIZED to INITIALIZING

2020-11-07 19:38:58.516 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:2e93f2b9' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-11-07 19:39:20.012 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:2e93f2b9' has been updated.

2020-11-07 19:42:44.385 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:2e93f2b9' has been updated.

2020-11-07 19:43:10.385 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:2e93f2b9' has been updated.

2020-11-07 19:43:19.790 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:2e93f2b9' has been updated.

2020-11-07 19:51:16.113 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:2e93f2b9' changed from UNINITIALIZED to INITIALIZING

2020-11-07 19:51:16.140 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:2e93f2b9' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

If i switch it to /dev/ttyS0 i get:

2020-11-07 19:54:51.302 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:2e93f2b9

2020-11-07 19:55:11.718 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:2e93f2b9

2020-11-07 19:55:26.345 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:2e93f2b9

2020-11-07 19:55:26.389 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update received

2020-11-07 19:55:26.412 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_softreset to false

2020-11-07 19:55:26.415 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update security_networkkey to 66 2E 89 78 34 85 7C A0 47 7D 7F 06 DB EE 37 52

2020-11-07 19:55:26.417 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update security_inclusionmode to 0

2020-11-07 19:55:26.424 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_sisnode to null

2020-11-07 19:55:26.426 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_sync to false

2020-11-07 19:55:26.429 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update port to /dev/ttyS0

2020-11-07 19:55:26.431 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_master to true

2020-11-07 19:55:26.434 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update inclusion_mode to 2

2020-11-07 19:55:26.436 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_wakeupperiod to 3600

2020-11-07 19:55:26.438 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update heal_time to 2

2020-11-07 19:55:26.442 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 7 hours time.

2020-11-07 19:55:26.444 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_exclude to false

2020-11-07 19:55:26.447 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_inclusiontimeout to 30

2020-11-07 19:55:26.449 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_hardreset to false

2020-11-07 19:55:26.484 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Disposing receive thread

2020-11-07 19:55:26.548 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Stopped ZWave thread: Receive

2020-11-07 19:55:26.551 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Receive thread dispose

2020-11-07 19:55:26.553 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Disposing serial connection

2020-11-07 19:55:26.611 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Serial connection disposed

2020-11-07 19:55:26.613 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler

2020-11-07 19:55:26.617 [DEBUG] [ve.internal.protocol.ZWaveController] - Shutting down ZWave controller

2020-11-07 19:55:26.619 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Shutting down transaction manager

2020-11-07 19:55:26.623 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Exiting ZWave Receive Thread

2020-11-07 19:55:26.625 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction manager shutdown

2020-11-07 19:55:26.628 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller shutdown

2020-11-07 19:55:26.630 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller.

2020-11-07 19:55:26.638 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:2e93f2b9.

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

2020-11-07 19:55:26.491 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:2e93f2b9' has been updated.

Trying to run a scan triggers an Exception:

2020-11-07 19:58:58.276 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - ZWave product zwave:serial_zstick has no references!

2020-11-07 19:58:58.313 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - ZWave product zwave:device has no references!

2020-11-07 19:58:58.472 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:2e93f2b9

2020-11-07 19:58:58.478 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:2e93f2b9

2020-11-07 19:59:00.483 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 

java.lang.NullPointerException: null

	at org.openhab.binding.zwave.discovery.ZWaveDiscoveryService$1.run(ZWaveDiscoveryService.java:87) ~[?:?]

	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_265]

	at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_265]

	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_265]

	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) ~[?:1.8.0_265]

	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_265]

	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_265]

	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_265]

Try removing it from pi then disabling bluetooth and then attach it and enable serial.

They both might be talking at once

1 Like
EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0:/dev/ttyUSB1:/dev/ttyS0:/dev/ttyS2:/dev/ttyACM0:/dev/ttyAMA0"
EXTRA_JAVA_OPTS="-Xms192m -Xmx320m"

Merge these into a single line else later ones substitute earlier ones i.e. the serial port definition is GONE which is likely the reason for your inability to access the controller(s).

Do NOT edit files manually when there’s openHABian menu options to do that for you.

BT is already disabled (including services). Still no worky.

Always wondering about those lines. I didn’t add them, and it’s a fresh install - so i can only assume it’s part of the release.

Have consolidated those into a single line and no difference:

2020-11-08 11:33:26.584 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:0e582461' changed from UNINITIALIZED to INITIALIZING

2020-11-08 11:33:26.607 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:0e582461' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

Removed it and re-added it, same output:

2020-11-08 11:36:40.180 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyAMA0'

2020-11-08 11:36:40.206 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Starting receive thread

2020-11-08 11:36:40.215 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive

2020-11-08 11:36:40.217 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized

2020-11-08 11:36:40.220 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller

2020-11-08 11:36:40.278 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller

2020-11-08 11:36:40.278 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2020-11-08 11:36:40.280 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-08 11:36:40.280 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.

2020-11-08 11:36:40.284 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.

2020-11-08 11:36:40.289 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.

2020-11-08 11:36:40.292 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 15 hours time.

2020-11-08 11:36:43.284 [DEBUG] [.ZWaveController$InitializeDelayTask] - Initialising network

2020-11-08 11:36:43.314 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 0 to queue - size 1

2020-11-08 11:36:43.315 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-08 11:36:43.325 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9 

2020-11-08 11:36:43.328 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9 

2020-11-08 11:36:43.352 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-08 11:36:43.354 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-08 11:36:43.360 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 1 to queue - size 1

2020-11-08 11:36:43.362 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-11-08 11:36:43.366 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 2 to queue - size 2

2020-11-08 11:36:43.368 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-11-08 11:36:43.371 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 3 to queue - size 3

2020-11-08 11:36:43.373 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-11-08 11:36:43.376 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID

2020-11-08 11:36:43.378 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 4 to queue - size 4

2020-11-08 11:36:43.379 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-11-08 11:36:45.357 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 0: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-08 11:36:45.359 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 0: Transaction is current transaction, so clearing!!!!!

2020-11-08 11:36:45.360 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 0: Transaction CANCELLED

2020-11-08 11:36:45.367 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:0 CANCELLED

2020-11-08 11:36:45.371 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-08 11:36:45.374 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 20 DC 

2020-11-08 11:36:45.377 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 20 DC 

2020-11-08 11:36:45.402 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-08 11:36:45.403 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-08 11:36:47.404 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 1: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-08 11:36:47.406 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 1: Transaction is current transaction, so clearing!!!!!

2020-11-08 11:36:47.407 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1: Transaction CANCELLED

2020-11-08 11:36:47.408 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:1 CANCELLED

2020-11-08 11:36:47.412 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-08 11:36:47.415 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 07 FB 

2020-11-08 11:36:47.417 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 07 FB 

2020-11-08 11:36:47.442 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-08 11:36:47.443 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-08 11:36:49.444 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 2: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-08 11:36:49.446 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 2: Transaction is current transaction, so clearing!!!!!

2020-11-08 11:36:49.447 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 2: Transaction CANCELLED

2020-11-08 11:36:49.448 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:2 CANCELLED

2020-11-08 11:36:49.450 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-08 11:36:49.454 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 06 96 0F 65 

2020-11-08 11:36:49.457 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 06 96 0F 65 

2020-11-08 11:36:49.482 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-08 11:36:49.483 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-08 11:36:51.484 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 3: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-08 11:36:51.486 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 3: Transaction is current transaction, so clearing!!!!!

2020-11-08 11:36:51.487 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3: Transaction CANCELLED

2020-11-08 11:36:51.488 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:3 CANCELLED

2020-11-08 11:36:51.491 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-08 11:36:51.494 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 56 AA 

2020-11-08 11:36:51.497 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 56 AA 

2020-11-08 11:36:51.522 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-11-08 11:36:51.523 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-11-08 11:36:53.524 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 4: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-11-08 11:36:53.526 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 4: Transaction is current transaction, so clearing!!!!!

2020-11-08 11:36:53.527 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 4: Transaction CANCELLED

2020-11-08 11:36:53.528 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:4 CANCELLED

2020-11-08 11:36:53.531 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-11-08 11:37:31.758 [INFO ] [.reconnect.PeriodicReconnectStrategy] - Try to restore connection to 'vps209562.vps.ovh.ca'. Next attempt in 60000ms

2020-11-08 11:37:31.762 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to 'vps209562.vps.ovh.ca' with clientid ea9ada6b-d121-40a6-a66b-333e52da40a4

Switch to ttyS0, same thing:

2020-11-08 11:38:16.789 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:d0d15cb8

2020-11-08 11:38:26.428 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:d0d15cb8

2020-11-08 11:38:26.454 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update received

2020-11-08 11:38:26.487 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_softreset to false

2020-11-08 11:38:26.490 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update security_networkkey to B3 36 51 0C 97 1D 09 9C B4 47 65 39 B2 1E 56 C4

2020-11-08 11:38:26.493 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update security_inclusionmode to 0

2020-11-08 11:38:26.496 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_sisnode to null

2020-11-08 11:38:26.498 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_sync to false

2020-11-08 11:38:26.501 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update port to /dev/ttyS0

2020-11-08 11:38:26.503 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_master to true

2020-11-08 11:38:26.506 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update inclusion_mode to 2

2020-11-08 11:38:26.508 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_wakeupperiod to 3600

2020-11-08 11:38:26.510 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update heal_time to 2

2020-11-08 11:38:26.513 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 15 hours time.

2020-11-08 11:38:26.515 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_exclude to false

2020-11-08 11:38:26.518 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_inclusiontimeout to 30

2020-11-08 11:38:26.520 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_hardreset to false

2020-11-08 11:38:26.532 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Disposing receive thread

2020-11-08 11:38:26.638 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Stopped ZWave thread: Receive

2020-11-08 11:38:26.641 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Receive thread dispose

2020-11-08 11:38:26.643 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Disposing serial connection

2020-11-08 11:38:26.689 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Serial connection disposed

2020-11-08 11:38:26.704 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler

2020-11-08 11:38:26.709 [DEBUG] [ve.internal.protocol.ZWaveController] - Shutting down ZWave controller

2020-11-08 11:38:26.712 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Shutting down transaction manager

2020-11-08 11:38:26.717 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Exiting ZWave Receive Thread

2020-11-08 11:38:26.719 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction manager shutdown

2020-11-08 11:38:26.723 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller shutdown

2020-11-08 11:38:26.726 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller.

2020-11-08 11:38:26.729 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:d0d15cb8.

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

2020-11-08 11:38:26.533 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:d0d15cb8' has been updated.


Are you using this binding?

I’ve tried both Z-Wave and Z-Way, and reflashed it. Neither work. Makes me think it’s a hardware problem, so i’ve ordered another one to test that theory.

Update to this. Added a second new Razberry2 straight out of the box, and still no luck. Exact same situation.

Author of the Z-Wave binding said this on the Github issue: "There is probably something wrong with either your configuration, or the stick. The binding is sending data, but there is no data received from the controller."

Some additional tales of woe here, which indicate the hardware just doesn’t work in many cases:

Hi,

lshw doesn’t show it but do you have any usb storage attached? I have a similar setup and zwave is working fine untill I plug in some external usb drive. The controller is still online but will not communicate with nodes. Once I unplug it, it all starts working again.

Nope, just SD card. I literally just gave up after 2 lost days with that thing. The GoControl USB is a much better piece of gear - just wished they weren’t discontinuing it!

I don’t have one to try :frowning:

Did you get it to work at all on a virgin install ?

Hah i’ll send you mine!

Both were virgin cards with virgin OpenHABIan installs, with BT disabled. I know other people have got it working with the Pi 4, but i suspect it’s a hardware incompatibility; it’s like the card just isn’t talking back, as if it’s dead. The Amazon reviews are vicious.

Sure I would love another project.

Try this

Download
https://razberry.z-wave.me/z-way-server/razberry.img.zip

Flash to sd card

After installing Z-Way wait about 1 minute then open a web browser and point to find.z-wave.me. Below the login screen you will see the IP address of your Raspberry Pi system.

Get it working with that software first :slight_smile: Once you get it working try it with openhabian again. This will confirm that it is not the pi or the hat