Open Majestic7979 opened 3 days ago
Update: I used image tag 9.26 and it works again, so definitely not an issue with my controller or setup, it's a problem in the latest images.
I am getting the exact same error. Restarting container, using different USB port, restarting the system - nothing fixes the error
also my Aeotec USB stick was recognized anymore. I did a restart of my docker, replugged the USB stick but nothing works. When I did recreate the image I've got everything back online. Not sure what the root cause was in my case.
Same error message as OP as of 12:00 CT.
Controller: Aeotec z-stick 7 plus Version: 9.27.1
Rollback to 9.26 fixed issue
Same issue here using a HUSBZB-1 controller using 9.27.1
Reverting to 9.26.0 fixed it.
Please make a driver log, loglevel debug
and attach it here as a file (drag & drop into the text field).
cc @AlCalzone seems this issue is still relevant with 9.27.1
If this is still happening with 9.27.1, I definitely need to see driver logs.
Side note: IMO it seems a bit negligent to auto-update critical infrastructure, e.g. when doors cannot be opened without it working
Just tested again, with a fresh pull of 9.27.1. Works fine for me, with UZB 3 (500 series), Aeotec Z-Stick 7 (700 series) and Zooz ZSt39 (800 series) controllers.
Also working again with a fresh pull of 9.27.0
@Majestic7979 can you double check if pulling 9.27.2 (latest version) solves your issue?
Confirmed that 9.27.2 is also working for me, but using the latest
tag still defaults back to 9.27.0 (also working still)
@robertsLando Any idea what's going on with the tag?
I checked on https://hub.docker.com/r/zwavejs/zwave-js-ui/tags and the shas of 9.27.2 match latest so sincerely I have no clue
I'm still getting this with a fresh 9.27.2 pull:
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-14 13:23:52.037 INFO STORE: Controller status: Driver: Failed to initialize the driver: ZWaveError: Timeout while waiting for an ACK from the controller (ZW0200)
My controller is via tcp (ser2sock) but it is working fine.
A downgrade to 9.25.0 restores it immediately. (9.26.0 is also broken.)
Coulds you paste full logs (application logs AND driver logs on loglevel debug) please?
I've set the driver to debug and restarted, but it did not add the driver logs. I had to point it at a file before I could get anything:
███╔╝ █████╗ ██║ █╗ ██║ ███████║ ██║ ██║ █████╗ ██║ ███████╗
███╔╝ ╚════╝ ██║███╗██║ ██╔══██║ ╚██╗ ██╔╝ ██╔══╝ ██ ██║ ╚════██║
███████╗ ╚███╔███╔╝ ██║ ██║ ╚████╔╝ ███████╗ ╚█████╔╝ ███████║
╚══════╝ ╚══╝╚══╝ ╚═╝ ╚═╝ ╚═══╝ ╚══════╝ ╚════╝ ╚══════╝
2024-11-15T12:53:49.223Z DRIVER version 14.3.2
2024-11-15T12:53:49.224Z DRIVER
2024-11-15T12:53:49.225Z DRIVER starting driver...
2024-11-15T12:53:49.230Z DRIVER opening serial port tcp://ser2sock-zwave:10000
2024-11-15T12:53:49.262Z DRIVER serial port opened
2024-11-15T12:53:49.265Z SERIAL » 0x15 (1 bytes)
2024-11-15T12:53:49.772Z CNTRLR [BOOTLOADER] !SER2SOCK Connected
!SER2SOCK SERIAL_CONNECTED
2024-11-15T12:53:50.276Z DRIVER loading configuration...
2024-11-15T12:53:50.285Z CONFIG Using external configuration dir /usr/src/app/store/.config-db
2024-11-15T12:53:50.287Z CONFIG version 14.3.2
2024-11-15T12:53:51.919Z DRIVER beginning interview...
2024-11-15T12:53:51.921Z DRIVER added request handler for AddNodeToNetwork (0x4a)...
1 registered
2024-11-15T12:53:51.921Z DRIVER added request handler for RemoveNodeFromNetwork (0x4b)...
1 registered
2024-11-15T12:53:51.922Z DRIVER added request handler for ReplaceFailedNode (0x63)...
1 registered
2024-11-15T12:53:51.923Z DRIVER added request handler for SetLearnMode (0x50)...
1 registered
2024-11-15T12:53:51.924Z CNTRLR querying Serial API capabilities...
2024-11-15T12:53:51.938Z SERIAL » 0x01030007fb (5 bytes)
2024-11-15T12:53:51.939Z DRIVER » [REQ] [GetSerialApiCapabilities]
2024-11-15T12:53:51.947Z SERIAL « +
2024-11-15T12:53:51.948Z CNTRLR [BOOTLOADER] +
2024-11-15T12:53:51.949Z SERIAL « �
2024-11-15T12:53:51.950Z CNTRLR [BOOTLOADER] �
2024-11-15T12:53:51.950Z SERIAL «
2024-11-15T12:53:51.951Z CNTRLR [BOOTLOADER]
2024-11-15T12:53:51.952Z SERIAL « Z�����O����g
2024-11-15T12:53:51.953Z CNTRLR [BOOTLOADER] Z�����O����g
2024-11-15T12:53:51.954Z SERIAL « ��
2024-11-15T12:53:51.955Z CNTRLR [BOOTLOADER] ��
2024-11-15T12:53:51.955Z SERIAL « ��
2024-11-15T12:53:51.956Z CNTRLR [BOOTLOADER] ��
2024-11-15T12:53:51.956Z SERIAL «
2024-11-15T12:53:51.957Z CNTRLR [BOOTLOADER]
2024-11-15T12:53:51.958Z SERIAL « �s
2024-11-15T12:53:51.958Z CNTRLR [BOOTLOADER] �s
2024-11-15T12:53:51.959Z SERIAL « �
2024-11-15T12:53:51.959Z CNTRLR [BOOTLOADER] �
2024-11-15T12:53:51.960Z SERIAL « `
2024-11-15T12:53:51.961Z CNTRLR [BOOTLOADER] `
2024-11-15T12:53:52.462Z CNTRLR [BOOTLOADER] �
2024-11-15T12:53:52.942Z SERIAL « +
2024-11-15T12:53:52.944Z CNTRLR [BOOTLOADER] +
2024-11-15T12:53:52.945Z SERIAL « �
2024-11-15T12:53:52.946Z CNTRLR [BOOTLOADER] �
2024-11-15T12:53:52.947Z SERIAL «
2024-11-15T12:53:52.949Z CNTRLR [BOOTLOADER]
2024-11-15T12:53:52.955Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2024-11-15T12:53:52.960Z SERIAL « Z�����O����g
2024-11-15T12:53:52.962Z CNTRLR [BOOTLOADER] Z�����O����g
2024-11-15T12:53:52.963Z SERIAL « ��
2024-11-15T12:53:52.964Z CNTRLR [BOOTLOADER] ��
2024-11-15T12:53:52.964Z SERIAL « ��
2024-11-15T12:53:52.965Z CNTRLR [BOOTLOADER] ��
2024-11-15T12:53:52.966Z SERIAL «
2024-11-15T12:53:52.967Z CNTRLR [BOOTLOADER]
2024-11-15T12:53:52.968Z SERIAL « �s
2024-11-15T12:53:52.969Z CNTRLR [BOOTLOADER] �s
2024-11-15T12:53:52.970Z SERIAL « �
2024-11-15T12:53:52.971Z CNTRLR [BOOTLOADER] �
2024-11-15T12:53:52.971Z SERIAL « `
2024-11-15T12:53:52.973Z CNTRLR [BOOTLOADER] `
2024-11-15T12:53:53.059Z DRIVER » [REQ] [GetSerialApiCapabilities]
2024-11-15T12:53:53.062Z SERIAL » 0x01030007fb (5 bytes)
2024-11-15T12:53:53.573Z CNTRLR [BOOTLOADER] �
2024-11-15T12:53:53.943Z SERIAL « +
2024-11-15T12:53:53.945Z CNTRLR [BOOTLOADER] +
2024-11-15T12:53:53.947Z SERIAL « �
2024-11-15T12:53:53.948Z CNTRLR [BOOTLOADER] �
2024-11-15T12:53:53.949Z SERIAL «
2024-11-15T12:53:53.950Z CNTRLR [BOOTLOADER]
2024-11-15T12:53:53.951Z SERIAL « Z�����O����g
2024-11-15T12:53:53.953Z CNTRLR [BOOTLOADER] Z�����O����g
2024-11-15T12:53:53.954Z SERIAL « ��
2024-11-15T12:53:53.955Z CNTRLR [BOOTLOADER] ��
2024-11-15T12:53:53.956Z SERIAL « ��
2024-11-15T12:53:53.957Z CNTRLR [BOOTLOADER] ��
2024-11-15T12:53:53.958Z SERIAL «
2024-11-15T12:53:53.959Z CNTRLR [BOOTLOADER]
2024-11-15T12:53:53.960Z SERIAL « �s
2024-11-15T12:53:53.961Z CNTRLR [BOOTLOADER] �s
2024-11-15T12:53:53.962Z SERIAL « �
2024-11-15T12:53:53.963Z CNTRLR [BOOTLOADER] �
2024-11-15T12:53:53.964Z SERIAL « `
2024-11-15T12:53:53.965Z CNTRLR [BOOTLOADER] `
2024-11-15T12:53:54.070Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
2024-11-15T12:53:54.468Z CNTRLR [BOOTLOADER] �
2024-11-15T12:53:54.945Z SERIAL « +
2024-11-15T12:53:54.947Z CNTRLR [BOOTLOADER] +
2024-11-15T12:53:54.948Z SERIAL « �
2024-11-15T12:53:54.949Z CNTRLR [BOOTLOADER] �
2024-11-15T12:53:54.950Z SERIAL «
2024-11-15T12:53:54.951Z CNTRLR [BOOTLOADER]
2024-11-15T12:53:54.952Z SERIAL « Z�����O����g
2024-11-15T12:53:54.953Z CNTRLR [BOOTLOADER] Z�����O����g
2024-11-15T12:53:54.953Z SERIAL « ��
2024-11-15T12:53:54.954Z CNTRLR [BOOTLOADER] ��
2024-11-15T12:53:54.954Z SERIAL « ��
2024-11-15T12:53:54.955Z CNTRLR [BOOTLOADER] ��
2024-11-15T12:53:54.956Z SERIAL «
2024-11-15T12:53:54.956Z CNTRLR [BOOTLOADER]
2024-11-15T12:53:54.957Z SERIAL « �s
2024-11-15T12:53:54.957Z CNTRLR [BOOTLOADER] �s
2024-11-15T12:53:54.958Z SERIAL « �
2024-11-15T12:53:54.959Z CNTRLR [BOOTLOADER] �
2024-11-15T12:53:54.960Z SERIAL « `
2024-11-15T12:53:54.961Z CNTRLR [BOOTLOADER] `
2024-11-15T12:53:55.175Z DRIVER » [REQ] [GetSerialApiCapabilities]
2024-11-15T12:53:55.177Z SERIAL » 0x01030007fb (5 bytes)
2024-11-15T12:53:55.688Z CNTRLR [BOOTLOADER] �
2024-11-15T12:53:56.187Z DRIVER Failed to initialize the driver: ZWaveError: Timeout while waiting for an ACK
from the controller (ZW0200)
at Driver.sendMessage (/usr/src/app/node_modules/zwave-js/src/lib/driver/D
river.ts:6071:23)
at ZWaveController2.queryCapabilities (/usr/src/app/node_modules/zwave-js/
src/lib/controller/Controller.ts:1144:37)
at Driver.initializeControllerAndNodes (/usr/src/app/node_modules/zwave-js
/src/lib/driver/Driver.ts:1677:46)
at Immediate.<anonymous> (/usr/src/app/node_modules/zwave-js/src/lib/drive
r/Driver.ts:1478:16)
2024-11-15T12:53:56.192Z DRIVER destroying driver instance...
2024-11-15T12:53:56.196Z DRIVER all queues idle
2024-11-15T12:53:56.198Z DRIVER driver instance destroyed
+ zwavejs2mqtt-0 › zwavejs2mqtt
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:38.928 INFO STORE: Version: 9.27.2.b0ade31
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:38.941 INFO STORE: Application path:/usr/src/app
zwavejs2mqtt-0 zwavejs2mqtt ______ __ __ _ _____ _ _ _____
zwavejs2mqtt-0 zwavejs2mqtt |___ / \ \ / / | |/ ____| | | | |_ _|
zwavejs2mqtt-0 zwavejs2mqtt / /____\ \ /\ / /_ ___ _____ | | (___ | | | | | |
zwavejs2mqtt-0 zwavejs2mqtt / /______\ \/ \/ / _' \ \ / / _ \ _ | |\___ \ | | | | | |
zwavejs2mqtt-0 zwavejs2mqtt / /__ \ /\ / (_| |\ V / __/ | |__| |____) | | |__| |_| |_
zwavejs2mqtt-0 zwavejs2mqtt /_____| \/ \/ \__,_| \_/ \___| \____/|_____/ \____/|_____|
zwavejs2mqtt-0 zwavejs2mqtt
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.014 WARN STORE: scenes.json not found
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.120 INFO STORE: Listening on port 8091host 0.0.0.0 protocol HTTP
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.138 INFO STORE: Zniffer is DISABLED
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.154 INFO STORE: Connecting to mqtts://mqtt.DOMAIN:8883
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.443 WARN STORE: Store backup is disabled
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.447 WARN STORE: Nvm backup is disabled
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.560 INFO STORE: Connecting to tcp://ser2sock-zwave:10000
zwavejs2mqtt-0 zwavejs2mqtt Logging to file:
zwavejs2mqtt-0 zwavejs2mqtt /usr/src/app/store/logs/zwavejs_2024-11-15.log
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.719 INFO STORE: Starting ZwaveJS prom plugin
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.722 INFO STORE: Successfully loaded plugin zwavejs-prom
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.747 INFO STORE: MQTT client connected
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.761 DEBUG STORE: Subscribing to homeassistant/status with options { qos: 1 }
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.772 DEBUG STORE: Subscribing to zwave/_CLIENTS/ZWAVE_GATEWAY-zwave-js-ui/broadcast/# with options { qos: 1 }
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.776 DEBUG STORE: Subscribing to zwave/_CLIENTS/ZWAVE_GATEWAY-zwave-js-ui/api/# with options { qos: 1 }
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.778 DEBUG STORE: Subscribing to zwave/_CLIENTS/ZWAVE_GATEWAY-zwave-js-ui/multicast/# with options { qos: 1 }
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.791 INFO STORE: Subscribed to homeassistant/status
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.797 INFO STORE: Message received on homeassistant/status: 'offline'
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.800 INFO STORE: Home Assistant is OFFLINE
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.805 INFO STORE: Subscribed to zwave/_CLIENTS/ZWAVE_GATEWAY-zwave-js-ui/broadcast/#
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.807 INFO STORE: Subscribed to zwave/_CLIENTS/ZWAVE_GATEWAY-zwave-js-ui/api/#
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:39.810 INFO STORE: Subscribed to zwave/_CLIENTS/ZWAVE_GATEWAY-zwave-js-ui/multicast/#
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:46.594 DEBUG STORE: New connection vblPhfiBC2C6UWdWAAAC
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:46.639 DEBUG STORE: Event INITED emitted to vblPhfiBC2C6UWdWAAAC
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:48.165 INFO STORE: Controller status: Driver: Failed to initialize the driver: ZWaveError: Timeout while waiting for an ACK from the controller (ZW0200)
zwavejs2mqtt-0 zwavejs2mqtt at Driver.sendMessage (/usr/src/app/node_modules/zwave-js/src/lib/driver/Driver.ts:6071:23)
zwavejs2mqtt-0 zwavejs2mqtt at ZWaveController2.queryCapabilities (/usr/src/app/node_modules/zwave-js/src/lib/controller/Controller.ts:1144:37)
zwavejs2mqtt-0 zwavejs2mqtt at Driver.initializeControllerAndNodes (/usr/src/app/node_modules/zwave-js/src/lib/driver/Driver.ts:1677:46)
zwavejs2mqtt-0 zwavejs2mqtt at Immediate.<anonymous> (/usr/src/app/node_modules/zwave-js/src/lib/driver/Driver.ts:1478:16) (ZW0100)
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:48.168 INFO STORE: Restarting client in 1 seconds, retry 1
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:49.181 INFO STORE: Client closed
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:49.218 INFO STORE: Connecting to tcp://ser2sock-zwave:10000
zwavejs2mqtt-0 zwavejs2mqtt Logging to file:
zwavejs2mqtt-0 zwavejs2mqtt /usr/src/app/store/logs/zwavejs_2024-11-15.log
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:56.190 INFO STORE: Restarting client in 2 seconds, retry 2
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:58.194 INFO STORE: Client closed
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:53:58.220 INFO STORE: Connecting to tcp://ser2sock-zwave:10000
zwavejs2mqtt-0 zwavejs2mqtt Logging to file:
zwavejs2mqtt-0 zwavejs2mqtt /usr/src/app/store/logs/zwavejs_2024-11-15.log
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:54:04.893 INFO STORE: Restarting client in 4 seconds, retry 3
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:54:08.899 INFO STORE: Client closed
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:54:08.920 INFO STORE: Connecting to tcp://ser2sock-zwave:10000
zwavejs2mqtt-0 zwavejs2mqtt Logging to file:
zwavejs2mqtt-0 zwavejs2mqtt /usr/src/app/store/logs/zwavejs_2024-11-15.log
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:54:10.954 INFO STORE: GET /metrics 200 11.322 ms - 1
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:54:15.621 INFO STORE: Restarting client in 8 seconds, retry 4
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:54:23.628 INFO STORE: Client closed
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:54:23.638 INFO STORE: Connecting to tcp://ser2sock-zwave:10000
zwavejs2mqtt-0 zwavejs2mqtt Logging to file:
zwavejs2mqtt-0 zwavejs2mqtt /usr/src/app/store/logs/zwavejs_2024-11-15.log
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:54:30.413 INFO STORE: Restarting client in 15 seconds, retry 5
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:54:45.416 INFO STORE: Client closed
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:54:45.440 INFO STORE: Connecting to tcp://ser2sock-zwave:10000
zwavejs2mqtt-0 zwavejs2mqtt Logging to file:
zwavejs2mqtt-0 zwavejs2mqtt /usr/src/app/store/logs/zwavejs_2024-11-15.log
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:54:52.117 INFO STORE: Restarting client in 15 seconds, retry 6
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:55:07.120 INFO STORE: Client closed
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:55:07.136 INFO STORE: Connecting to tcp://ser2sock-zwave:10000
zwavejs2mqtt-0 zwavejs2mqtt Logging to file:
zwavejs2mqtt-0 zwavejs2mqtt /usr/src/app/store/logs/zwavejs_2024-11-15.log
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:55:10.717 INFO STORE: GET /metrics 200 5.343 ms - 1
zwavejs2mqtt-0 zwavejs2mqtt 2024-11-15 07:55:13.777 INFO STORE: Restarting client in 15 seconds, retry 7
2024-11-15T12:53:49.772Z CNTRLR [BOOTLOADER] !SER2SOCK Connected
!SER2SOCK SERIAL_CONNECTED
ser2sock
is emitting ASCII text that causes Z-Wave JS to continue parsing the input as if it were in bootloader mode.
I think you need to run in raw device mode (-0
flag on the command line) to disable that.
That was it! Thanks!
If anyone else hits this with ser2sock, the docker container entrypoint is a mess. (Even on my fork.) The fix is to force command: /usr/local/bin/ser2sock
and then provide args:
.
command: /usr/local/bin/ser2sock
args: ["-0","-s","/dev/ttyUSB0","-b","115200"]
Checklist
Deploy method
Docker
Z-Wave JS UI version
See bug description
ZwaveJS version
See bug description
Describe the bug
zwave-js-ui: 9.27.0.f3c4ac5 zwave-js: 14.3.1 home id: undefined home hex: undefined
All was working at least until yesterday morning when I last used the door from outside, my door lock is z-wave, that's how I know it was fine at least up to yesterday. Today my housemate was locked out, door lock would not respond, I checked zwavejsui and it had this error:
I navigated to /dev/serial/by-id and the stick is recognized. I checked my docker CLI to ensure it was fine, and it was. I have my container auto-update itself via Watchtower, so the only thing that may have changed from yesterday to today is the zwavejsui version, and I believe this is the issue because upon logging in I received the usual "what's new" popup.
So whatever you did on the latest update as of this post, broke my Aeotec stick. When I say broke, don't worry I don't mean you killed it. I'm just saying it is not working. I will now try to use image tag to downgrade and see if it works again, will update this if it does. Otherwise please be aware it's non-functional and thankfully I was inside to open the door otherwise we'd have no way to get in and would have to break the door! So please treat this urgently as it may affect others, for instance it would be catastrophic if there was a fire and their lock was not operational because the latest update fubar'd something.
Thanks for reading my report, I appreciate your effort in making this software available!
To Reproduce
Not applicable
Expected behavior
Not break the driver...
Additional context
No response