CNTRLR Failed to execute controller command after X attempts. Scheduling next try in 1100 ms #101068

highfi13g · 2023-09-28T18:26:59Z

The problem

This is a similar issue to #61502.

Same error. However, i may be seeing specifically what the error is. It seems that despite choosing the /dev/serial/by-id/usb-0658_0200-if00 option in the add on config, the logs show that the add-on is still trying to load /dev/ttyACM0.

Log entry showing wrong

What version of Home Assistant Core has the issue?

core-2023.9.3

What was the last working version of Home Assistant Core?

2023.9.3

What type of installation are you running?

Home Assistant OS

Integration causing the issue

zwave-js

Link to integration documentation on our website

https://www.home-assistant.io/integrations/zwave_js/

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
cont-init: info: running /etc/cont-init.d/config.sh
[14:12:38] INFO: No 'network_key' detected, setting it to 's0_legacy_key' for backwards compatibility
[14:12:40] INFO: Flushing config to disk due to creation of new key(s)...
[14:12:42] INFO: Virtual Machine not detected, enabling soft-reset
cont-init: info: /etc/cont-init.d/config.sh exited 0
cont-init: info: running /etc/cont-init.d/structure.sh
cont-init: info: /etc/cont-init.d/structure.sh exited 0
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
services-up: info: copying legacy longrun zwave_js (no readiness notification)
s6-rc: info: service legacy-services successfully started
[14:12:44] INFO: Successfully send discovery information to Home Assistant.
2023-09-28T18:12:47.269Z DRIVER   ███████╗ ██╗    ██╗  █████╗  ██╗   ██╗ ███████╗             ██╗ ███████╗
                                  ╚══███╔╝ ██║    ██║ ██╔══██╗ ██║   ██║ ██╔════╝             ██║ ██╔════╝
                                    ███╔╝  ██║ █╗ ██║ ███████║ ██║   ██║ █████╗   █████╗      ██║ ███████╗
                                   ███╔╝   ██║███╗██║ ██╔══██║ ╚██╗ ██╔╝ ██╔══╝   ╚════╝ ██   ██║ ╚════██║
                                  ███████╗ ╚███╔███╔╝ ██║  ██║  ╚████╔╝  ███████╗        ╚█████╔╝ ███████║
                                  ╚══════╝  ╚══╝╚══╝  ╚═╝  ╚═╝   ╚═══╝   ╚══════╝         ╚════╝  ╚══════╝
2023-09-28T18:12:47.280Z DRIVER   version 12.0.0
2023-09-28T18:12:47.281Z DRIVER   
2023-09-28T18:12:48.384Z CONFIG   version 12.0.0
2023-09-28T18:12:50.146Z CNTRLR   querying Serial API capabilities...
2023-09-28T18:12:51.727Z CNTRLR   Failed to execute controller command after 1/3 attempts. Scheduling next try i
                                  n 100 ms.
2023-09-28T18:12:52.838Z CNTRLR   Failed to execute controller command after 2/3 attempts. Scheduling next try i
                                  n 1100 ms.
2023-09-28T18:12:54.963Z CNTRLR   The controller is unresponsive
2023-09-28T18:12:54.967Z DRIVER   Attempting to recover unresponsive controller...
2023-09-28T18:12:55.032Z CNTRLR   Performing soft reset...
2023-09-28T18:12:56.051Z CNTRLR   Failed to execute controller command after 1/3 attempts. Scheduling next try i
                                  n 100 ms.
2023-09-28T18:12:57.161Z CNTRLR   Failed to execute controller command after 2/3 attempts. Scheduling next try i
                                  n 1100 ms.
2023-09-28T18:12:59.282Z CNTRLR   Soft reset failed: Timeout while waiting for an ACK from the controller (ZW020
                                  0)
2023-09-28T18:12:59.284Z DRIVER   Recovering unresponsive controller failed. Restarting the driver...
Error in driver ZWaveError: Recovering unresponsive controller failed. Restarting the driver... (ZW0100)
    at Driver.destroyWithMessage (/usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:2769:17)
    at fail (/usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:3484:14)
    at /usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:3533:5 {
  code: 100,
  context: undefined,
  transactionSource: undefined
}
Shutting down
2023-09-28T18:12:59.306Z DRIVER   Failed to initialize the driver: ZWaveError: Timeout while waiting for an ACK 
                                  from the controller (ZW0200)
                                      at Driver.sendMessage (/usr/src/node_modules/zwave-js/src/lib/driver/Drive
                                  r.ts:4981:23)
                                      at ZWaveController.identify (/usr/src/node_modules/zwave-js/src/lib/contro
                                  ller/Controller.ts:897:37)
                                      at Driver.initializeControllerAndNodes (/usr/src/node_modules/zwave-js/src
                                  /lib/driver/Driver.ts:1371:26)
                                      at Immediate.<anonymous> (/usr/src/node_modules/zwave-js/src/lib/driver/Dr
                                  iver.ts:1165:16)
Error in driver ZWaveError: Failed to initialize the driver: ZWaveError: Timeout while waiting for an ACK from the controller (ZW0200)
    at Driver.sendMessage (/usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:4981:23)
    at ZWaveController.identify (/usr/src/node_modules/zwave-js/src/lib/controller/Controller.ts:897:37)
    at Driver.initializeControllerAndNodes (/usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:1371:26)
    at Immediate.<anonymous> (/usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:1165:16) (ZW0100)
    at Immediate.<anonymous> (/usr/src/node_modules/zwave-js/src/lib/driver/Driver.ts:1185:6) {
  code: 100,
  context: undefined,
  transactionSource: undefined
}
[18:12:59] WARNING: Halt add-on
s6-rc: info: service legacy-services: stopping
s6-rc: info: service legacy-services successfully stopped
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped

Additional information

No response

The text was updated successfully, but these errors were encountered:

home-assistant · 2023-09-28T18:27:03Z

Hey there @home-assistant/z-wave, mind taking a look at this issue as it has been labeled with an integration (zwave_js) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of zwave_js can trigger bot actions by commenting:

@home-assistant close Closes the issue.
@home-assistant rename Awesome new title Renames the issue.
@home-assistant reopen Reopen the issue.
@home-assistant unassign zwave_js Removes the current integration label and assignees on the issue, add the integration domain after the command.

_{^{(message by CodeOwnersMention)}}

zwave_js documentation
zwave_js source
_{^{(message by IssueLinks)}}

kpine · 2023-09-28T19:05:38Z

[14:12:42] INFO: Virtual Machine not detected, enabling soft-reset

Just to confirm, you are not using a VM, is that correct?

the logs show that the add-on is still trying to load /dev/ttyACM0

I'm not finding a reference to this in the logs you provided. Do you have something else that shows this?

sofa74surfer · 2023-09-30T07:03:26Z

It seams to be exactly the same, like mentioned here: #3230

jamiepenney · 2023-09-30T18:28:49Z

Just to comment on this part, I had a lot of trouble getting the config changes to "stick" when switching from ACM0 to the by-id device. It gets stuck and eventually throws an OOM error if it's on the ACM0 device though.

highfi13g · 2023-09-30T20:16:36Z

Just to confirm, you are not using a VM, is that correct?

Ahh nah not VM

I'm not finding a reference to this in the logs you provided. Do you have something else that shows this?

Doh! The next refresh of the logs removed this. It is indeed showing the same error now as 3230

I may try a firmware upgrade to my Gen5 stick to see if that helps.

kpine · 2023-09-30T22:42:28Z

The add-on doesn't even give me an option to use a non by-id path, so I don't think it's even possible to use anything else. The logs in the other issue aren't showing anything either. They must be using by-id.

Would be nice if the add-on logged it.

lsegal · 2023-10-01T06:58:30Z

Seeing this issue with a VM, but it was working before.

Scorpiondude · 2023-10-02T10:19:35Z

Restored zwavejsmqtt_1.16.0, problems temporary resolved…till automatic update of Z-Wave JS UI 2.0.1

highfi13g · 2023-10-03T02:53:48Z

Ended up switching to Zwave JS UI. Had some issues starting up but worked through them and now i am up and running there. In the last 3 hours i have been live I have had one Unresponsive controller type issue. 🤷🏽

jamiepenney · 2023-10-03T03:08:43Z

@highfi13g I get the same issues when I use Z-Wave JS UI. I've disabled soft-reset, and still get the following error:

2023-10-03 16:06:56.218 INFO Z-WAVE: Zwavejs usage statistics ENABLED
2023-10-03 16:06:56.219 WARN Z-WAVE: Zwavejs driver is not ready yet, statistics will be enabled on driver initialization
2023-10-03T03:06:57.227Z CONFIG version 12.0.0
2023-10-03T03:06:58.697Z CNTRLR querying Serial API capabilities...
2023-10-03T03:06:59.717Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2023-10-03T03:07:00.825Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
2023-10-03T03:07:02.936Z CNTRLR The controller is unresponsive
2023-10-03T03:07:02.938Z DRIVER Attempting to recover unresponsive controller...
2023-10-03T03:07:02.942Z CNTRLR The controller does not support soft reset or the soft reset feature has been
disabled with a config option or the ZWAVEJS_DISABLE_SOFT_RESET environment va
riable.
2023-10-03T03:07:02.944Z DRIVER Recovering unresponsive controller failed. Restarting the driver...
2023-10-03 16:07:02.946 INFO Z-WAVE: Controller status: Driver: Recovering unresponsive controller failed. Restarting the driver... (ZW0100)
2023-10-03 16:07:02.948 INFO Z-WAVE: Restarting client in 15 seconds, retry 12
2023-10-03T03:07:02.950Z DRIVER Failed to initialize the driver: ZWaveError: Timeout while waiting for an ACK
from the controller (ZW0200)
at Driver.sendMessage (/opt/node_modules/zwave-js/src/lib/driver/Driver.ts
:4981:23)
at ZWaveController.identify (/opt/node_modules/zwave-js/src/lib/controller
/Controller.ts:897:37)
at Driver.initializeControllerAndNodes (/opt/node_modules/zwave-js/src/lib
/driver/Driver.ts:1371:26)
at Immediate.<anonymous> (/opt/node_modules/zwave-js/src/lib/driver/Driver
.ts:1165:16)
2023-10-03 16:07:02.952 INFO Z-WAVE: Controller status: Driver: Failed to initialize the driver: ZWaveError: Timeout while waiting for an ACK from the controller (ZW0200)
at Driver.sendMessage (/opt/node_modules/zwave-js/src/lib/driver/Driver.ts:4981:23)
at ZWaveController.identify (/opt/node_modules/zwave-js/src/lib/controller/Controller.ts:897:37)
at Driver.initializeControllerAndNodes (/opt/node_modules/zwave-js/src/lib/driver/Driver.ts:1371:26)
at Immediate.<anonymous> (/opt/node_modules/zwave-js/src/lib/driver/Driver.ts:1165:16) (ZW0100)
2023-10-03 16:07:02.953 INFO Z-WAVE: Restarting client in 15 seconds, retry 13

highfi13g · 2023-10-04T23:16:07Z

Weird man,

Are you already,

Putting your stick on a usb hub instead of directly plugging?
Disabled the Z-Wave JS plug in?

The other thing i can think of is that i disabled NVR backup.

jamiepenney · 2023-10-04T23:20:53Z

Putting your stick on a usb hub instead of directly plugging?

Yep, it's been working for 3 years prior to the latest HA and ZWave JS updates. I'm actually wondering if the ZWave JS update has bricked the stick at this point.

Disabled the Z-Wave JS plug in?

Yep

i disabled NVR backup.

It was already disabled for me.

highfi13g · 2023-10-04T23:23:25Z

I'm actually wondering if the ZWave JS update has bricked the stick at this point.

If mine suddenly working is any indication; there may still be hope for yer stick 😄

raman325 · 2023-10-06T00:14:32Z

this is effectively a dupe of home-assistant/addons#3234 which has more info so closing this in favor of that one

home-assistant bot added the integration: zwave_js label Sep 28, 2023

raman325 closed this as completed Oct 6, 2023

github-actions bot locked and limited conversation to collaborators Nov 5, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

CNTRLR Failed to execute controller command after X attempts. Scheduling next try in 1100 ms #101068

CNTRLR Failed to execute controller command after X attempts. Scheduling next try in 1100 ms #101068

highfi13g commented Sep 28, 2023

home-assistant bot commented Sep 28, 2023

kpine commented Sep 28, 2023 •

edited

sofa74surfer commented Sep 30, 2023 •

edited

jamiepenney commented Sep 30, 2023

highfi13g commented Sep 30, 2023

kpine commented Sep 30, 2023

lsegal commented Oct 1, 2023

Scorpiondude commented Oct 2, 2023

highfi13g commented Oct 3, 2023 •

edited

jamiepenney commented Oct 3, 2023

highfi13g commented Oct 4, 2023

jamiepenney commented Oct 4, 2023

highfi13g commented Oct 4, 2023

raman325 commented Oct 6, 2023

CNTRLR Failed to execute controller command after X attempts. Scheduling next try in 1100 ms #101068

CNTRLR Failed to execute controller command after X attempts. Scheduling next try in 1100 ms #101068

Comments

highfi13g commented Sep 28, 2023

The problem

What version of Home Assistant Core has the issue?

What was the last working version of Home Assistant Core?

What type of installation are you running?

Integration causing the issue

Link to integration documentation on our website

Diagnostics information

Example YAML snippet

Anything in the logs that might be useful for us?

Additional information

home-assistant bot commented Sep 28, 2023

kpine commented Sep 28, 2023 • edited

sofa74surfer commented Sep 30, 2023 • edited

jamiepenney commented Sep 30, 2023

highfi13g commented Sep 30, 2023

kpine commented Sep 30, 2023

lsegal commented Oct 1, 2023

Scorpiondude commented Oct 2, 2023

highfi13g commented Oct 3, 2023 • edited

jamiepenney commented Oct 3, 2023

highfi13g commented Oct 4, 2023

jamiepenney commented Oct 4, 2023

highfi13g commented Oct 4, 2023

raman325 commented Oct 6, 2023

kpine commented Sep 28, 2023 •

edited

sofa74surfer commented Sep 30, 2023 •

edited

highfi13g commented Oct 3, 2023 •

edited