search

home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
73.67k stars 30.8k forks source link

Zwavejs - interviewing Zooz 72 fails #72872

Closed dredjohn21 closed 2 years ago

dredjohn21 commented 2 years ago

The problem

I got an error message “failed to interview device” for my Zooz 72 device through the UI. I’m using the latest zwavejs version (0.1.60).

I contacted Zooz and they advised they have heard of clients having issues with zwavejs and recommended I use the MQTT zwavejs add on, but would prefer to use this official implementation.

What version of Home Assistant Core has the issue?

core-2022.6.0

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Z-wave 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?

is read-only:        false
                                  is advanced (UI):    false
                                  has bulk support:    true
                                  alters capabilities: false
2022-06-02T00:30:19.358Z CNTRLR » [Node 043] querying parameter #10 information...
2022-06-02T00:30:19.398Z CNTRLR   Failed to execute controller command after 1/3 attempts. Scheduling next try i
                                  n 100 ms.
2022-06-02T00:30:19.513Z CNTRLR   Failed to execute controller command after 2/3 attempts. Scheduling next try i
                                  n 1100 ms.
2022-06-02T00:30:20.653Z CNTRLR   [Node 043] failed to decode the message, retrying with SPAN extension...
2022-06-02T00:30:20.657Z CNTRLR   Failed to execute controller command after 1/3 attempts. Scheduling next try i
                                  n 100 ms.
2022-06-02T00:30:20.831Z CNTRLR   [Node 043] failed to decode the message after re-transmission with SPAN extens
                                  ion, dropping the message.
2022-06-02T00:30:20.836Z CNTRLR   [Node 043] Interview attempt 1/5 failed, retrying in 5000 ms...
2022-06-02T00:30:25.841Z CNTRLR   [Node 043] Beginning interview - last completed stage: NodeInfo
2022-06-02T00:30:25.878Z CNTRLR   [Node 043] Embedded device config loaded
2022-06-02T00:30:25.895Z CNTRLR   [Node 043] Interviewing Configuration...
2022-06-02T00:30:25.896Z CNTRLR   [Node 043] ConfigurationCC: Loading configuration parameters from device confi
                                  g
2022-06-02T00:30:25.910Z CNTRLR » [Node 043] finding first configuration parameter...
2022-06-02T00:30:26.025Z CNTRLR » [Node 043] querying parameter #1 information...
2022-06-02T00:30:27.437Z CNTRLR « [Node 043] received information for parameter #1:
                                  parameter name:      Locally Button function
                                  value format:        UnsignedInteger
                                  value size:          1 bytes
                                  min value:           0
                                  max value:           2
                                  default value:       0
                                  is read-only:        false
                                  is advanced (UI):    false
                                  has bulk support:    true
                                  alters capabilities: false
2022-06-02T00:30:27.440Z CNTRLR » [Node 043] querying parameter #2 information...
2022-06-02T00:30:28.414Z CNTRLR « [Node 043] received information for parameter #2:
                                  parameter name:      LED Indicator
                                  value format:        UnsignedInteger
                                  value size:          1 bytes
                                  min value:           0
                                  max value:           3
                                  default value:       0
                                  is read-only:        false
                                  is advanced (UI):    false
                                  has bulk support:    true
                                  alters capabilities: false
2022-06-02T00:30:28.414Z CNTRLR » [Node 043] querying parameter #3 information...
2022-06-02T00:30:29.543Z CNTRLR « [Node 043] received information for parameter #3:
                                  parameter name:      Auto Turn-Off Timer
                                  value format:        UnsignedInteger
                                  value size:          4 bytes
                                  min value:           0
                                  max value:           65535
                                  default value:       0
                                  is read-only:        false
                                  is advanced (UI):    false
                                  has bulk support:    true
                                  alters capabilities: false
2022-06-02T00:30:29.544Z CNTRLR » [Node 043] querying parameter #5 information...
2022-06-02T00:30:30.571Z CNTRLR « [Node 043] received information for parameter #5:
                                  parameter name:      Auto Turn-On Timer
                                  value format:        UnsignedInteger
                                  value size:          4 bytes
                                  min value:           0
                                  max value:           65535
                                  default value:       0
                                  is read-only:        false
                                  is advanced (UI):    false
                                  has bulk support:    true
                                  alters capabilities: false
2022-06-02T00:30:30.572Z CNTRLR » [Node 043] querying parameter #8 information...
2022-06-02T00:30:32.255Z CNTRLR   [Node 043] Timed out while waiting for a response from the node (ZW0201)
2022-06-02T00:30:32.256Z CNTRLR « [Node 043] received information for parameter #8:
                                  parameter name:      Restores state after power failure
                                  value format:        UnsignedInteger
                                  value size:          1 bytes
                                  min value:           0
                                  max value:           2
                                  default value:       2
                                  is read-only:        false
                                  is advanced (UI):    false
                                  has bulk support:    true
                                  alters capabilities: false
2022-06-02T00:30:32.257Z CNTRLR » [Node 043] querying parameter #9 information...
2022-06-02T00:30:32.282Z CNTRLR   Failed to execute controller command after 1/3 attempts. Scheduling next try i
                                  n 100 ms.
2022-06-02T00:30:32.432Z CNTRLR « [Node 043] received S2 nonce, not sure what to do with it
2022-06-02T00:30:32.466Z CNTRLR   [Node 043] in the process of replying to a NonceGet, won't send another NonceR
                                  eport
2022-06-02T00:30:33.638Z CNTRLR   [Node 043] Timed out while waiting for a response from the node (ZW0201)
2022-06-02T00:30:33.639Z CNTRLR   [Node 043] Querying parameter #9 information timed out, skipping interview...
2022-06-02T00:30:33.645Z CNTRLR   [Node 043] Interviewing Central Scene...
2022-06-02T00:30:33.648Z CNTRLR » [Node 043] Querying supported scenes...
2022-06-02T00:30:33.755Z CNTRLR « [Node 043] received supported scenes:
                                  # of scenes:           2
                                  supports slow refresh: true
2022-06-02T00:30:33.757Z CNTRLR » [Node 043] Enabling slow refresh capability...
2022-06-02T00:30:33.804Z CNTRLR   [Node 043] Interview stage completed: CommandClasses
2022-06-02T00:30:33.807Z CNTRLR   [Node 043] Interview stage completed: OverwriteConfig
2022-06-02T00:30:33.808Z CNTRLR   [Node 043] Interview completed
2022-06-02T00:30:33.810Z CNTRLR   [Node 043] The node is ready to be used

Additional information

I also noticed this error in the logs after the latest core upgrade:

Logger: homeassistant.components.websocket_api.http.connection Source: components/zwave_js/light.py:354 Integration: Home Assistant WebSocket API (documentation, issues) First occurred: 7:55:27 PM (1 occurrences) Last logged: 7:55:27 PM

[547157835008] Z-Wave error 1405: The node failed to decode the message. (ZW1405) Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 193, in handle_call_service await hass.services.async_call( File "/usr/src/homeassistant/homeassistant/core.py", line 1704, in async_call task.result() File "/usr/src/homeassistant/homeassistant/core.py", line 1741, in _execute_service await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)( File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 204, in handle_service await service.entity_service_call( File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 680, in entity_service_call future.result() # pop exception if have File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 964, in async_request_call await coro File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 717, in _handle_entity_call await result File "/usr/src/homeassistant/homeassistant/components/light/init.py", line 553, in async_handle_light_on_service await light.async_turn_on(filter_turn_on_params(light, params)) File "/usr/src/homeassistant/homeassistant/components/zwave_js/light.py", line 293, in async_turn_on await self._async_set_brightness(kwargs.get(ATTR_BRIGHTNESS), transition) File "/usr/src/homeassistant/homeassistant/components/zwave_js/light.py", line 354, in _async_set_brightness await self.info.node.async_set_value( File "/usr/local/lib/python3.9/site-packages/zwave_js_server/model/node/init.py", line 446, in async_set_value result = await self.async_send_command( File "/usr/local/lib/python3.9/site-packages/zwave_js_server/model/node/init.py", line 403, in async_send_command result = await self.client.async_send_command(message, kwargs) File "/usr/local/lib/python3.9/site-packages/zwave_js_server/client.py", line 103, in async_send_command return await future zwave_js_server.exceptions.FailedZWaveCommand: Z-Wave error 1405: The node failed to decode the message. (ZW1405)

probot-home-assistant[bot] commented 2 years ago

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! (message by CodeOwnersMention)

zwave_js documentation zwave_js source (message by IssueLinks)

kpine commented 2 years ago

You'll need to post a full log of the add/interview process, the snippet is missing earlier information. See instructions.

Regardless, this is a driver or network issue, HA doesn't have any role in the inclusion and interview. There is a similar open issue for the ZEN72 (can't tell for sure w/o logs) with a pending fix. If that is the right fix, your only option, aside from switching to zwavejs2mqtt, would be to wait for a new driver and then add-on release. It's not possible to install custom device files in the official add-on (but it is in zwavejs2mqtt).

You could also try repeating the interview, one or more times, maybe it will make it through. Or, try including without security, maybe that will have an effect.

dredjohn21 commented 2 years ago

zwave_js.log

Thanks @kpine I attached the log w/ debug on (note: I think the first bit of log activity for this device was me turning off the light first). And fingers crossed the pending fix you linked to solves the problem.

kpine commented 2 years ago

Yes, it's the same problem.

dredjohn21 commented 2 years ago

Cool thanks for confirming @kpine - have a nice weekend