home-assistant / addons

:heavy_plus_sign: Docker add-ons for Home Assistant
https://home-assistant.io/hassio/
Apache License 2.0
1.53k stars 1.49k forks source link

Unable to add Matter devices #3588

Closed BazlTech closed 4 months ago

BazlTech commented 5 months ago

Describe the issue you are experiencing

Unable to add matter devices (they are thread devices that support matter already added to an Apple Home ecosystem).

What type of installation are you running?

Home Assistant OS

Which operating system are you running on?

Home Assistant Operating System

Which add-on are you reporting an issue with?

Matter Server

What is the version of the add-on?

5.6.0

Steps to reproduce the issue

  1. Matter Server add-on is running
  2. Matter integration is running (checkbox selected to use official Matter add-on)
  3. On Devices & Services page I attempt to add a Matter device using the companion app on iOS. I use the Home app to put the device in sharing mode and get the PIN. I add the PIN to HA.
  4. It eventually just times out and fails to add. See logs for more details ...

System Health information

System Information

version core-2024.5.1
installation_type Home Assistant OS
dev false
hassio true
docker true
user root
virtualenv false
python_version 3.12.2
os_name Linux
os_version 6.6.25-haos
arch x86_64
timezone America/Chicago
config_dir /config
Home Assistant Community Store GitHub API | ok -- | -- GitHub Content | ok GitHub Web | ok GitHub API Calls Remaining | 5000 Installed Version | 1.34.0 Stage | running Available Repositories | 1399 Downloaded Repositories | 3 HACS Data | ok
Home Assistant Cloud logged_in | false -- | -- can_reach_cert_server | ok can_reach_cloud_auth | ok can_reach_cloud | ok
Home Assistant Supervisor host_os | Home Assistant OS 12.2 -- | -- update_channel | stable supervisor_version | supervisor-2024.04.4 agent_version | 1.6.0 docker_version | 25.0.5 disk_total | 468.7 GB disk_used | 10.5 GB healthy | true supported | true board | generic-x86-64 supervisor_api | ok version_api | ok installed_addons | Node-RED (17.0.12), Cloudflared (5.1.9), Studio Code Server (5.15.0), File editor (5.8.0), Terminal & SSH (9.13.0), Z-Wave JS UI (3.6.0), Matter Server (5.6.0)
Dashboards dashboards | 3 -- | -- resources | 3 views | 2 mode | storage
Recorder oldest_recorder_run | April 23, 2024 at 8:28 PM -- | -- current_recorder_run | May 3, 2024 at 12:41 PM estimated_db_size | 10.95 MiB database_engine | sqlite database_version | 3.44.2

Anything in the Supervisor logs that might be useful for us?

2024-05-03 13:05:28.731 WARNING (MainThread) [homeassistant.components.websocket_api.http.connection] [139871492253120] from 2600:1700:2ab0:41dd:e91f:69c3:ff91:22c4 (Mozilla/5.0 (Linux; Android 9; KFTRWI Build/PS7327.3326N; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/110.0.5481.154 Safari/537.36 Home Assistant/2024.1.5-12102 (Android 9; KFTRWI)): Disconnected: Did not receive auth message within 10 seconds
2024-05-03 13:06:29.549 WARNING (MainThread) [homeassistant.components.http.ban] Login attempt or request with invalid authentication from 2600:1700:2ab0:41dd:e91f:69c3:ff91:22c4 (2600:1700:2ab0:41dd:e91f:69c3:ff91:22c4). Requested URL: '/auth/token'. (Home Assistant/2024.1.5-12102 (Android 9; KFTRWI))
2024-05-03 13:06:30.171 WARNING (MainThread) [homeassistant.components.websocket_api.http.connection] [139871472929216] from 2600:1700:2ab0:41dd:e91f:69c3:ff91:22c4 (Mozilla/5.0 (Linux; Android 9; KFTRWI Build/PS7327.3326N; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/110.0.5481.154 Safari/537.36 Home Assistant/2024.1.5-12102 (Android 9; KFTRWI)): Disconnected: Did not receive auth message within 10 seconds

Anything in the add-on logs that might be useful for us?

2024-05-03 13:00:59.552 (Dummy-2) CHIP_PROGRESS [chip.native.CTL] Setting CSR nonce to random value
2024-05-03 13:00:59.552 (Dummy-2) CHIP_DETAIL [chip.native.CTL] Stopping commissioning discovery over DNS-SD
2024-05-03 13:00:59.552 (Dummy-2) CHIP_PROGRESS [chip.native.CTL] Starting commissioning discovery over DNS-SD
2024-05-03 13:00:59.589 (Dummy-2) CHIP_PROGRESS [chip.native.CTL] Discovered device to be commissioned over DNS-SD
2024-05-03 13:00:59.590 (Dummy-2) CHIP_PROGRESS [chip.native.CTL] Attempting PASE connection to UDP:[fde5:fd9f:e5fb:0:5343:58a8:b57c:b9e2]:5540
2024-05-03 13:00:59.591 (Dummy-2) CHIP_DETAIL [chip.native.IN] SecureSession[0x7fd6a000eba0]: Allocated Type:1 LSID:26109
2024-05-03 13:00:59.591 (Dummy-2) CHIP_DETAIL [chip.native.SC] Assigned local session key ID 26109
2024-05-03 13:00:59.592 (Dummy-2) CHIP_PROGRESS [chip.native.EM] <<< [E:58952i S:0 M:142856547] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fde5:fd9f:e5fb:0:5343:58a8:b57c:b9e2]:5540] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)
2024-05-03 13:00:59.593 (Dummy-2) CHIP_DETAIL [chip.native.SC] Sent PBKDF param request
2024-05-03 13:00:59.593 (Dummy-2) CHIP_PROGRESS [chip.native.CTL] Commission called for node ID 0x0000000000000021
2024-05-03 13:01:00.623 (Dummy-2) CHIP_PROGRESS [chip.native.EM] Retransmitting MessageCounter:142856547 on exchange 58952i with Node: <0000000000000000, 0> Send Cnt 1
2024-05-03 13:01:01.613 (Dummy-2) CHIP_PROGRESS [chip.native.EM] Retransmitting MessageCounter:142856547 on exchange 58952i with Node: <0000000000000000, 0> Send Cnt 2
2024-05-03 13:01:03.082 (Dummy-2) CHIP_PROGRESS [chip.native.EM] Retransmitting MessageCounter:142856547 on exchange 58952i with Node: <0000000000000000, 0> Send Cnt 3
2024-05-03 13:01:05.840 (Dummy-2) CHIP_PROGRESS [chip.native.EM] Retransmitting MessageCounter:142856547 on exchange 58952i with Node: <0000000000000000, 0> Send Cnt 4
2024-05-03 13:01:10.138 (Dummy-2) CHIP_ERROR [chip.native.EM] Failed to Send CHIP MessageCounter:142856547 on exchange 58952i with Node: <0000000000000000, 0> sendCount: 4 max retries: 4
2024-05-03 13:01:12.865 (Dummy-2) CHIP_ERROR [chip.native.SC] PASESession timed out while waiting for a response from the peer. Expected message type was 33
2024-05-03 13:01:12.865 (Dummy-2) CHIP_DETAIL [chip.native.IN] SecureSession[0x7fd6a000eba0]: Released - Type:1 LSID:26109
2024-05-03 13:01:12.866 (Dummy-2) CHIP_PROGRESS [chip.native.CTL] Ignoring SecurePairingFailed status for now; we are waiting to see if we discover more devices
2024-05-03 13:01:12.866 (Dummy-2) CHIP_PROGRESS [chip.native.CTL] Waiting to discover commissionees that match our filters
2024-05-03 13:01:29.557 (Dummy-2) CHIP_ERROR [chip.native.CTL] Discovery timed out
2024-05-03 13:01:29.557 (Dummy-2) CHIP_DETAIL [chip.native.CTL] Stopping commissioning discovery over DNS-SD
2024-05-03 13:01:29.558 (Dummy-2) CHIP_ERROR [chip.native.ZCL] Secure Pairing Failed
2024-05-03 13:01:29.558 (Dummy-2) WARNING [root] Failed to establish secure session to device: src/controller/python/ChipDeviceController-ScriptDevicePairingDelegate.cpp:89: CHIP Error 0x00000003: Incorrect state
2024-05-03 13:01:29.558 (Dummy-2) WARNING [root] Failed to commission: src/controller/python/ChipDeviceController-ScriptDevicePairingDelegate.cpp:89: CHIP Error 0x00000003: Incorrect state
2024-05-03 13:01:29.559 (MainThread) ERROR [matter_server.server.client_handler] [140560120584464] Error while handling: commission_with_code: Commission with code failed for node 33.
2024-05-03 13:03:52.647 (Dummy-2) CHIP_DETAIL [chip.native.DIS] SRV record already actively processed.
2024-05-03 13:03:52.648 (Dummy-2) CHIP_DETAIL [chip.native.DIS] SRV record already actively processed.
2024-05-03 13:03:52.648 (Dummy-2) CHIP_DETAIL [chip.native.DIS] SRV record already actively processed.
2024-05-03 13:03:52.648 (Dummy-2) CHIP_DETAIL [chip.native.DIS] SRV record already actively processed.
2024-05-03 13:03:52.649 (Dummy-2) CHIP_DETAIL [chip.native.DIS] SRV record already actively processed.
2024-05-03 13:03:52.649 (Dummy-2) CHIP_DETAIL [chip.native.DIS] SRV record already actively processed.
2024-05-03 13:03:52.649 (Dummy-2) CHIP_DETAIL [chip.native.DIS] SRV record already actively processed.
2024-05-03 13:03:52.650 (Dummy-2) CHIP_DETAIL [chip.native.DIS] SRV record already actively processed.
2024-05-03 13:03:52.650 (Dummy-2) CHIP_DETAIL [chip.native.DIS] SRV record already actively processed.
2024-05-03 13:03:52.650 (Dummy-2) CHIP_DETAIL [chip.native.DIS] SRV record already actively processed.
2024-05-03 13:03:52.651 (Dummy-2) CHIP_DETAIL [chip.native.DIS] SRV record already actively processed.
2024-05-03 13:03:52.651 (Dummy-2) CHIP_DETAIL [chip.native.DIS] SRV record already actively processed.
2024-05-03 13:03:52.651 (Dummy-2) CHIP_DETAIL [chip.native.DIS] SRV record already actively processed.

Additional information

No response

github-actions[bot] commented 4 months ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.