KeyErrors that may be caused or triggered by smartir

[ehedlund76]

Hi

Yesterday I started to notice keyerrors in the systemlog reported from the quirk I'm using for my Tuya Zigbee IR device. Maybe it's been like this for a while, I don't know.

2024-07-31 08:25:49.111 ERROR (MainThread) [bellows.ezsp] Exception running handler
Traceback (most recent call last):
File "/usr/local/lib/python3.12/site-packages/bellows/ezsp/init.py", line 494, in handle_callback
handler(*args)
File "/usr/local/lib/python3.12/site-packages/bellows/zigbee/application.py", line 617, in ezsp_callback_handler
self._handle_frame(*args)
File "/usr/local/lib/python3.12/site-packages/bellows/zigbee/application.py", line 662, in _handle_frame
self.packet_received(
File "/usr/local/lib/python3.12/site-packages/zigpy/application.py", line 1032, in packet_received
return device.packet_received(packet)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/zigpy/device.py", line 497, in packet_received
endpoint.handle_message(
File "/usr/local/lib/python3.12/site-packages/zigpy/endpoint.py", line 247, in handle_message
handler(hdr, args, dst_addressing=dst_addressing)
File "/usr/local/lib/python3.12/site-packages/zigpy/zcl/init.py", line 430, in handle_message
self.handle_cluster_request(hdr, args, dst_addressing=dst_addressing)
File "/config/custom_zha_quirks/ts1201.py", line 304, in handle_cluster_request
irmsg = self.endpoint.device.ir_msg_to_send[seq]
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^
KeyError: 195

To rule out the problem wasn't caused by the quirk, I made an automation that uses zha issue_zigbee_cluster_command to issues all the IR-commands, one by on, from the device codes file I'm using (1266.json). I found that I had to delay each service call by about 1 second to eliminate the errors.

Then I created a script to issue all possible combinations of hvac, preset, fan and temperature with the SmartIR climate component. I set the same delay between each operation, but the same errors started to show up pretty soon. Maybe the quirk or some other component should have handled this, but I've found a couple of things in the SmartIR component that probably should be corrected:

1. I may be wrong, but it seems to me that the delay setting in the configuration is not honored correctly. For testing purposes I've altered climate.py:
   Added await asyncio.sleep(self._delay) after the last await self._controller.send(commands["on"]) in the async def _send_command operation.

2. Traling comma in ZHAController send service_data:
   service_data["params"] = {
   "code": command,
   }
   For testing purposes I've altered controller.py by removing the trailing comma.

I've got no keyerrors in the system log after these small "fixes".

Sorry for my lack of competence on Github :-(

[litinoveweedle]

Hello, thank you for report. The trailing edge comma shall have zero impact on the data structure, it is just byproduct of the python Black formatter. The code with and without comma is equal. I think that this is just coincidence and root cause of the error lays somewhere else.

As you can see Python exception points to the key error - key seq is not defined in the self.endpoint.device.ir_msg_to_send dictionary.

[ehedlund76]

Yes, I agree. The root cause is probably somewhere else, and to me it seems like it's triggered by simultanous/multiple zha calls.

Anyway, when I added "await asyncio.sleep(self._delay)" the issues have disappeared.

[litinoveweedle]

Great finding, where did you put the line? In the SmartIR code?

[ehedlund76]

Yes, in climate.py after the last await self._controller.send(commands["on"]) in the async def _send_command operation. In the version I'm using at line number 769:

                _LOGGER.debug("Send commands.")
                await self._controller.send(commands)
                _LOGGER.debug("Wait for '%s' seconds",self._delay)
                await asyncio.sleep(self._delay)

Also added some debug statements just to check

[ehedlund76]

About here in the latest version: https://github.com/litinoveweedle/SmartIR/blob/master/custom_components/smartir/climate.py#L790

[litinoveweedle]

Right now almost all the proposed changes for this release are merged with master (and current beta is based on that).

In the master there is already sleep after sending 'on' command.

                        else:
                            # if on code is not present, the on bit can be still set later in the all operation/fan codes"""
                            _LOGGER.debug("Found 'on' operation mode command.")
                            await self._controller.send(commands["on"])
                            await asyncio.sleep(self._delay)

So I am bit confused about you modification as the code is already there....

[ehedlund76]

That piece of code is not executed after every code send operation. I've placed it here instead: https://github.com/litinoveweedle/SmartIR/blob/master/custom_components/smartir/climate.py#L790

[ehedlund76]

It seems like the existing code handle sleep after on operation, but not delays between ir calls. According to the docs delay "Adjusts the delay in seconds between multiple commands. The default is 0.5". With my suggested placement it should be handled.

[litinoveweedle]

Great, thank you for reporting, I will fix this and schedule to release it in incoming release.

[ehedlund76]

Thx!

Fyi. I've just finished a couple of days intensive testing of the component and checked that all the IR-codes (in the device codes file I'm using) is picked up and sent correctly by the component. I'm glad to report that I've not been able to find any hickups. Well done, @litinoveweedle!

[litinoveweedle]

Hello, fix was provided in #96 and was merged into master. I will release new beta soon. Please be warned there are additional breaking changes in the controllers configuration in the latest beta.

[litinoveweedle]

The fix was relesed in the latest beta