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.

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

[Connection Issue]: Permission denied (126) #492

Open
3 of 7 tasks
DeckardCain2014 opened this issue Feb 1, 2025 · 11 comments
Open
3 of 7 tasks

[Connection Issue]: Permission denied (126) #492

DeckardCain2014 opened this issue Feb 1, 2025 · 11 comments
Labels
connection-issue Connection issues

Comments

@DeckardCain2014
Copy link

DeckardCain2014 commented Feb 1, 2025

Version

3.0.0-alpha.66

Matter Controller

Alexa

Things you tried

Since last night I get a permission denied exception. Also Alexa is not reaching any of the devices. What I tried now:

  • Factory reset hub
  • repair hub with Alexa
  • restart Alexa
  • restart home network

However, pairing works, but after a few minutes the attached error occurs

Relevant log output

[ 2025-02-01T08:56:55.816Z ] [ DEBUG ] [ Matter / MdnsScanner                               ]: Added 3 IPs for operational device E387C4912DD70714-040419D505529461._matter._tcp.local to cache (interface enp0s18): type: udp ip: fe80::6a37:e9ff:feec:53c8%enp0s18 port: 5541 type: udp ip: 2a00:6020:4a95:1900:6a37:e9ff:feec:53c8 port: 5541 type: udp ip: 192.168.178.35 port: 5541
[ 2025-02-01T08:56:59.103Z ] [ DEBUG ] [ Matter / MdnsScanner                               ]: Added 3 IPs for operational device E387C4912DD70714-040419D3AB93BBE1._matter._tcp.local to cache (interface enp0s18): type: udp ip: fe80::6a13:f3ff:fee3:31ad%enp0s18 port: 5541 type: udp ip: 2a00:6020:4a95:1900:6a13:f3ff:fee3:31ad port: 5541 type: udp ip: 192.168.178.115 port: 5541
[ 2025-02-01T08:57:08.487Z ] [ DEBUG ] [ Matter / MdnsScanner                               ]: Added 3 IPs for operational device E387C4912DD70714-040419D530515491._matter._tcp.local to cache (interface enp0s18): type: udp ip: fe80::a12:a5ff:fe51:6f24%enp0s18 port: 5541 type: udp ip: 2a00:6020:4a95:1900:a12:a5ff:fe51:6f24 port: 5541 type: udp ip: 192.168.178.41 port: 5541
[ 2025-02-01T08:57:08.490Z ] [ DEBUG ] [ Matter / MdnsScanner                               ]: Added 3 IPs for operational device E387C4912DD70714-040419D523F2E591._matter._tcp.local to cache (interface enp0s18): type: udp ip: fe80::a84:9dff:fe94:b03a%enp0s18 port: 5541 type: udp ip: 2a00:6020:4a95:1900:a84:9dff:fe94:b03a port: 5541 type: udp ip: 192.168.178.42 port: 5541
[ 2025-02-01T08:57:08.510Z ] [ DEBUG ] [ Matter / MdnsScanner                               ]: Added 3 IPs for operational device E387C4912DD70714-04041B87B55DED81._matter._tcp.local to cache (interface enp0s18): type: udp ip: fe80::fea1:83ff:fea8:2b4b%enp0s18 port: 5541 type: udp ip: 2a00:6020:4a95:1900:fea1:83ff:fea8:2b4b port: 5541 type: udp ip: 192.168.178.59 port: 5541
[ 2025-02-01T08:57:14.797Z ] [ DEBUG ] [ Matter / MessageExchange                           ]: New exchange channel: udp://192.168.178.115:5541 on session insecure/17364035912358098762 protocol: 0 exId: 57734 sess: insecure/17364035912358098762 peerSess: 0 SAT: 4000 SAI: 300 SII: 500 maxTrans: 5 MRP
[ 2025-02-01T08:57:14.798Z ] [ DEBUG ] [ Matter / MessageExchange                           ]: Message « for: SC/Sigma1 msgId: 0/57734/134621861 type: 0x0/0x30 reqAck size: 212 payload: 153001206c56c77a6ca484bbb01676fb971d7a572d06dd737ad73c84aee0173fa390703b2502a95a300320e91d26faedcb1141b66cd1ef3ccf1ecb98a3e661565b8ec38c3dae00c65cf7be30044104b241ab31b0b0c209bcbf88fef1fbade026a66085d6ea6b030c2d257b1a443d8221386c3d25f892aec3e76c876997c84f617136ed44737ef7987f84939807bed035052501f40125022c012503a00f24041124050b260600000301240701183006105ebb8685865075a448a625246c30eb14300710baf49b8393a506c4ca0ec903cc33364718
[ 2025-02-01T08:57:14.798Z ] [ INFO  ] [ Matter / CaseServer                                ]: Received pairing request from udp://192.168.178.115:5541
[ 2025-02-01T08:57:14.799Z ] [ DEBUG ] [ Matter / SecureSession                             ]: Created secure CASE session for fabric index 1 secure/18556 SII: 500 SAI: 300 SAT: 4000 DMRev: 17 IMRev: 11 spec: 0x1030000 maxPaths: 1 CATs: 1114154
[ 2025-02-01T08:57:14.800Z ] [ DEBUG ] [ Matter / ExchangeManager                           ]: Message » for: SC/Sigma2Resume msgId: 0/57734/106020941 type: 0x0/0x33 acked: 134621861 reqAck size: 74 payload: 1530011025d2782c5fc9e46de498c0126b75ea48300210c88d2e605f910f08ced1aa1f51f2948c25037c4835042501f40125022c012503a00f24041124050c26060000030124070a1818
[ 2025-02-01T08:57:14.807Z ] [ DEBUG ] [ Matter / MessageExchange                           ]: Message « for: SC/StandaloneAck msgId: 0/57734/134621862 type: 0x0/0x10 acked: 106020941
[ 2025-02-01T08:57:14.807Z ] [ INFO  ] [ Matter / CaseServer                                ]: Session 18556 resumed with udp://192.168.178.115:5541 for Fabric 04728781035EDCB0(index 1) and PeerNode 040419D3AB93BBE1 with CATs 1114154
[ 2025-02-01T08:57:14.826Z ] [ DEBUG ] [ Matter / MessageExchange                           ]: Message « for: SC/StatusReport msgId: 0/57734/134621863 type: 0x0/0x40 acked: 106020941 reqAck size: 8 payload: 0000000000000000
[ 2025-02-01T08:57:14.827Z ] [ DEBUG ] [ Matter / ExchangeManager                           ]: Message » for: SC/StandaloneAck msgId: 0/57734/106020942 type: 0x0/0x10 acked: 134621863
[ 2025-02-01T08:57:14.828Z ] [ INFO  ] [ Matter / InsecureSession                           ]: End insecure session insecure/17364035912358098762
[ 2025-02-01T08:57:14.828Z ] [ DEBUG ] [ Matter / MessageExchange                           ]: New exchange channel: udp://192.168.178.115:5541 on session secure/18556 protocol: 1 exId: 57735 sess: secure/18556 peerSess: 18556 SAT: 4000 SAI: 300 SII: 500 maxTrans: 5 MRP
[ 2025-02-01T08:57:14.829Z ] [ DEBUG ] [ Matter / MessageExchange                           ]: Message « for: I/ReadRequest msgId: 18556/57735/23800444 type: 0x1/0x2 reqAck size: 21 payload: 1536001724020024031d2404031818280324ff0b18
[ 2025-02-01T08:57:14.829Z ] [ DEBUG ] [ Matter / InteractionServer                         ]: Received read request from udp://192.168.178.115:5541 on session secure/18556: attributes:RootNode(0x0)/Descriptor(0x1d)/partsList(0x3), events:none isFabricFiltered=false
[ 2025-02-01T08:57:14.829Z ] [ DEBUG ] [ Matter / BehaviorServer                            ]: Read *cf6b244fe6324dfb80f749702bbe91d4.state.partsList* via online#16b2a7c@40419d3ab93bbe1
[ 2025-02-01T08:57:14.831Z ] [ ERROR ] [ Matter / Transaction                               ]: Rolling back online#16b2a7c@40419d3ab93bbe1 due to error: Reading cf6b244fe6324dfb80f749702bbe91d4.descriptor.state: Permission denied (126)
[ 2025-02-01T08:57:14.832Z ] [ ERROR ] [ Matter / InteractionServer                         ]: Error while reading attribute from udp://192.168.178.115:5541 on session secure/18556 to RootNode(0x0)/Descriptor(0x1d)/partsList(0x3): Reading cf6b244fe6324dfb80f749702bbe91d4.descriptor.state: Permission denied (126)
  at Object.authorizeRead (file:///usr/local/lib/node_modules/home-assistant-matter-hub/node_modules/@matter/node/dist/esm/behavior/AccessControl.js:45:11)
  at Descriptor$State.value (file:///usr/local/lib/node_modules/home-assistant-matter-hub/node_modules/@matter/node/dist/esm/behavior/state/managed/values/StructManager.js:76:18)
  at Function.assertDirectReadAuthorized (file:///usr/local/lib/node_modules/home-assistant-matter-hub/node_modules/@matter/node/dist/esm/behavior/state/managed/values/StructManager.js:92:34)
  at AttributeServer.getter (file:///usr/local/lib/node_modules/home-assistant-matter-hub/node_modules/@matter/node/dist/esm/endpoint/server/BehaviorServer.js:110:19)
  at AttributeServer.get (file:///usr/local/lib/node_modules/home-assistant-matter-hub/node_modules/@matter/protocol/dist/esm/cluster/server/AttributeServer.js:175:17)
  at AttributeServer.getWithVersion (file:///usr/local/lib/node_modules/home-assistant-matter-hub/node_modules/@matter/protocol/dist/esm/cluster/server/AttributeServer.js:185:60)
  at TransactionalInteractionServer.readAttribute (file:///usr/local/lib/node_modules/home-assistant-matter-hub/node_modules/@matter/protocol/dist/esm/interaction/InteractionServer.js:380:22)
  at readAttribute (file:///usr/local/lib/node_modules/home-assistant-matter-hub/node_modules/@matter/node/dist/esm/node/server/TransactionalInteractionServer.js:146:39)
  at actOnline (file:///usr/local/lib/node_modules/home-assistant-matter-hub/node_modules/@matter/node/dist/esm/behavior/context/server/OnlineContext.js:99:16)
  at Transaction.act (file:///usr/local/lib/node_modules/home-assistant-matter-hub/node_modules/@matter/node/dist/esm/behavior/state/transaction/Tx.js:71:25)
[ 2025-02-01T08:57:14.832Z ] [ DEBUG ] [ Matter / ExchangeManager                           ]: Message » for: I/ReportData suppressResponse attr: 1 msgId: 18556/57735/197068271 type: 0x1/0x5 acked: 23800444 reqAck size: 33 payload: 153601153500370024020024031d24040318350124007e18181818290424ff0c18
[ 2025-02-01T08:57:14.845Z ] [ DEBUG ] [ Matter / MessageExchange                           ]: Message « for: SC/StandaloneAck msgId: 18556/57735/23800445 type: 0x0/0x10 acked: 197068271
[ 2025-02-01T08:57:26.153Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuche_decke>#868 locked *cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuche_decke.homeAssistantEntity.state*
[ 2025-02-01T08:57:26.154Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuche_decke>#868 committed and unlocked 1 resource
[ 2025-02-01T08:57:26.155Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuche_decke>#868 locked *cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuche_decke.homeAssistantEntity.state and cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuche_decke.onOff.state*
[ 2025-02-01T08:57:26.155Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuche_decke>#868 committed and unlocked 2 resources
[ 2025-02-01T08:57:26.294Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_links>#869 locked *cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_links.homeAssistantEntity.state*
[ 2025-02-01T08:57:26.295Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_links>#869 committed and unlocked 1 resource
[ 2025-02-01T08:57:26.295Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_links>#869 locked *cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_links.homeAssistantEntity.state and cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_links.colorControl.state*
[ 2025-02-01T08:57:26.296Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_links>#869 locked *cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_links.onOff.state*
[ 2025-02-01T08:57:26.297Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_links>#869 committed and unlocked 3 resources
[ 2025-02-01T08:57:26.317Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_rechts>#86a locked *cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_rechts.homeAssistantEntity.state*
[ 2025-02-01T08:57:26.317Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenlichter>#86b locked *cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenlichter.homeAssistantEntity.state*
[ 2025-02-01T08:57:26.318Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_rechts>#86a committed and unlocked 1 resource
[ 2025-02-01T08:57:26.318Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenlichter>#86b committed and unlocked 1 resource
[ 2025-02-01T08:57:26.319Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_rechts>#86a locked *cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_rechts.homeAssistantEntity.state and cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_rechts.colorControl.state*
[ 2025-02-01T08:57:26.319Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenlichter>#86b locked *cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenlichter.homeAssistantEntity.state and cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenlichter.colorControl.state*
[ 2025-02-01T08:57:26.319Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_rechts>#86a locked *cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_rechts.onOff.state*
[ 2025-02-01T08:57:26.320Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenlichter>#86b locked *cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenlichter.onOff.state*
[ 2025-02-01T08:57:26.321Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_rechts>#86a committed and unlocked 3 resources
[ 2025-02-01T08:57:26.321Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenlichter>#86b committed and unlocked 3 resources
[ 2025-02-01T08:57:26.321Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_rechts>#86c locked *cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_rechts.homeAssistantEntity.state*
[ 2025-02-01T08:57:26.322Z ] [ DEBUG ] [ Matter / Transaction                               ]: Transaction setStateOf<cf6b244fe6324dfb80f749702bbe91d4.aggregator.light_kuchenoberschrank_rechts>#86c committed and unlocked 1 resource
[ 2025-02-01T08:57:38.937Z ] [ DEBUG ] [ Matter / DeviceAdvertiser                          ]: Announcement duration reached, stop announcing

What deployment method do you use?

Home Assistant AddOn

Did you already check the following?

  • Does your network include any VLAN setup?
  • Do you have any special firewall rules / services in place?
  • Is IPv6 enabled in your LOCAL network?
  • If you are using the docker deployment: Is IPv6 enabled within your docker daemon config?
  • If you are using the docker deployment: Do you run the container with host network?

Documentation & Issues

  • I have reviewed the documentation and the linked troubleshooting guide.
  • I have searched the issues for a similar problem.
@DeckardCain2014 DeckardCain2014 added the connection-issue Connection issues label Feb 1, 2025
@DeckardCain2014
Copy link
Author

Now, after a couple of retries and factory resets, it works now. 🤞
However, still it would be interesting why I would get an Unauthorized error

@Apollon77
Copy link

In gfact something or somewhat on that fabric destroyed the Access Control Settings. SO a log would be needed that should ideally show when ACl was changed and by whom

@DeckardCain2014
Copy link
Author

Can you give me a hint where to find that? I'm quite aware of the logs, but actually I don't know what you mean by "ACI"

@DeckardCain2014
Copy link
Author

Now it broke again. I need to re-pair it every 24h :(

@Apollon77
Copy link

Then enable debug logging also for matter,js and provide a log

@DeckardCain2014
Copy link
Author

491eb00d_hamh_2025-02-03T10-31-50.754Z.log
This is my latest log. Also it contains the debug log for the just restarted Hub.

As you can see, until now no error exists, however Alexa is not finding any device and also can't control the Hub entity itself after a couple of hours

@Apollon77
Copy link

change port 5541 is not working with alexa, they only support 5540 for initial commissioning

@DeckardCain2014
Copy link
Author

Thanks for pointing it out! You are correct, I saw this in the Readme. However I wouldn't know why it's not using the port displayed in the MatterHub UI?

Image

@t0bst4r
Copy link
Owner

t0bst4r commented Feb 3, 2025

@Apollon77 Are you sure that it is using the wrong port?

For me the logs look like that the bridge is actually using 5540

But it gets a pairing request from an ipv4 address with port 5541.

I've seen that already in Alexa, that it's using the port 5541 of the echo device to connect to port 5540 of the bridge.

@Apollon77
Copy link

I think I saw logs that UDP channel was initialized on 5541. ... can look again tomorrow

@Apollon77
Copy link

Ok, sorry you were right I was reading line wrong. so yes started on 5540 ... so no idea whats up with Alexa ...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
connection-issue Connection issues
Projects
None yet
Development

No branches or pull requests

3 participants