Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Matter nodes offline #123980

Closed
josephdouce opened this issue Aug 15, 2024 · 6 comments
Closed

Matter nodes offline #123980

josephdouce opened this issue Aug 15, 2024 · 6 comments
Labels
integration: matter

Comments

@josephdouce
Copy link

josephdouce commented Aug 15, 2024 •
edited
Loading

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] Node:1 Setting-up node...
2024-08-15 10:58:37.466 (MainThread) INFO [matter_server.server.device_controller] Node:1 Setting up attributes and events subscription.
2024-08-15 10:59:38.746 (MainThread) WARNING [matter_server.server.device_controller] Node:1 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
Copy link

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

@josephdouce
Copy link
Author

josephdouce commented Aug 15, 2024 via email

@home-assistant
Copy link

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
Copy link
Member

marcelveldt commented Sep 2, 2024 •
edited
Loading

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.

  • What device is this ?
  • Did a Matter Server restart fix the issue ?

@ferdydek ferdydek mentioned this issue Sep 6, 2024
Closed
@ferdydek
Copy link

ferdydek commented Sep 6, 2024

I would assume its #122736

@marcelveldt
Copy link
Member

Closed due to no follow up

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
integration: matter
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@josephdouce @ferdydek @marcelveldt @joostlek @HaraldGithub