home-assistant-libs / python-matter-server

Python server to interact with Matter
Apache License 2.0
485 stars 76 forks source link

Matter light platform crashing on missing attributes #344

Closed Gonta01 closed 1 year ago

Gonta01 commented 1 year ago

Logs python-matter-server:

2023-06-29 10:32:01 core-matter-server matter_server.server.helpers.paa_certificates[126] INFO Fetching the latest PAA root certificates from DCL.
2023-06-29 10:32:02 core-matter-server matter_server.server.helpers.paa_certificates[126] INFO Fetched 0 PAA root certificates from DCL.
2023-06-29 10:32:02 core-matter-server matter_server.server.helpers.paa_certificates[126] INFO Fetching the latest PAA root certificates from Git.
2023-06-29 10:32:02 core-matter-server matter_server.server.helpers.paa_certificates[126] INFO Fetched 0 PAA root certificates from Git.
2023-06-29 10:32:06 core-matter-server chip.EM[126] ERROR Failed to Send CHIP MessageCounter:1397172 on exchange 9584i sendCount: 4 max retries: 4
2023-06-29 10:32:08 core-matter-server chip.SC[126] ERROR PASESession timed out while waiting for a response from the peer. Expected message type was 33
2023-06-29 10:32:08 core-matter-server chip.ZCL[126] ERROR Secure Pairing Failed
marcelveldt commented 1 year ago

A little more context would be very helpful as this report is kinda useless in this shape.

Gonta01 commented 1 year ago

Trying to connect Extended color light device on ESP32C3 basis (or ESP32C6 for Thread). Data model consists of endpoint 0 (root) and endpoint 1. Endpoint 1 has a color temperature light data type and I added color control cluster with Hue saturation configuration. Commission through HomeAssistant app. Matter server is an add-on. Here are some additional logs from debug logging.

2023-07-03 17:29:33.353 ERROR (MainThread) [homeassistant.components.light] Error adding entities for domain light with platform matter
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 471, in async_add_entities
    await asyncio.gather(*tasks)
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 749, in _async_add_entity
    await entity.add_to_platform_finish()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 849, in add_to_platform_finish
    await self.async_added_to_hass()
  File "/usr/src/homeassistant/homeassistant/components/matter/entity.py", line 99, in async_added_to_hass
    self._update_from_device()
  File "/usr/src/homeassistant/homeassistant/components/matter/light.py", line 342, in _update_from_device
    self._attr_xy_color = self._get_xy_color()
                          ^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/matter/light.py", line 153, in _get_xy_color
    assert x_color is not None
           ^^^^^^^^^^^^^^^^^^^
AssertionError
2023-07-03 17:29:33.373 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 471, in async_add_entities
    await asyncio.gather(*tasks)
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 749, in _async_add_entity
    await entity.add_to_platform_finish()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 849, in add_to_platform_finish
    await self.async_added_to_hass()
  File "/usr/src/homeassistant/homeassistant/components/matter/entity.py", line 99, in async_added_to_hass
    self._update_from_device()
  File "/usr/src/homeassistant/homeassistant/components/matter/light.py", line 342, in _update_from_device
    self._attr_xy_color = self._get_xy_color()
                          ^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/matter/light.py", line 153, in _get_xy_color
    assert x_color is not None
           ^^^^^^^^^^^^^^^^^^^
AssertionError
2023-07-03 17:29:37.802 ERROR (MainThread) [homeassistant.components.matter] Unexpected exception: 
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/matter/__init__.py", line 128, in _client_listen
    await matter_client.start_listening(init_ready)
  File "/usr/local/lib/python3.11/site-packages/matter_server/client/client.py", line 331, in start_listening
    self._handle_incoming_message(msg)
  File "/usr/local/lib/python3.11/site-packages/matter_server/client/client.py", line 370, in _handle_incoming_message
    self._handle_event_message(msg)
  File "/usr/local/lib/python3.11/site-packages/matter_server/client/client.py", line 393, in _handle_event_message
    self._signal_event(event, data=node, node_id=node.node_id)
  File "/usr/local/lib/python3.11/site-packages/matter_server/client/client.py", line 433, in _signal_event
    callback(event, data)
  File "/usr/src/homeassistant/homeassistant/components/matter/entity.py", line 110, in _on_matter_event
    self._update_from_device()
  File "/usr/src/homeassistant/homeassistant/components/matter/light.py", line 342, in _update_from_device
    self._attr_xy_color = self._get_xy_color()
                          ^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/matter/light.py", line 153, in _get_xy_color
    assert x_color is not None
           ^^^^^^^^^^^^^^^^^^^
AssertionError
2023-07-03 17:29:37.942 ERROR (MainThread) [homeassistant.components.light] Error adding entities for domain light with platform matter
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 471, in async_add_entities
    await asyncio.gather(*tasks)
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 749, in _async_add_entity
    await entity.add_to_platform_finish()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 849, in add_to_platform_finish
    await self.async_added_to_hass()
  File "/usr/src/homeassistant/homeassistant/components/matter/entity.py", line 99, in async_added_to_hass
    self._update_from_device()
  File "/usr/src/homeassistant/homeassistant/components/matter/light.py", line 342, in _update_from_device
    self._attr_xy_color = self._get_xy_color()
                          ^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/matter/light.py", line 153, in _get_xy_color
    assert x_color is not None
           ^^^^^^^^^^^^^^^^^^^
AssertionError
2023-07-03 17:29:37.951 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 471, in async_add_entities
    await asyncio.gather(*tasks)
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 749, in _async_add_entity
    await entity.add_to_platform_finish()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 849, in add_to_platform_finish
    await self.async_added_to_hass()
  File "/usr/src/homeassistant/homeassistant/components/matter/entity.py", line 99, in async_added_to_hass
    self._update_from_device()
  File "/usr/src/homeassistant/homeassistant/components/matter/light.py", line 342, in _update_from_device
    self._attr_xy_color = self._get_xy_color()
                          ^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/matter/light.py", line 153, in _get_xy_color
    assert x_color is not None
           ^^^^^^^^^^^^^^^^^^^
AssertionError
marcelveldt commented 1 year ago

Would it be possible for you to test the HA beta 2023.7 version ? I fixed a few bugs in this regard where we kinda assumed XY color support where only HS was there

Gonta01 commented 1 year ago

In what way is it possible to test it? I chose System - Updates - Join beta channel. Then checked for updates but there weren't any beta updates shown.

marcelveldt commented 1 year ago

It should work that way but maybe it takes a while before the beta pops up then.

marcelveldt commented 1 year ago

@Gonta01 can this issue be closed ?

Gonta01 commented 1 year ago

The same problem remains. Logs are the same for Matter server side.

marcelveldt commented 1 year ago

Is the device still commissioned ? Are you able to re-commission it to HA and then grab the log from that attempt ? First of all I'm interested in the Matter server log but if commissioning succeeds and the device does not work in HA, I'd like to receive the HA logs too.

So, if possible, please test with the latest Matter server and Home Assistant 2023.7.1

Gonta01 commented 1 year ago

Matter server version: 4.8.2 Home Assistant 2023.7.1 It seems to me that commissioning succeeds since device is visible but after "Connecting device to Home Assistant" error occurs "Something went wrong" and it isn't possible to control device. Matter server add-on logs:

2023-07-12 08:50:05 core-matter-server matter_server.server.helpers.paa_certificates[125] INFO Fetching the latest PAA root certificates from DCL.
2023-07-12 08:50:06 core-matter-server matter_server.server.helpers.paa_certificates[125] INFO Fetched 0 PAA root certificates from DCL.
2023-07-12 08:50:06 core-matter-server matter_server.server.helpers.paa_certificates[125] INFO Fetching the latest PAA root certificates from Git.
2023-07-12 08:50:06 core-matter-server matter_server.server.helpers.paa_certificates[125] INFO Fetched 0 PAA root certificates from Git.
2023-07-12 08:50:13 core-matter-server PersistentStorage[125] INFO SetSdkKey: f/1/s/0000000000000009 = b'\x150\x03\x10\x19t(\xb9Ma\xec*=\xe6\xa9\xcb\xbf`\xa520\x04 8\xf7\xcb08\xe26V\xa6\xe5cr\rA6\xe4\xea\xa9(v\x9a^V\x81\x1e\xfc\x1em\x01\xa0\xcfl0\x05\x0c\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x18'
2023-07-12 08:50:13 core-matter-server PersistentStorage[125] INFO Committing...
2023-07-12 08:50:13 core-matter-server PersistentStorage[125] INFO SetSdkKey: g/s/GXQouU1h7Co95qnLv2ClMg== = b'\x15$\x01\x01$\x02\t\x18'
2023-07-12 08:50:13 core-matter-server PersistentStorage[125] INFO Committing...
2023-07-12 08:50:13 core-matter-server PersistentStorage[125] INFO SetSdkKey: g/sri = b'\x16\x15$\x01\x01$\x02\x03\x18\x15$\x01\x01$\x02\x04\x18\x15$\x01\x01$\x02\x05\x18\x15$\x01\x01$\x02\x06\x18\x15$\x01\x01$\x02\x07\x18\x15$\x01\x01$\x02\x08\x18\x15$\x01\x01$\x02\t\x18\x18'
2023-07-12 08:50:13 core-matter-server PersistentStorage[125] INFO Committing...
2023-07-12 08:50:22 core-matter-server matter_server.server.device_controller.[node 9][125] INFO Subscription succeeded
2023-07-12 08:50:23 core-matter-server matter_server.server.device_controller.[node 9][125] INFO Subscription succeeded

HA logs: home-assistant_matter_logs.log

marcelveldt commented 1 year ago

OK, the device commissioned just fine but there is a bug in our HA integration causing it to fail completely on the data from this light. Strictly taken this is a device bug because xy color is mandatory while HS is optional.

Nevertheless we'll fix it in our code so does not crash this hard. I'll move this issue to the HA core issue tracker and report back when we have a fix in place.