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
71.13k stars 29.8k forks source link

Matter nodes offline #123980

Open josephdouce opened 4 weeks ago

josephdouce commented 4 weeks ago

The problem

The matter node is showing offline.

I am able to ping the node from the entity page.

See log 2nd from bottom, "Unable to subscribe"

What version of Home Assistant Core has the issue?

2024.8.1

What was the last working version of Home Assistant Core?

na

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Matter Server

Link to integration documentation on our website

No response

Diagnostics information

s6-rc: info: service legacy-cont-init: starting s6-rc: info: service legacy-cont-init successfully started


Add-on: Matter Server Matter WebSocket Server for Home Assistant Matter support.

Add-on version: 6.4.1 You are running the latest version of this add-on. System: Home Assistant OS 12.2 (amd64 / qemux86-64) Home Assistant Core: 2024.8.1 Home Assistant Supervisor: 2024.08.0

Please, share the above information when looking for help or support in, e.g., GitHub, forums or the Discord chat.

s6-rc: info: service banner successfully started s6-rc: info: service matter-server: starting s6-rc: info: service matter-server successfully started s6-rc: info: service legacy-services: starting [10:52:31] INFO: Starting Matter Server... s6-rc: info: service legacy-services successfully started [10:52:32] INFO: Using 'enp2s2' as primary network interface. [10:52:32] INFO: Successfully send discovery information to Home Assistant. 2024-08-15 10:52:38.171 (MainThread) INFO [matter_server.server.stack] Initializing CHIP/Matter Logging... 2024-08-15 10:52:38.172 (MainThread) INFO [matter_server.server.stack] Initializing CHIP/Matter Controller Stack... [1723715558.462185][126:126] CHIP:CTL: Setting attestation nonce to random value [1723715558.468933][126:126] CHIP:CTL: Setting CSR nonce to random value [1723715558.497472][126:126] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1723715558.497836][126:126] CHIP:DL: writing settings to file (/tmp/chip_kvs-svrH9I) [1723715558.497956][126:126] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1723715558.498379][126:126] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /data/chip_factory.ini [1723715558.498619][126:126] CHIP:DL: writing settings to file (/data/chip_factory.ini-zZV9VI) [1723715558.498729][126:126] CHIP:DL: renamed tmp file to file (/data/chip_factory.ini) [1723715558.498781][126:126] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /data/chip_config.ini [1723715558.498853][126:126] CHIP:DL: writing settings to file (/data/chip_config.ini-3C3eKJ) [1723715558.498952][126:126] CHIP:DL: renamed tmp file to file (/data/chip_config.ini) [1723715558.499017][126:126] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /data/chip_counters.ini [1723715558.499092][126:126] CHIP:DL: writing settings to file (/data/chip_counters.ini-7GxvWG) [1723715558.499185][126:126] CHIP:DL: renamed tmp file to file (/data/chip_counters.ini) [1723715558.504919][126:126] CHIP:DL: writing settings to file (/data/chip_factory.ini-KM1jQJ) [1723715558.506881][126:126] CHIP:DL: renamed tmp file to file (/data/chip_factory.ini) [1723715558.506964][126:126] CHIP:DL: NVS set: chip-factory/unique-id = "C0EF100E02F26CB8" [1723715558.507314][126:126] CHIP:DL: writing settings to file (/data/chip_factory.ini-CWLInL) [1723715558.508450][126:126] CHIP:DL: renamed tmp file to file (/data/chip_factory.ini) [1723715558.508653][126:126] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1) [1723715558.509353][126:126] CHIP:DL: writing settings to file (/data/chip_factory.ini-neWNOK) [1723715558.510277][126:126] CHIP:DL: renamed tmp file to file (/data/chip_factory.ini) [1723715558.510574][126:126] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001) [1723715558.511287][126:126] CHIP:DL: writing settings to file (/data/chip_counters.ini-qaKRgK) [1723715558.512240][126:126] CHIP:DL: renamed tmp file to file (/data/chip_counters.ini) [1723715558.512418][126:126] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1) [1723715558.512986][126:126] CHIP:DL: writing settings to file (/data/chip_counters.ini-W4zQuI) [1723715558.514317][126:126] CHIP:DL: renamed tmp file to file (/data/chip_counters.ini) [1723715558.514436][126:126] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1723715558.515317][126:126] CHIP:DL: writing settings to file (/data/chip_counters.ini-WZ4EeH) [1723715558.516322][126:126] CHIP:DL: renamed tmp file to file (/data/chip_counters.ini) [1723715558.516423][126:126] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0) [1723715558.516939][126:126] CHIP:DL: writing settings to file (/data/chip_config.ini-CE1EkK) [1723715558.517905][126:126] CHIP:DL: renamed tmp file to file (/data/chip_config.ini) [1723715558.518007][126:126] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0) [1723715558.519001][126:126] CHIP:DL: writing settings to file (/data/chip_config.ini-xhX5XJ) [1723715558.520015][126:126] CHIP:DL: renamed tmp file to file (/data/chip_config.ini) [1723715558.520119][126:126] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2) [1723715558.521651][126:126] CHIP:DL: Got Ethernet interface: enp2s2 [1723715558.523171][126:126] CHIP:DL: Found the primary Ethernet interface:enp2s2 [1723715558.524918][126:126] CHIP:DL: Failed to get WiFi interface [1723715558.524992][126:126] CHIP:DL: Failed to reset WiFi statistic counts 2024-08-15 10:52:38.525 (MainThread) INFO [chip.storage] Initializing persistent storage from file: /data/chip.json 2024-08-15 10:52:38.526 (MainThread) ERROR [chip.storage] [Errno 2] No such file or directory: '/data/chip.json' 2024-08-15 10:52:38.527 (MainThread) CRITICAL [chip.storage] Could not load configuration from /data/chip.json - resetting configuration... 2024-08-15 10:52:38.527 (MainThread) WARNING [chip.storage] No valid SDK configuration present - clearing out configuration 2024-08-15 10:52:38.528 (MainThread) WARNING [chip.storage] No valid REPL configuration present - clearing out configuration 2024-08-15 10:52:38.804 (MainThread) INFO [chip.CertificateAuthority] Loading certificate authorities from storage... 2024-08-15 10:52:38.804 (MainThread) INFO [chip.CertificateAuthority] New CertificateAuthority at index 1 2024-08-15 10:52:38.816 (MainThread) INFO [chip.FabricAdmin] New FabricAdmin: FabricId: 0x0000000000000002, VendorId = 0x134B 2024-08-15 10:52:38.817 (MainThread) INFO [matter_server.server.stack] CHIP Controller Stack initialized. 2024-08-15 10:52:38.820 (MainThread) INFO [matter_server.server.server] Starting the Matter Server... 2024-08-15 10:52:38.834 (MainThread) INFO [matter_server.server.helpers.paa_certificates] Fetching the latest PAA root certificates from DCL. 2024-08-15 10:52:42.441 (MainThread) INFO [matter_server.server.helpers.paa_certificates] Fetched 62 PAA root certificates from DCL. 2024-08-15 10:52:42.442 (MainThread) INFO [matter_server.server.helpers.paa_certificates] Fetching the latest PAA root certificates from Git. 2024-08-15 10:52:42.929 (MainThread) INFO [matter_server.server.helpers.paa_certificates] Fetched 2 PAA root certificates from Git. 2024-08-15 10:52:42.932 (MainThread) INFO [chip.FabricAdmin] Allocating new controller with CaIndex: 1, FabricId: 0x0000000000000002, NodeId: 0x000000000001B669, CatTags: [] 2024-08-15 10:52:43.123 (Dummy-2) CHIP_ERROR [chip.native.DL] Long dispatch time: 189 ms, for event type 2 2024-08-15 10:52:43.150 (MainThread) INFO [matter_server.server.vendor_info] Loading vendor info from storage. 2024-08-15 10:52:43.150 (MainThread) INFO [matter_server.server.vendor_info] Loaded 0 vendors from storage. 2024-08-15 10:52:43.151 (MainThread) INFO [matter_server.server.vendor_info] Fetching the latest vendor info from DCL. 2024-08-15 10:52:43.444 (MainThread) INFO [matter_server.server.vendor_info] Fetched 232 vendors from DCL. 2024-08-15 10:52:43.444 (MainThread) INFO [matter_server.server.vendor_info] Saving vendor info to storage. 2024-08-15 10:52:43.453 (MainThread) INFO [matter_server.server.device_controller] Loaded 0 nodes from stored configuration 2024-08-15 10:52:43.471 (MainThread) INFO [matter_server.server.server] Matter Server successfully initialized. 2024-08-15 10:57:28.673 (MainThread) INFO [matter_server.server.device_controller] Starting Matter commissioning with code using Node ID 1. 2024-08-15 10:57:29.700 (Dummy-2) INFO [chip.ChipDeviceCtrl] Established secure session with Device 2024-08-15 10:57:33.890 (Dummy-2) INFO [chip.ChipDeviceCtrl] Commissioning complete 2024-08-15 10:57:33.891 (MainThread) INFO [matter_server.server.device_controller] Commissioned Node ID: 1 vs 1 2024-08-15 10:57:33.891 (MainThread) INFO [matter_server.server.device_controller] Matter commissioning of Node ID 1 successful. 2024-08-15 10:57:33.891 (MainThread) INFO [matter_server.server.device_controller] Interviewing node: 1 2024-08-15 10:58:37.441 (MainThread) INFO [matter_server.server.device_controller] Setting-up node... 2024-08-15 10:58:37.466 (MainThread) INFO [matter_server.server.device_controller] Setting up attributes and events subscription. 2024-08-15 10:59:38.746 (MainThread) WARNING [matter_server.server.device_controller] Unable to subscribe to Node: IM Error 0x00000580: General error: 0x80 (INVALID_ACTION) 2024-08-15 10:59:38.747 (MainThread) INFO [matter_server.server.device_controller] Commissioning of Node ID 1 completed.

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

HaraldGithub commented 4 weeks ago

Is this related or the same problem than this: #123835 ?

josephdouce commented 4 weeks ago

Different error but possible

On Thu, 15 Aug 2024, 11:18 HaraldGithub, @.***> wrote:

Is this related or the same problem than this: #123835 https://github.com/home-assistant/core/issues/123835 ?

— Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/123980#issuecomment-2291024777, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAN74Y2GSA74TGSFTVMCLODZRR54XAVCNFSM6AAAAABMR5XHOGVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDEOJRGAZDINZXG4 . You are receiving this because you authored the thread.Message ID: @.***>

home-assistant[bot] commented 4 weeks 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)

marcelveldt commented 1 week ago

So, if I read your log and report right, you just commissioned one single node to the Matter server and that node shows offline after commisisoning ? It seems to have failed the subscription, first time I have seen that.

ferdydek commented 5 days ago

I would assume its #122736