When provisioning preferred thread credentials: AttributeError: 'NoneType' object has no attribute 'encode'

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

74k stars 31.05k forks source link

When provisioning preferred thread credentials: AttributeError: 'NoneType' object has no attribute 'encode' #125925

Open maia opened 2 months ago

maia commented 2 months ago

The problem

I cannot provision the preferred thread credentials to a Nanoleaf Essentials Homekit Lightstrip (NL55). Steps to reproduce:

delete device, restart HA, run "Recorder: Purge entities" for this device, restart HA again
reset device until it flashes
it shows up as a discovered Homekit device in HA web GUI. Add it using the Homekit pairing code.
confirm it shows up as a homekit device and can be controlled properly. Thread Capabilities say "Router Eligible End Device", Thread Status is "disabled"
press "Provision Preferred Thread Credentials" button
the error message "Failed to perform the action button/press. 'NoneType' object has no attribute 'encode'" shows up.
two errors show up in the log file: "HomeKit device update skipped as previous poll still in flight" and "AttributeError: 'NoneType' object has no attribute 'encode'", see below.

I had the device working as a thread router until today. It was connected to a SkyConnect OTBR thread network, which I decided to remove completely. I upgraded all my eligible Eve and Nanoleaf devices to Matter and readded them to the Thread network of my HomePod Mini. They all work and properly connect to thread. Just my only remaining Homekit device will not connect to Thread.

I have also tried to provision from by iOS companion app. It also shows "AttributeError: 'NoneType' object has no attribute 'encode'". Both my iOS app and the HA server have the thread network credentials, they show the (i) icon next to the Apple BorderRouter and display channel, dataset id, pan id and extended pan id.

My HA server is a Raspberry Pi 4. I have tried enabling and disabling both the internal bluetooth antenna and the external Zexmte Bluetooth Adapter RTL8761B. Distance between the light strip and the HA server are 3 meters with line of sight.

What version of Home Assistant Core has the issue?

core-2024.9.1

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

websocket_api

Link to integration documentation on our website

https://www.home-assistant.io/integrations/websocket_api/

Diagnostics information

homekit_controller-01J7PE62QMW45VJJXKPSP3GPGJ-Nanoleaf Strip 7B7T-0324317f570466cc4d3f772b15695dbf.json

Example YAML snippet

No response

Anything in the logs that might be useful for us?

Logger: homeassistant.components.homekit_controller.connection
Source: components/homekit_controller/connection.py:896
integration: HomeKit Device (documentation, issues)
First occurred: 21:40:05 (1 occurrences)
Last logged: 21:40:05

HomeKit device update skipped as previous poll still in flight: D7:C3:3E:95:91:D8

and:

Logger: homeassistant.components.websocket_api.http.connection
Source: components/websocket_api/commands.py:245
integration: Home Assistant WebSocket API (documentation, issues)
First occurred: 21:40:07 (1 occurrences)
Last logged: 21:40:07

[547293214560] Unexpected exception
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 245, in handle_call_service
    response = await hass.services.async_call(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2761, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2804, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 996, in entity_service_call
    single_response = await _handle_entity_call(
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 1068, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/button/__init__.py", line 132, in _async_press_action
    await self.async_press()
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/button.py", line 190, in async_press
    await self._accessory.async_thread_provision()
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/connection.py", line 1032, in async_thread_provision
    await self.pairing.thread_provision(dataset)
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ble/pairing.py", line 197, in _async_operation_lock_wrap
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/bleak_retry_connector/__init__.py", line 505, in _async_wrap_bluetooth_connection_error_retry
    return await func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ble/pairing.py", line 236, in _async_force_fresh_connection
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ble/pairing.py", line 213, in _async_restore_and_resume
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ble/pairing.py", line 1560, in thread_provision
    (1, decoded.networkname.encode("utf-8")),
        ^^^^^^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'encode'



### Additional information

_No response_

home-assistant[bot] commented 2 months ago

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

Code owner commands

Code owners of `websocket_api` 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 websocket_api` 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)}}

websocket_api documentation websocket_api source _{^{(message by IssueLinks)}}

maia commented 2 months ago

And more errors:

Log details (ERROR)

Logger: homeassistant.components.homekit_controller.config_flow
Source: components/homekit_controller/config_flow.py:454
integration: HomeKit Device (documentation, issues)
First occurred: 23:19:50 (1 occurrences)
Last logged: 23:19:50

Pairing attempt failed with an unhandled exception
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/config_flow.py", line 454, in async_step_pair
    return await self._entry_from_accessory(pairing)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/config_flow.py", line 582, in _entry_from_accessory
    name = await pairing.get_primary_name()
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/abstract.py", line 264, in get_primary_name
    accessories = await self.list_accessories_and_characteristics()
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/coap/pairing.py", line 149, in list_accessories_and_characteristics
    accessories = await self.connection.get_accessory_info()
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/coap/connection.py", line 413, in get_accessory_info
    _, body = await self.enc_ctx.post(OpCode.UNK_09_READ_GATT, 0x0000, b"")
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/coap/connection.py", line 194, in post
    res_pdu = await self.post_bytes(req_pdu)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/coap/connection.py", line 171, in post_bytes
    response = await self.coap_ctx.request(request).response
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiocoap/protocol.py", line 758, in _run_outer
    await cls._run(app_request, response, weak_observation, protocol, log)
  File "/usr/local/lib/python3.12/site-packages/aiocoap/protocol.py", line 833, in _run
    blockresponse = await blockrequest.response
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^
aiocoap.error.LibraryShutdown

Logger: coap-server
Source: runner.py:189
First occurred: 23:19:51 (1 occurrences)
Last logged: 23:19:51

An exception that is not an aiocoap Error was raised from a transport; please report this as a bug in aiocoap: TypeError("'NoneType' object does not support item assignment")

Logger: aiohomekit.utils
Source: /usr/local/lib/python3.12/site-packages/aiohomekit/utils.py:45
First occurred: 23:19:51 (1 occurrences)
Last logged: 23:19:51

Failure running background task: Task-4297
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/utils.py", line 40, in _handle_task_result
    task.result()
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/coap/pairing.py", line 169, in _process_config_changed
    await self.list_accessories_and_characteristics()
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/coap/pairing.py", line 149, in list_accessories_and_characteristics
    accessories = await self.connection.get_accessory_info()
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/coap/connection.py", line 413, in get_accessory_info
    _, body = await self.enc_ctx.post(OpCode.UNK_09_READ_GATT, 0x0000, b"")
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/coap/connection.py", line 194, in post
    res_pdu = await self.post_bytes(req_pdu)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/coap/connection.py", line 171, in post_bytes
    response = await self.coap_ctx.request(request).response
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiocoap/protocol.py", line 758, in _run_outer
    await cls._run(app_request, response, weak_observation, protocol, log)
  File "/usr/local/lib/python3.12/site-packages/aiocoap/protocol.py", line 833, in _run
    blockresponse = await blockrequest.response
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiocoap/protocol.py", line 473, in send
    request_interface.request(pipe)
  File "/usr/local/lib/python3.12/site-packages/aiocoap/tokenmanager.py", line 246, in request
    self.outgoing_requests[key] = request
    ~~~~~~~~~~~~~~~~~~~~~~^^^^^
TypeError: 'NoneType' object does not support item assignment

Logger: homeassistant.components.recorder.entity_registry
Source: components/recorder/entity_registry.py:76
integration: Recorder (documentation, issues)
First occurred: 23:23:52 (5 occurrences)
Last logged: 23:23:52

Cannot migrate history for entity_id `button.nanoleaf_strip_7b7t_identify` to `button.wohnzimmer_lightstrip_identify` because the new entity_id is already in use
Cannot migrate history for entity_id `light.nanoleaf_strip_7b7t_nanoleaf_light_strip` to `light.wohnzimmer_lightstrip_nanoleaf_light_strip` because the new entity_id is already in use
Cannot migrate history for entity_id `button.nanoleaf_strip_7b7t_provision_preferred_thread_credentials` to `button.wohnzimmer_lightstrip_provision_preferred_thread_credentials` because the new entity_id is already in use
Cannot migrate history for entity_id `sensor.nanoleaf_strip_7b7t_thread_capabilities` to `sensor.wohnzimmer_lightstrip_thread_capabilities` because the new entity_id is already in use
Cannot migrate history for entity_id `sensor.nanoleaf_strip_7b7t_thread_status` to `sensor.wohnzimmer_lightstrip_thread_status` because the new entity_id is already in use

Logger: homeassistant.components.light
Source: helpers/entity_platform.py:761
integration: Light (documentation, issues)
First occurred: 23:24:23 (1 occurrences)
Last logged: 23:24:23

Platform homekit_controller does not generate unique IDs. ID C4:69:C2:7B:60:12_1_48 already exists - ignoring light.wohnzimmer_lightstrip_nanoleaf_light_strip

Logger: homeassistant.components.sensor
Source: helpers/entity_platform.py:761
integration: Sensor (documentation, issues)
First occurred: 23:24:23 (2 occurrences)
Last logged: 23:24:23

Platform homekit_controller does not generate unique IDs. ID C4:69:C2:7B:60:12_1_112_115 already exists - ignoring sensor.wohnzimmer_lightstrip_thread_capabilities
Platform homekit_controller does not generate unique IDs. ID C4:69:C2:7B:60:12_1_112_117 already exists - ignoring sensor.wohnzimmer_lightstrip_thread_status

Logger: homeassistant.components.button
Source: helpers/entity_platform.py:761
integration: Button (documentation, issues)
First occurred: 23:24:23 (2 occurrences)
Last logged: 23:24:23

Platform homekit_controller does not generate unique IDs. ID C4:69:C2:7B:60:12_1_112_119 already exists - ignoring button.wohnzimmer_lightstrip_provision_preferred_thread_credentials
Platform homekit_controller does not generate unique IDs. ID C4:69:C2:7B:60:12_1_1_2 already exists - ignoring button.wohnzimmer_lightstrip_identify

maia commented 2 months ago

Here are some more logs. And as for context, this only remaining homekit device that I cannot provision the preferred thread credentials is supposed to act as a thread router, many devices in my home depend on this router. They might now only be connected to the border router with other routers with worse signal quality, so "previous poll still in flight" might be caused by a bad connection to them. But this homekit device is rather close to the border router and has two ESP32 BLE proxies about 2-3 meters away from it too.

2024-09-14 10:18:48.345 INFO (MainThread) [homeassistant.components.homekit_controller.connection] HomeKit device no longer detecting back pressure - not skipping poll: C4:69:C2:7B:60:12
2024-09-14 10:20:51.185 WARNING (MainThread) [homeassistant.components.homekit_controller.connection] HomeKit device update skipped as previous poll still in flight: C4:69:C2:7B:60:12
2024-09-14 10:21:53.229 INFO (MainThread) [homeassistant.components.homekit_controller.connection] HomeKit device no longer detecting back pressure - not skipping poll: C4:69:C2:7B:60:12
2024-09-14 10:26:53.196 WARNING (MainThread) [homeassistant.components.homekit_controller.connection] HomeKit device update skipped as previous poll still in flight: C4:69:C2:7B:60:12
2024-09-14 10:27:38.392 INFO (MainThread) [homeassistant.components.homekit_controller.connection] HomeKit device no longer detecting back pressure - not skipping poll: C4:69:C2:7B:60:12
2024-09-14 10:29:54.704 WARNING (MainThread) [homeassistant.components.homekit_controller.connection] HomeKit device update skipped as previous poll still in flight: C4:69:C2:7B:60:12
2024-09-14 10:31:04.189 INFO (MainThread) [homeassistant.components.homekit_controller.connection] HomeKit device no longer detecting back pressure - not skipping poll: C4:69:C2:7B:60:12
2024-09-14 10:31:15.313 WARNING (MainThread) [homeassistant.components.homekit_controller.connection] HomeKit device update skipped as previous poll still in flight: C4:69:C2:7B:60:12
2024-09-14 10:31:18.138 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [546838423456] Unexpected exception
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 245, in handle_call_service
    response = await hass.services.async_call(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2761, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2804, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 996, in entity_service_call
    single_response = await _handle_entity_call(
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 1068, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/button/__init__.py", line 132, in _async_press_action
    await self.async_press()
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/button.py", line 190, in async_press
    await self._accessory.async_thread_provision()
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/connection.py", line 1032, in async_thread_provision
    await self.pairing.thread_provision(dataset)
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ble/pairing.py", line 197, in _async_operation_lock_wrap
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/bleak_retry_connector/__init__.py", line 505, in _async_wrap_bluetooth_connection_error_retry
    return await func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ble/pairing.py", line 236, in _async_force_fresh_connection
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ble/pairing.py", line 213, in _async_restore_and_resume
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ble/pairing.py", line 1560, in thread_provision
    (1, decoded.networkname.encode("utf-8")),
        ^^^^^^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'encode'
2024-09-14 10:31:25.204 INFO (MainThread) [homeassistant.components.homekit_controller.connection] HomeKit device no longer detecting back pressure - not skipping poll: C4:69:C2:7B:60:12
2024-09-14 10:32:19.660 WARNING (MainThread) [homeassistant.components.homekit_controller.connection] HomeKit device update skipped as previous poll still in flight: C4:69:C2:7B:60:12
2024-09-14 10:32:20.923 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [546838423456] Unexpected exception
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 245, in handle_call_service
    response = await hass.services.async_call(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2761, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2804, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 996, in entity_service_call
    single_response = await _handle_entity_call(
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 1068, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/button/__init__.py", line 132, in _async_press_action
    await self.async_press()
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/button.py", line 190, in async_press
    await self._accessory.async_thread_provision()
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/connection.py", line 1032, in async_thread_provision
    await self.pairing.thread_provision(dataset)
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ble/pairing.py", line 197, in _async_operation_lock_wrap
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/bleak_retry_connector/__init__.py", line 505, in _async_wrap_bluetooth_connection_error_retry
    return await func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ble/pairing.py", line 236, in _async_force_fresh_connection
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ble/pairing.py", line 213, in _async_restore_and_resume
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ble/pairing.py", line 1560, in thread_provision
    (1, decoded.networkname.encode("utf-8")),
        ^^^^^^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'encode'

maia commented 2 months ago

And here some debug logs for exactly the time when I pressed "provision preferred thread credentials", I restarted HA before, waited a minute and them pressed the button:

2024-09-14 11:51:14.350 DEBUG (MainThread) [homeassistant.components.homekit_controller.config_flow] Discovered device HASS Bridge E6DDD7 (HASS Bridge - 02:26:5E:E6:DD:D7)
2024-09-14 11:51:14.350 DEBUG (MainThread) [homeassistant.components.homekit_controller.config_flow] HomeKit device 02:26:5E:E6:DD:D7 ignored as already paired
2024-09-14 11:51:34.554 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Migrating device registry entries for pairing C4:69:C2:7B:60:12
2024-09-14 11:51:34.554 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Removing legacy serial numbers from device registry entries for pairing C4:69:C2:7B:60:12
2024-09-14 11:51:34.554 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Removing stale entity registry entries for pairing C4:69:C2:7B:60:12
2024-09-14 11:51:34.556 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Starting HomeKit device update: C4:69:C2:7B:60:12
2024-09-14 11:51:38.392 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Called async_set_available_state with True for C4:69:C2:7B:60:12
2024-09-14 11:51:38.393 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Finished HomeKit device update: C4:69:C2:7B:60:12
2024-09-14 11:52:11.218 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Starting HomeKit device update: 6F:7A:3A:E5:71:28
2024-09-14 11:52:11.251 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Called async_set_available_state with True for 6F:7A:3A:E5:71:28
2024-09-14 11:52:11.252 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Finished HomeKit device update: 6F:7A:3A:E5:71:28
2024-09-14 11:52:38.149 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Migrating device registry entries for pairing C4:69:C2:7B:60:12
2024-09-14 11:52:38.150 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Removing legacy serial numbers from device registry entries for pairing C4:69:C2:7B:60:12
2024-09-14 11:52:38.150 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Removing stale entity registry entries for pairing C4:69:C2:7B:60:12
2024-09-14 11:52:38.154 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Starting HomeKit device update: C4:69:C2:7B:60:12
2024-09-14 11:52:43.108 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Migrating device registry entries for pairing C4:69:C2:7B:60:12
2024-09-14 11:52:43.108 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Removing legacy serial numbers from device registry entries for pairing C4:69:C2:7B:60:12
2024-09-14 11:52:43.108 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Removing stale entity registry entries for pairing C4:69:C2:7B:60:12
2024-09-14 11:52:43.112 WARNING (MainThread) [homeassistant.components.homekit_controller.connection] HomeKit device update skipped as previous poll still in flight: C4:69:C2:7B:60:12
2024-09-14 11:52:44.721 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [547470195248] Unexpected exception
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 245, in handle_call_service
    response = await hass.services.async_call(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2761, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2804, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 996, in entity_service_call
    single_response = await _handle_entity_call(
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 1068, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/button/__init__.py", line 132, in _async_press_action
    await self.async_press()
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/button.py", line 190, in async_press
    await self._accessory.async_thread_provision()
  File "/usr/src/homeassistant/homeassistant/components/homekit_controller/connection.py", line 1032, in async_thread_provision
    await self.pairing.thread_provision(dataset)
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ble/pairing.py", line 197, in _async_operation_lock_wrap
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/bleak_retry_connector/__init__.py", line 505, in _async_wrap_bluetooth_connection_error_retry
    return await func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ble/pairing.py", line 236, in _async_force_fresh_connection
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ble/pairing.py", line 213, in _async_restore_and_resume
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ble/pairing.py", line 1560, in thread_provision
    (1, decoded.networkname.encode("utf-8")),
        ^^^^^^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'encode'
2024-09-14 11:52:46.959 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Called async_set_available_state with True for C4:69:C2:7B:60:12
2024-09-14 11:52:46.960 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Finished HomeKit device update: C4:69:C2:7B:60:12

home-assistant[bot] commented 2 months ago

Hey there @jc2k, @bdraco, mind taking a look at this issue as it has been labeled with an integration (homekit_controller) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of `homekit_controller` 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 homekit_controller` 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)}}

homekit_controller documentation homekit_controller source _{^{(message by IssueLinks)}}

Jc2k commented 2 months ago

Your preferred network credential is incomplete, if it does not have the network name we can't provision the device on to the thread network.

Matter is provisioned differently (code on the iOS app directly adds it to thread without involving the preferred network settings in HA).

I don't know why your preferred network credential is incomplete or how it's possible to add an incomplete one. If you added it via the iOS app it might by a limitation of the iOS app. But I think you'd have to raise an issue against the app in that case.

You can work around it by pairing the device to iOS home app, making sure it's connected by thread, unpairing it, then and only then adding it to HA. When you unpair a device it stays on its current thread network. When you add it to HA this way you skip the step that's not working. That's how i added all my devices to my HomePod minis.

maia commented 2 months ago

@Jc2k Thanks for the suggestion. I followed the workaround multiple times:

Paired the device with Apple Home.
Waited a few minutes until it showed as using Thread (verified in the iOS Eve and Nanoleaf apps).
Removed it from Home.app without resetting the device.

However, when HA discovers the device, it asks for the pairing code, then tells me the device is already paired and needs to be reset. I’m not sure why this is happening. If needed, I can retry and provide the debug logs.

Regarding the missing network name: the HA iOS Companion app (Settings > Debugging > Thread) shows two Thread networks saved in Apple Keychain:

“MyHome47” (from my Apple HomePod Mini)
“home-assistant” (from my HA OTBR, which is deactivated but still stored in the Apple Keychain)

The “Transfer to Home Assistant” button turns green when pressed for the "MyHome47" network.

Is there a way to delete the Thread credentials currently saved in HA and re-add the credentials from the Companion app, ideally without having to re-add all ~30 Matter devices that are working fine? Alternatively, can I manually add the network name in HA?

For context, HA used the Thread network "MyHome47" about a year ago. I later moved everything to the OTBR network, but have since moved them back because the iOS apps couldn’t access devices in the OTBR network. The network name seems to have disappeared from HA during that time when it wasn’t in use.

Thanks again!

maia commented 2 months ago

@Jc2k Regarding the missing network name in the Thread credentials stored in the Home Assistant database: Do you know if there’s a way to pull the current Thread dataset through the WebSocket API, set the network name, and push it back to Home Assistant? I assume that Python Scripts cannot interact with the WebSocket API directly, but perhaps AppDaemon, a custom integration, or something else could handle this?

I’m really just looking for a one-time fix to restore the network name without having to re-pair all my Matter and HomeKit devices. The HomeKit device I’m currently having trouble joining to Thread is a Nanoleaf light strip, which was previously acting as a Thread router. Without it, my Thread network has a weak spot, causing many devices to frequently go offline.

Any advice on how to approach this would be greatly appreciated.

maia commented 2 months ago

I copied .storage/thread.datasets and used parse_tlv from python-otbr-api/main/python_otbr_api/tlv_parser.pyto decode my current thread.dataset. I can see that the TLV contains the Channel, PAN ID, Extended PAN ID, Network Key and Active Timestamp. I don't know what it should contain, but there's no network name in the saved dataset.

import binascii
from tlv_parser import parse_tlv

# TLV data from the dataset
tlv_hex = "00030000190102ae5…d0820e080000000000030000"
tlv_bytes = binascii.unhexlify(tlv_hex)
tlv_str = binascii.hexlify(tlv_bytes).decode()
parsed_tlv = parse_tlv(tlv_str)
print(parsed_tlv)

Here's the parsed data:

Channel:
   - Tag: CHANNEL
   - Data: b'\x00\x00\x19'
   - Channel Number: 25

PAN ID:
   - Tag: PANID
   - Data: b'\xaeV'

Extended PAN ID:
   - Tag: EXTPANID
   - Data: b'4\xbc…\x06'

Network Key:
   - Tag: NETWORKKEY
   - Data: b'\t\x15F…\xd0\x82'

Active Timestamp:
   - Tag: ACTIVETIMESTAMP
   - Data: b'\x00\x00\x00\x00\x00\x03\x00\x00'
   - Seconds: 3
   - Ticks: 0

maia commented 2 months ago

With the help of @Jc2k I managed to solve the issue:

As mentioned above, decode the TLV currently stored in .storage/thread.datasets
Use this gist, copy the current TLV data, increase the TIMESTAMP by 1 second, add the missing network name and create a new TLV: https://gist.github.com/Jc2k/b29c63e374382d749546df498b678fd0
Make a full backup of Home Assistant
Go to Settings > Devices & Services > Thread, click "Configure" for the current Thread service
Click the three dots in the top right and choose: "Add dataset from TLV"
Enter the generated TLV.
You'll now see that the preferred network has its network name restored. Wait about a minute, then your Thread Border Router will show up again too.

I don't know what exactly to suggest for future versions of HA. Obviously there should be no need to manually decode and encode credentials. But also there should be no need for ever having to update the credentials manually too. So maybe my primary wish is that HA validates the credentials from time to time and alerts the user in case of issues. Also credentials should only be saved by HA when they are valid.

ffedee7 commented 5 days ago

@maia Hi, I'm having the same problem but with Nanoleaf Essential Bulbs (non-Matter). I have a bunch of them that were working correctly, but I moved so I removed them from HA, resetted them, and now when I try to add them I have the same issue that you have. I've tried 10 different bulbs (the usual reset-add to apple home-wait til they are on thread-remove from home-add to HA) without luck, I always get the same error as you. If there is a way to just reset everything thread-related I'm okay with that.

On the other hand, I could try what you did, Im quite technical but not very familiar with how Thread works, can you try to explain me how to achieve the first 2 steps? Thanks!

maia commented 5 days ago

@ffedee7 I have to admit, the process was rather challenging for me, even though it wasn't my first time working with Python code. You'd need to install python and run some code from https://github.com/home-assistant-libs/python-otbr-api/blob/63fc1f1f15ffbcd11de0c3bc65ec8113f8299387/python_otbr_api/tlv_parser.py . Unfortunately I cannot remember my steps and I cannot find any file locally including parse_tlv, but in my experience ChatGPT is a great assistant that can guide you through the process of running code. Maybe you can also find online tools to decode a TLV, as I believe TLV isn't just used for Thread credentials.

The other solution I can think of is to completely disable/delete anything thread related from your HA configuration and from your mobile devices and factory reset all IoT devices, including the thread border router you're using and hope that when you set up the border router (e.g. Apple Homepod Mini) it will generate new thread credentials.