Z-WaveJS has been broken by new HA version - service calls to cover.xxx not working for JS devices

[danielbrunt57]

The problem

None of my Z-Wave devices are working...

EDIT: after a couple of HA restarts, only cover service calls for my iBlinds is not working. Other z-wave devices are** working now. Also note: service calls cover.xxx for my templated cover for MIMOlite garage door open is working as well as a cover that exists in HomeSeer which is exposed into HA via marthoc's custom HomeSeer integration.

What is version of Home Assistant Core has the issue?

core-2021.2.1

What was the last working version of Home Assistant Core?

core-2021.2.0

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/

Example YAML snippet

N/A

Anything in the logs that might be useful for us?

# Put your logs below this line
Logger: homeassistant.core
Source: components/zwave_js/cover.py:76
First occurred: 8:40:36 AM (2 occurrences)
Last logged: 8:41:46 AM

Error executing service: <ServiceCall cover.set_cover_position (c:139dafeb401c61abb248229316162ed5): entity_id=['cover.kitchen_2'], position=40>
Error executing service: <ServiceCall cover.set_cover_position (c:7c7fdb5f85ca035ac20d414329bc9241): entity_id=['cover.kitchen_2'], position=40>
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/core.py", line 1471, in catch_exceptions
    await coro_or_task
  File "/usr/src/homeassistant/homeassistant/core.py", line 1490, in _execute_service
    await handler.job.target(service_call)
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 204, in handle_service
    await self.hass.helpers.service.entity_service_call(
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 595, in entity_service_call
    future.result()  # pop exception if have
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 664, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 632, in _handle_entity_call
    await result
  File "/usr/src/homeassistant/homeassistant/components/zwave_js/cover.py", line 76, in async_set_cover_position
    await self.info.node.async_set_value(
  File "/usr/local/lib/python3.8/site-packages/zwave_js_server/model/node.py", line 250, in async_set_value
    result = await self.client.async_send_command(
  File "/usr/local/lib/python3.8/site-packages/zwave_js_server/client.py", line 64, in async_send_command
    return await future
zwave_js_server.exceptions.FailedCommand: Command failed: unknown_error

[probot-home-assistant[bot]]

Hey there @home-assistant/z-wave, mind taking a look at this issue as its been labeled with an integration (zwave_js) you are listed as a codeowner for? Thanks! _{^{(message by CodeOwnersMention)}}

[kylerw]

I am seeing the same issue:

Logger: homeassistant.components.websocket_api.http.connection Source: components/zwave_js/cover.py:83 Integration: Home Assistant WebSocket API (documentation, issues) First occurred: 9:54:26 AM (6 occurrences) Last logged: 11:39:09 AM

[23021178650240] None [23021283831616] None Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 136, in handle_call_service await hass.services.async_call( File "/usr/src/homeassistant/homeassistant/core.py", line 1455, in async_call task.result() File "/usr/src/homeassistant/homeassistant/core.py", line 1490, in _execute_service await handler.job.target(service_call) File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 204, in handle_service await self.hass.helpers.service.entity_service_call( File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 595, in entity_service_call future.result() # pop exception if have File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 664, in async_request_call await coro File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 632, in _handle_entity_call await result File "/usr/src/homeassistant/homeassistant/components/group/cover.py", line 218, in async_open_cover await self.hass.services.async_call( File "/usr/src/homeassistant/homeassistant/core.py", line 1455, in async_call task.result() File "/usr/src/homeassistant/homeassistant/core.py", line 1490, in _execute_service await handler.job.target(service_call) File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 204, in handle_service await self.hass.helpers.service.entity_service_call( File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 595, in entity_service_call future.result() # pop exception if have File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 664, in async_request_call await coro File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 632, in _handle_entity_call await result File "/usr/src/homeassistant/homeassistant/components/zwave_js/cover.py", line 83, in async_open_cover await self.info.node.async_set_value(target_value, PRESS_BUTTON) File "/usr/local/lib/python3.8/site-packages/zwave_js_server/model/node.py", line 248, in async_set_value val = self.values[val] KeyError: None

[scott7685]

Same experience here

[MartinHjelmare]

I am seeing the same issue:

Logger: homeassistant.components.websocket_api.http.connection Source: components/zwave_js/cover.py:83 Integration: Home Assistant WebSocket API (documentation, issues) First occurred: 9:54:26 AM (6 occurrences) Last logged: 11:39:09 AM [23021178650240] None [23021283831616] None Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 136, in handle_call_service await hass.services.async_call( File "/usr/src/homeassistant/homeassistant/core.py", line 1455, in async_call task.result() File "/usr/src/homeassistant/homeassistant/core.py", line 1490, in _execute_service await handler.job.target(service_call) File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 204, in handle_service await self.hass.helpers.service.entity_service_call( File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 595, in entity_service_call future.result() # pop exception if have File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 664, in async_request_call await coro File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 632, in _handle_entity_call await result File "/usr/src/homeassistant/homeassistant/components/group/cover.py", line 218, in async_open_cover await self.hass.services.async_call( File "/usr/src/homeassistant/homeassistant/core.py", line 1455, in async_call task.result() File "/usr/src/homeassistant/homeassistant/core.py", line 1490, in _execute_service await handler.job.target(service_call) File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 204, in handle_service await self.hass.helpers.service.entity_service_call( File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 595, in entity_service_call future.result() # pop exception if have File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 664, in async_request_call await coro File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 632, in _handle_entity_call await result File "/usr/src/homeassistant/homeassistant/components/zwave_js/cover.py", line 83, in async_open_cover await self.info.node.async_set_value(target_value, PRESS_BUTTON) File "/usr/local/lib/python3.8/site-packages/zwave_js_server/model/node.py", line 248, in async_set_value val = self.values[val] KeyError: None

That's a duplicate of https://github.com/home-assistant/core/issues/45922.

It's not the same stack trace as in the OP.

[marcelveldt]

@danielbrunt57 please do not edit your original post but post a reply. It's very hard for us to notice your update. So everything is working now or is there an issue left ? If so, please describe the issue that is left in detail please.

[danielbrunt57]

After battling this all day, cover.xxx service calls are working now. Countless restarts: JS server, ZW JS integration, HA, entire host. The original errors are no longer appearing. I've no idea what was causing the original issue. All non-cover z-wave entities are working. cover.garage is fine as is cover.homeseer_z_wave_bedroom_blind via marthoc's Homeseer custom integration. 4 of 6 window blinds connected to Z-Wave JS are working. The remaining two are not presenting CC38 entities despite what looks like a successful pairing:

15:52:43.132 CNTRLR   starting inclusion process...
15:52:43.157 CNTRLR   handling add node request (status = Ready)
15:52:43.158 CNTRLR     the controller is now ready to add nodes
15:52:57.158 CNTRLR   handling add node request (status = NodeFound)
15:52:57.163 CNTRLR   handling add node request (status = AddingSlave)
15:52:57.168 CNTRLR   handling add node request (status = ProtocolDone)
15:52:57.168 CNTRLR   stopping inclusion process...
15:52:57.230 CNTRLR   handling add node request (status = Done)
15:52:57.231 CNTRLR   done called for 30
15:52:57.231 CNTRLR   finished adding node 30:
                        basic device class:    Routing Slave
                        generic device class:  Multilevel Switch
                        specific device class: Unused
                        supported CCs: 
                        · Basic (0x20)
                        · Multilevel Switch (0x26)
                        · Z-Wave Plus Info (0x5e)
                        · Association (0x85)
                        · Association Group Information (0x59)
                        · Version (0x86)
                        · Manufacturer Specific (0x72)
                        · Device Reset Locally (0x5a)
                        · Powerlevel (0x73)
                        · Binary Switch (0x25)
                        · Battery (0x80)
                        · Configuration (0x70)
                        controlled CCs: 
15:52:57.231 CNTRLR » [Node 030] Assigning return route to controller...
15:52:57.238 CNTRLR   the inclusion process was stopped
15:52:57.741 CNTRLR   [Node 030] Configuring Z-Wave+ Lifeline association...
15:52:57.824 CNTRLR   [Node 030] Beginning interview - last completed stage: None
15:52:57.825 CNTRLR   [Node 030] new node, doing a full interview...
15:52:57.825 CNTRLR » [Node 030] querying protocol info...
15:52:57.839 CNTRLR « [Node 030] received response for protocol info:
                      basic device class:    Routing Slave
                      generic device class:  Multilevel Switch
                      specific device class: Unused
                      is a listening device: false
                      is frequent listening: true
                      is a routing device:   true
                      is a secure device:    unknown
                      is a beaming device:   true
                      maximum baud rate:     40000 kbps
                      version:               4
15:52:57.847 CNTRLR   [Node 030] Interview stage completed: ProtocolInfo
15:52:57.847 CNTRLR » [Node 030] pinging the node...
15:52:57.915 CNTRLR « [Node 030] ping successful
15:52:57.915 CNTRLR » [Node 030] querying node info...
15:52:58.079 CNTRLR « [Node 030] node info received
                      supported CCs:
                      · Z-Wave Plus Info
                      · Association
                      · Association Group Information
                      · Version
                      · Manufacturer Specific
                      · Device Reset Locally
                      · Powerlevel
                      · Multilevel Switch
                      · Binary Switch
                      · Battery
                      · Configuration
                      controlled CCs:
15:52:58.087 CNTRLR   [Node 030] Interview stage completed: NodeInfo
15:52:58.089 CNTRLR   [Node 030] ManufacturerSpecificCC: doing a partial interview...
15:52:58.090 CNTRLR   [Node 030] VersionCC: doing a partial interview...
15:52:58.090 CNTRLR   [Node 030] trying to load device config
15:52:58.095 CNTRLR   [Node 030] device config loaded
15:52:58.095 CNTRLR   [Node 030] ZWavePlusCC: doing a partial interview...
15:52:58.096 CNTRLR   [Node 030] BatteryCC: doing a partial interview...
15:52:58.097 CNTRLR » [Node 030] querying battery status...
15:52:58.364 CNTRLR « [Node 030] received response for battery information:
                      level:                           100
15:52:58.365 CNTRLR   [Node 030] MultilevelSwitchCC: doing a partial interview...
15:52:58.366 CNTRLR » [Node 030] requesting current switch state...
15:52:58.617 CNTRLR   [Node 030] BinarySwitchCC: doing a partial interview...
15:52:58.618 CNTRLR » [Node 030] querying Binary Switch state...
15:52:58.866 CNTRLR « [Node 030] received Binary Switch state:
                      current value:      true
15:52:58.866 CNTRLR   [Node 030] ConfigurationCC: Loading configuration parameters from device confi
                      g
15:52:58.868 CNTRLR » [Node 030] querying parameter #1 value...
15:52:59.072 CNTRLR « [Node 030] parameter #1 has value: 1
15:52:59.073 CNTRLR   [Node 030] AssociationCC: doing a partial interview...
15:52:59.074 CNTRLR » [Node 030] querying association group #1...
15:52:59.282 CNTRLR « [Node 030] received information for association group #1:
                      maximum # of nodes: 1
                      currently assigned nodes: 1
15:52:59.284 CNTRLR   [Node 030] AssociationGroupInfoCC: doing a partial interview...
15:52:59.284 CNTRLR   [Node 030] Interview stage completed: CommandClasses
15:52:59.285 CNTRLR   [Node 030] Interview stage completed: OverwriteConfig
15:52:59.285 CNTRLR » [Node 030] requesting node neighbors...
15:52:59.300 CNTRLR « [Node 030]   node neighbors received: 1, 3, 8, 9, 12, 21, 22, 23, 26, 27
15:52:59.300 CNTRLR   [Node 030] Interview stage completed: Neighbors
15:52:59.301 CNTRLR   [Node 030] Interview completed
15:52:59.301 CNTRLR   [Node 030] The node is ready to be used
Client disconnected
Code 1000: 
New client

[danielbrunt57]

I've played with ZWaveJS2MQTT and some interesting info re those two nodes...

[marcelveldt]

OK, the remaining issue is two lights (and not cover) not appearing. There is a fix for that on it's way: #46082

[danielbrunt57]

Just to be clear, I wanted to use the ws method to interface, not mqtt. I was just pointing out that the two covers' multilevel switches seem to be presented to mqtt as light, not cover and that the ws method does not seem to see them at all. Strange that it only affected 2 of the 5 V2 blinds and they are all identical including firmware. If #46082 addresses that then great! ETA for that? Should I go beta to get it earlier??

[danielbrunt57]

I am completely up to date as of now with all core, supervisor, add-on's, integrations... I've removed the two problem nodes and re-added one of them but it is showing a light entity for the multi-sensor switch:

1. iBlinds V2 (still in HomeSeer)
2. iBlinds V3
3. iBlinds V2
4. iBlinds V2
5. iBlinds V2
6. iBlinds V2
7. Node excluded

[danielbrunt57]

Should I open a new issue??

[MartinHjelmare]

2021.2.2 is released. Please test it and open a new issue for remaining problems.