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
72.8k stars 30.5k forks source link

matter_server.common.errors.UpdateError: Error while setting up OTA Provider (Unexpected Exception) #123343

Closed 3oris closed 1 month ago

3oris commented 2 months ago

The problem

After Update to core-2024.8.0, Home Assistant offers firmware updates to EVE matter devices which all fail, see trace below.

The state after the update failure is so that the updates cannot be re-initiated: Device Info still shows the old firmware, 

Device info
Eve Motion 20EBY9901
by Eve Systems
Firmware: 3.2.0
Hardware: 1.1

Configuration shows:

Bewegung LAGER
7 minutes ago
Up-to-date
Installed version
3.2.1
Latest version
3.2.1

What version of Home Assistant Core has the issue?

core-2024.8.0

What was the last working version of Home Assistant Core?

core-2024.7.4

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Matter

Link to integration documentation on our website

No response

Diagnostics information

Logger: homeassistant.components.websocket_api.http.connection
Source: components/websocket_api/commands.py:241
integration: Home Assistant WebSocket API (documentation, issues)
First occurred: August 7, 2024 at 9:25:24 PM (2 occurrences)
Last logged: August 7, 2024 at 9:25:36 PM

[281471867836816] Unexpected exception
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/matter/update.py", line 222, in async_install
    await self.matter_client.update_node(
  File "/usr/local/lib/python3.12/site-packages/matter_server/client/client.py", line 536, in update_node
    await self.send_command(
  File "/usr/local/lib/python3.12/site-packages/matter_server/client/client.py", line 583, in send_command
    return await future
           ^^^^^^^^^^^^
matter_server.common.errors.UpdateError: Error while setting up OTA Provider.

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 241, in handle_call_service
    response = await hass.services.async_call(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2763, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2806, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 999, in entity_service_call
    single_response = await _handle_entity_call(
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 1071, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/update/__init__.py", line 154, in async_install
    await entity.async_install_with_progress(version, backup)
  File "/usr/src/homeassistant/homeassistant/components/update/__init__.py", line 458, in async_install_with_progress
    await self.async_install(version, backup)
  File "/usr/src/homeassistant/homeassistant/components/matter/update.py", line 229, in async_install
    raise HomeAssistantError(f"Error updating: {err}") from err
homeassistant.exceptions.HomeAssistantError: Error updating: Error while setting up OTA Provider.

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

harbri commented 2 months ago

I had exactly the same error with my Eve Motion Matter sensors. After restarting the Matter add-on in Home Assistant updating the sensors worked again.

home-assistant[bot] commented 2 months ago

Hey there @home-assistant/matter, mind taking a look at this issue as it has been labeled with an integration (matter) you are listed as a code owner for? Thanks!

Code owner commands Code owners of `matter` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign matter` Removes the current integration label and assignees on the issue, add the integration domain after the command. - `@home-assistant add-label needs-more-information` Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue. - `@home-assistant remove-label needs-more-information` Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

(message by CodeOwnersMention)

matter documentation matter source (message by IssueLinks)

markwiese commented 2 months ago

I have the same issue with Eve Motion sensors and Eve Door & Window sensors. I've tried restarting the Matter Server but it didn't help.

agners commented 2 months ago

@3oris can you reproduce this after restarting the Matter Server and try again?

Can you share the Matter Server logs? (or anyone else with the same error in the Core logs).

3oris commented 2 months ago

@agners - unfortunately, I cannot reproduce this after restarting the matter server. I was able to update a number of eve motion sensors since then.

Unfortunately I now cannot update eve energys with the "unable to process update file" message like here: https://github.com/home-assistant/core/issues/123568

It's either that, or the update runs half way through, then gets stuck (at different percentages from 5% to somewhere in the nighties)

I have 5 nest hub 2nd Gen (fuchsia 18) 1 otbr on rpi HA green (matter controller) ~80 matter over thread devices (mostly nanoleaf and then eve)

This is also why I am usually hesitant to restart the matter server because it takes ages for the thread devices to re-appear on the matter server (thread congestion, then devices backing off)

markwiese commented 1 month ago

@agners I've been re-trying the Matter firmware updates on and off for a month, now, and still not having any luck despite multiple host reboots, core restarts, and Matter Server restarts. My Thread devices connect via SkyConnect dongle (in pure OTBR mode). I also have 4 Nanoleaf devices that act as Thread routers (I thought these may be the issue so I powered them off and attempted a firmware update but it didn't change anything).

Core Log

2024-09-02 17:47:45.419 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [547419600160] Unexpected exception
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/matter/update.py", line 222, in async_install
    await self.matter_client.update_node(
  File "/usr/local/lib/python3.12/site-packages/matter_server/client/client.py", line 536, in update_node
    await self.send_command(
  File "/usr/local/lib/python3.12/site-packages/matter_server/client/client.py", line 583, in send_command
    return await future
           ^^^^^^^^^^^^
matter_server.common.errors.UpdateError: Error while setting up OTA Provider.

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 241, in handle_call_service
    response = await hass.services.async_call(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2763, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2806, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 999, in entity_service_call
    single_response = await _handle_entity_call(
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 1071, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/update/__init__.py", line 154, in async_install
    await entity.async_install_with_progress(version, backup)
  File "/usr/src/homeassistant/homeassistant/components/update/__init__.py", line 458, in async_install_with_progress
    await self.async_install(version, backup)
  File "/usr/src/homeassistant/homeassistant/components/matter/update.py", line 229, in async_install
    raise HomeAssistantError(f"Error updating: {err}") from err
homeassistant.exceptions.HomeAssistantError: Error updating: Error while setting up OTA Provider.

Matter Server Log

2024-09-02 17:47:43.857 (MainThread) INFO [matter_server.server.device_controller] <Node:1> Update to software version 6650
2024-09-02 17:47:43.858 (MainThread) DEBUG [matter_server.server.device_controller] <Node:1> Check for updates.
2024-09-02 17:47:44.535 (MainThread) INFO [matter_server.server.device_controller] <Node:1> New software update found: 3.2.1 on UpdateSource.MAIN_NET_DCL (current 3.2.0).
2024-09-02 17:47:44.536 (MainThread) INFO [matter_server.server.device_controller] <Node:1> Downloading update from 'https://eve-updates.evehome.com/matter/eve_door-3.2.1-matter-benc-enc-3F54862C-1F6C-427A-A650-EC2B739B4734.bin'
2024-09-02 17:47:44.537 (MainThread) DEBUG [matter_server.server.ota.provider] Download update from 'https://eve-updates.evehome.com/matter/eve_door-3.2.1-matter-benc-enc-3F54862C-1F6C-427A-A650-EC2B739B4734.bin'.
2024-09-02 17:47:45.111 (MainThread) INFO [matter_server.server.ota.provider] Update file 'eve_door-3.2.1-matter-benc-enc-3F54862C-1F6C-427A-A650-EC2B739B4734.bin' downloaded to '/config/updates/1'
2024-09-02 17:47:45.112 (MainThread) INFO [matter_server.server.device_controller] <Node:1> Starting update using OTA Provider.
2024-09-02 17:47:45.115 (MainThread) INFO [matter_server.server.ota.provider] Starting OTA Provider
2024-09-02 17:47:45.121 (MainThread) INFO [matter_server.server.ota.provider] Commission and initialize OTA Provider
2024-09-02 17:47:45.320 (Dummy-2) CHIP_ERROR [chip.native.SC] Received error (protocol code 2) during PASE process: src/protocols/secure_channel/PASESession.cpp:774: CHIP Error 0x00000038: Invalid PASE parameter
2024-09-02 17:47:45.321 (Dummy-2) CHIP_ERROR [chip.native.SC] Failed during PASE session setup: src/protocols/secure_channel/PASESession.cpp:774: CHIP Error 0x00000038: Invalid PASE parameter
2024-09-02 17:47:45.323 (Dummy-2) CHIP_ERROR [chip.native.ZCL] Secure Pairing Failed
2024-09-02 17:47:45.325 (Dummy-2) WARNING [chip.ChipDeviceCtrl] Failed to establish secure session to device: src/controller/python/ChipDeviceController-ScriptDevicePairingDelegate.cpp:89: CHIP Error 0x00000003: Incorrect state
2024-09-02 17:47:45.329 (MainThread) ERROR [root] Failed setting up OTA Provider.
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/matter_server/server/ota/provider.py", line 96, in _commission_ota_provider
    commissioned_node_id = await chip_device_controller.commission_on_network(
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/matter_server/server/sdk.py", line 150, in commission_on_network
    await self._chip_controller.CommissionOnNetwork(
  File "/usr/local/lib/python3.11/site-packages/chip/ChipDeviceCtrl.py", line 1872, in CommissionOnNetwork
    return await asyncio.futures.wrap_future(ctx.future)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
chip.exceptions.ChipStackError: src/controller/python/ChipDeviceController-ScriptDevicePairingDelegate.cpp:89: CHIP Error 0x00000003: Incorrect state
2024-09-02 17:47:45.330 (MainThread) INFO [matter_server.server.ota.provider] Cleaning up OTA provider
2024-09-02 17:47:45.331 (MainThread) INFO [matter_server.server.ota.provider] Terminating OTA Provider
2024-09-02 17:47:45.416 (MainThread) ERROR [matter_server.server.client_handler] [547839657488] Error while handling: update_node (node 1): Error while setting up OTA Provider.
2024-09-02 17:47:45.895 (MainThread) DEBUG [matter_server.server.device_controller.mdns] Commissionable Matter node disappeared: AsyncServiceInfo(type='_matterc._udp.local.', name='45CE0C13487F8E41._matterc._udp.local.', addresses=[], port=None, weight=0, priority=0, server=None, properties={}, interface_index=None)

It seems I can reproduce this as often as you'd like, so let me know if you need additional logs or tests done 👍

agners commented 1 month ago

@markwiese can you try with the latest Matter Server (6.5.1) again? You need to set the beta flag on the Matter Server add-on to get it currently.

markwiese commented 1 month ago

@markwiese can you try with the latest Matter Server (6.5.1) again? You need to set the beta flag on the Matter Server add-on to get it currently.

Tested with Matter Server 6.5.1 and I'm no longer getting the error. Thank you!!

agners commented 1 month ago

Unfortunately I now cannot update eve energys with the "unable to process update file" message like here: #123568

@3oris do you still suffer this issue with 6.5.1?

3oris commented 1 month ago

@agners - Sorry, I cannot report back on that because because I currently don't have any devices where updates get offered. All updates already happened on 6.4.x

(I have two (out of three) aqara door sensors though that don't see the availability of an update in the first place. But I think that should be a different issue)

3oris commented 1 month ago

@agners - not sure, should we close this for now?

marcelveldt commented 1 month ago

(I have two (out of three) aqara door sensors though that don't see the availability of an update in the first place. But I think that should be a different issue)

Aqara sensors can (not) yet be updated through DCL.

should we close this for now?

yes lets close for now. You can open a new issue report if you experience more issues.