search

zigpy / zha-device-handlers

ZHA device handlers bridge the functionality gap created when manufacturers deviate from the ZCL specification, handling deviations and exceptions by parsing custom messages to and from Zigbee devices.
Apache License 2.0
686 stars 637 forks source link

[BUG] Unhandled exception TypeError: ZCLCommandDef object is not subscriptable #2318

Closed adamschmalhofer closed 1 year ago

adamschmalhofer commented 1 year ago

Describe the bug After upgrading Homeassistant Core to 2023.4.0 my TRADFRI open/close remote from IKEA stopped reacting to button press events. Battery level is still displayed.

Looking at the logs with ha core logs and searching for ikea reviles the TypeError (see "Additional logs" below) or alternatively via webinterface searching for zigpy

To Reproduce Steps to reproduce the behavior:

  1. Have an automation on the button press of the ikea tradfri open/close remote button with a 2023.3
  2. Upgrade to 2023.4
  3. Press Button; see no reaction from automation
  4. check log with ha core logs and search for ikea

Expected behavior Automation reacts to button presses. No TypeError exception thrown

Device signature IEEE: 68:0a:e2:ff:fe:55:03:03 Nwk: 0xaa5b Device Type: EndDevice LQI: 255 RSSI: -32 Zuletzt gesehen: 2023-04-06T12:28:29 Energiequelle: Battery or Unknown Eigenart: zhaquirks.ikea.opencloseremote.IkeaTradfriOpenCloseRemote ```yaml { "node_descriptor": "NodeDescriptor(logical_type=, complex_descriptor_available=0, user_descriptor_available=0, reserved=0, aps_flags=0, frequency_band=, mac_capability_flags=, manufacturer_code=4476, maximum_buffer_size=82, maximum_incoming_transfer_size=82, server_mask=11264, maximum_outgoing_transfer_size=82, descriptor_capability_field=, *allocate_address=True, *is_alternate_pan_coordinator=False, *is_coordinator=False, *is_end_device=True, *is_full_function_device=False, *is_mains_powered=False, *is_receiver_on_when_idle=False, *is_router=False, *is_security_capable=False)", "endpoints": { "1": { "profile_id": 260, "device_type": "0x0203", "in_clusters": [ "0x0000", "0x0001", "0x0003", "0x0009", "0x0020", "0x1000", "0xfc7c" ], "out_clusters": [ "0x0003", "0x0004", "0x0008", "0x0019", "0x0102", "0x1000" ] } }, "manufacturer": "\u0002KE", "model": "TRADFRI open/close remote", "class": "zhaquirks.ikea.opencloseremote.IkeaTradfriOpenCloseRemote" } ```
Diagnostic information ```yaml { "home_assistant": { "installation_type": "Home Assistant OS", "version": "2023.4.0", "dev": false, "hassio": true, "virtualenv": false, "python_version": "3.10.10", "docker": true, "arch": "aarch64", "timezone": "Europe/Berlin", "os_name": "Linux", "os_version": "5.15.84-v8", "supervisor": "2023.04.0", "host_os": "Home Assistant OS 9.5", "docker_version": "20.10.22", "chassis": "embedded", "run_as_root": true }, "custom_components": { "grocy": { "version": "0.0.0", "requirements": [ "pygrocy==1.4.1" ] } }, "integration_manifest": { "domain": "zha", "name": "Zigbee Home Automation", "after_dependencies": [ "onboarding", "usb" ], "codeowners": [ "@dmulcahey", "@adminiuga", "@puddly" ], "config_flow": true, "dependencies": [ "file_upload" ], "documentation": "https://www.home-assistant.io/integrations/zha", "iot_class": "local_polling", "loggers": [ "aiosqlite", "bellows", "crccheck", "pure_pcapy3", "zhaquirks", "zigpy", "zigpy_deconz", "zigpy_xbee", "zigpy_zigate", "zigpy_znp" ], "requirements": [ "bellows==0.35.0", "pyserial==3.5", "pyserial-asyncio==0.6", "zha-quirks==0.0.95", "zigpy-deconz==0.20.0", "zigpy==0.54.0", "zigpy-xbee==0.17.0", "zigpy-zigate==0.10.3", "zigpy-znp==0.10.0" ], "usb": [ { "vid": "10C4", "pid": "EA60", "description": "*2652*", "known_devices": [ "slae.sh cc2652rb stick" ] }, { "vid": "1A86", "pid": "55D4", "description": "*sonoff*plus*", "known_devices": [ "sonoff zigbee dongle plus v2" ] }, { "vid": "10C4", "pid": "EA60", "description": "*sonoff*plus*", "known_devices": [ "sonoff zigbee dongle plus" ] }, { "vid": "10C4", "pid": "EA60", "description": "*tubeszb*", "known_devices": [ "TubesZB Coordinator" ] }, { "vid": "1A86", "pid": "7523", "description": "*tubeszb*", "known_devices": [ "TubesZB Coordinator" ] }, { "vid": "1A86", "pid": "7523", "description": "*zigstar*", "known_devices": [ "ZigStar Coordinators" ] }, { "vid": "1CF1", "pid": "0030", "description": "*conbee*", "known_devices": [ "Conbee II" ] }, { "vid": "10C4", "pid": "8A2A", "description": "*zigbee*", "known_devices": [ "Nortek HUSBZB-1" ] }, { "vid": "0403", "pid": "6015", "description": "*zigate*", "known_devices": [ "ZiGate+" ] }, { "vid": "10C4", "pid": "EA60", "description": "*zigate*", "known_devices": [ "ZiGate" ] }, { "vid": "10C4", "pid": "8B34", "description": "*bv 2010/10*", "known_devices": [ "Bitron Video AV2010/10" ] } ], "zeroconf": [ { "type": "_esphomelib._tcp.local.", "name": "tube*" }, { "type": "_zigate-zigbee-gateway._tcp.local.", "name": "*zigate*" }, { "type": "_zigstar_gw._tcp.local.", "name": "*zigstar*" }, { "type": "_slzb-06._tcp.local.", "name": "slzb-06*" } ], "is_built_in": true }, "data": { "ieee": "**REDACTED**", "nwk": 43611, "manufacturer": "\u0002KE", "model": "TRADFRI open/close remote", "name": "\u0002KE TRADFRI open/close remote", "quirk_applied": true, "quirk_class": "zhaquirks.ikea.opencloseremote.IkeaTradfriOpenCloseRemote", "manufacturer_code": 4476, "power_source": "Battery or Unknown", "lqi": 255, "rssi": -32, "last_seen": "2023-04-06T12:28:29", "available": true, "device_type": "EndDevice", "signature": { "node_descriptor": "NodeDescriptor(logical_type=, complex_descriptor_available=0, user_descriptor_available=0, reserved=0, aps_flags=0, frequency_band=, mac_capability_flags=, manufacturer_code=4476, maximum_buffer_size=82, maximum_incoming_transfer_size=82, server_mask=11264, maximum_outgoing_transfer_size=82, descriptor_capability_field=, *allocate_address=True, *is_alternate_pan_coordinator=False, *is_coordinator=False, *is_end_device=True, *is_full_function_device=False, *is_mains_powered=False, *is_receiver_on_when_idle=False, *is_router=False, *is_security_capable=False)", "endpoints": { "1": { "profile_id": 260, "device_type": "0x0203", "in_clusters": [ "0x0000", "0x0001", "0x0003", "0x0009", "0x0020", "0x1000", "0xfc7c" ], "out_clusters": [ "0x0003", "0x0004", "0x0008", "0x0019", "0x0102", "0x1000" ] } } }, "active_coordinator": false, "entities": [ { "entity_id": "button.ke_tradfri_open_close_remote_identify", "name": "\u0002KE TRADFRI open/close remote" }, { "entity_id": "sensor.ke_tradfri_open_close_remote_battery", "name": "\u0002KE TRADFRI open/close remote" } ], "neighbors": [], "routes": [], "endpoint_names": [ { "name": "WINDOW_COVERING_CONTROLLER" } ], "user_given_name": "Bad-Lichtschalter", "device_reg_id": "fa88261516b8b2eb04cae448d71978b0", "area_id": "bad", "cluster_details": { "1": { "device_type": { "name": "WINDOW_COVERING_CONTROLLER", "id": 515 }, "profile_id": 260, "in_clusters": { "0x0000": { "endpoint_attribute": "basic", "attributes": {}, "unsupported_attributes": {} }, "0x0001": { "endpoint_attribute": "power", "attributes": { "0x0020": { "attribute_name": "battery_voltage", "value": 25 }, "0x0021": { "attribute_name": "battery_percentage_remaining", "value": 32 }, "0x0031": { "attribute_name": "battery_size", "value": 10 }, "0x0033": { "attribute_name": "battery_quantity", "value": 1 } }, "unsupported_attributes": {} }, "0x0003": { "endpoint_attribute": "identify", "attributes": {}, "unsupported_attributes": {} }, "0x0009": { "endpoint_attribute": "alarms", "attributes": {}, "unsupported_attributes": {} }, "0x0020": { "endpoint_attribute": "poll_control", "attributes": { "0x0000": { "attribute_name": "checkin_interval", "value": 13200 } }, "unsupported_attributes": {} }, "0x1000": { "endpoint_attribute": "lightlink", "attributes": {}, "unsupported_attributes": {} }, "0xfc7c": { "endpoint_attribute": "manufacturer_specific", "attributes": {}, "unsupported_attributes": {} } }, "out_clusters": { "0x0003": { "endpoint_attribute": "identify", "attributes": {}, "unsupported_attributes": {} }, "0x0004": { "endpoint_attribute": "groups", "attributes": {}, "unsupported_attributes": {} }, "0x0008": { "endpoint_attribute": "level", "attributes": {}, "unsupported_attributes": {} }, "0x0019": { "endpoint_attribute": "ota", "attributes": {}, "unsupported_attributes": {} }, "0x0102": { "endpoint_attribute": "window_covering", "attributes": {}, "unsupported_attributes": {} }, "0x1000": { "endpoint_attribute": "lightlink", "attributes": {}, "unsupported_attributes": {} } } } } } } ```
Additional logs ``` Logger: zigpy_deconz.uart Source: /usr/local/lib/python3.10/site-packages/zigpy_deconz/uart.py:86 First occurred: 5. April 2023 um 23:58:05 (113 occurrences) Last logged: 12:28:33 Unexpected error handling the frame Traceback (most recent call last): File "/usr/local/lib/python3.10/site-packages/zigpy_deconz/uart.py", line 84, in data_received self._api.data_received(frame) File "/usr/local/lib/python3.10/site-packages/zigpy_deconz/api.py", line 373, in data_received getattr(self, f"_handle_{command.name}")(data) File "/usr/local/lib/python3.10/site-packages/zigpy_deconz/api.py", line 505, in _handle_aps_data_indication self._app.handle_rx( File "/usr/local/lib/python3.10/site-packages/zigpy_deconz/zigbee/application.py", line 448, in handle_rx self.packet_received( File "/usr/local/lib/python3.10/site-packages/zigpy/application.py", line 913, in packet_received self.handle_message( File "/usr/local/lib/python3.10/site-packages/zigpy/application.py", line 434, in handle_message return sender.handle_message( File "/usr/local/lib/python3.10/site-packages/zigpy/device.py", line 367, in handle_message self.endpoints[src_ep].handle_message( File "/usr/local/lib/python3.10/site-packages/zigpy/endpoint.py", line 224, in handle_message handler(hdr, args, dst_addressing=dst_addressing) File "/usr/local/lib/python3.10/site-packages/zigpy/zcl/__init__.py", line 375, in handle_message self.handle_cluster_request(hdr, args, dst_addressing=dst_addressing) File "/usr/local/lib/python3.10/site-packages/zhaquirks/ikea/opencloseremote.py", line 68, in handle_cluster_request cmd_name = self.server_commands.get(hdr.command_id, [hdr.command_id])[0] TypeError: 'ZCLCommandDef' object is not subscriptable ```
adamschmalhofer commented 1 year ago

@javicalle I noticed that you are the only one you changed zhaquirks/ikea/opencloseremote.py this cycle and did some refactoring. Could you have a look? Is it perhaps as simple as removing the [0] from cmd_name = self.server_commands.get(hdr.command_id, [hdr.command_id])[0] ?

MattWestb commented 1 year ago

I can confirming i dont getting any zha_events but the device is making checkins every 50 min = OK. Also if open the paring windows i can see its sending open and closing commands. I running on 24.5 firmware from Dirigera its its using the same quirk and shall working the same way.

Your linked PR was not braking then i was testing my remote for 2 week ago with HA 2023.3 and it was working.

I locking if i can finding any strange.

MattWestb commented 1 year ago

Im getting errors in HA log then using the remote and the error i have seen some user is having with custom quirks:

Logger: bellows.ezsp
Source: /usr/local/lib/python3.10/site-packages/bellows/ezsp/__init__.py:359
First occurred: 15:12:55 (16 occurrences)
Last logged: 15:14:28

Exception running handler
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/bellows/ezsp/__init__.py", line 357, in handle_callback
    handler(*args)
  File "/usr/local/lib/python3.10/site-packages/bellows/zigbee/application.py", line 463, in ezsp_callback_handler
    self._handle_frame(*args)
  File "/usr/local/lib/python3.10/site-packages/bellows/zigbee/application.py", line 508, in _handle_frame
    self.packet_received(
  File "/usr/local/lib/python3.10/site-packages/zigpy/application.py", line 913, in packet_received
    self.handle_message(
  File "/usr/local/lib/python3.10/site-packages/zigpy/application.py", line 434, in handle_message
    return sender.handle_message(
  File "/usr/local/lib/python3.10/site-packages/zigpy/device.py", line 367, in handle_message
    self.endpoints[src_ep].handle_message(
  File "/usr/local/lib/python3.10/site-packages/zigpy/endpoint.py", line 224, in handle_message
    handler(hdr, args, dst_addressing=dst_addressing)
  File "/usr/local/lib/python3.10/site-packages/zigpy/zcl/__init__.py", line 375, in handle_message
    self.handle_cluster_request(hdr, args, dst_addressing=dst_addressing)
  File "/usr/local/lib/python3.10/site-packages/zhaquirks/ikea/opencloseremote.py", line 68, in handle_cluster_request
    cmd_name = self.server_commands.get(hdr.command_id, [hdr.command_id])[0]
TypeError: 'ZCLCommandDef' object is not subscriptable

So its not one changes we was doing in the IKEA quirks but somthing in zigpy / ZHA.

Sorry @javicalle for pinging you but its one command that have start making problem with the last update: https://github.com/zigpy/zha-device-handlers/blob/db3288dd0387331178b6b7d02a5558424aee6124/zhaquirks/ikea/opencloseremote.py#L68

Can you taking one look if you can see what need being changes for getting it working ??

I think our P have doing somthing as normal ;-)))))))

javicalle commented 1 year ago

Hi there, my changes are from 2022. I can't see nothing in the last changes that justifies the error (https://github.com/zigpy/zha-device-handlers/commit/5aeee41925323ea4fd499a394e3be2c2d5643f87) The class hierarchy doesn't seems to have changed neither:

Maybe the issue can be related to https://github.com/zigpy/zigpy/commit/2cbb79f4335947a71c039a37ff26e87940dbd7a7

I would suggest to try with:

cmd_name = self.server_commands.get(hdr.command_id, (hdr.command_id)).name

Maybe some code validation should be added to ensure not null values but to test now can be enought.

javicalle commented 1 year ago

Probably something like this: https://github.com/zigpy/zha-device-handlers/blob/db3288dd0387331178b6b7d02a5558424aee6124/zhaquirks/__init__.py#L118-L126

MattWestb commented 1 year ago

https://github.com/zigpy/zha-device-handlers/issues/2318#issuecomment-1499249654 is working great i was patching the HA container and all 4 DA looks working well :-))

Was it our @puddly that was doing something not so nice ? ;-))

MattWestb commented 1 year ago

@adamschmalhofer If you like fixing your device you can installing the quirk as local quirk https://github.com/zigpy/zha-device-handlers/discussions/693#discussioncomment-857274 and copy the original and changing the line 68 ad proposed and restarting HA and all shall working OK.

puddly commented 1 year ago

Hmm, this should have been caught with a unit test.

@javicalle the above code seems a little redundant with the outer if block. If self.server_commands.get(hdr.command_id) is not None is True, then the command definition exists, so self.server_commands[hdr.command_id].name gets you the command name. The .get(id, [id])[0] hack shouldn't exist anymore but it's still around in a few places missed by unit tests.