t0bst4r / matterbridge-home-assistant-addon

Apache License 2.0
39 stars 6 forks source link

[Bug]: Can't pair with HomeKit #79

Open siobhanellis opened 3 days ago

siobhanellis commented 3 days ago

What happened?

A bug happened! Tried to pair with HomeKit. Got much closer than before, but pairing fails.

It get's to "Adding to Home" and then fails.

Your configuration

Homekit running on 17.6 (iOS,iPadOS, audioOS and tvOS). Home Assistant running on VM (on a Mac mini M1) Trying to pair from iPhone.

Relevant log output

2024-06-27 19:09:39.472 INFO   PaseServer           Received pairing request from udp://192.168.5.109:55103.
2024-06-27 19:09:39.583 INFO   PaseServer           Session 35440 created with udp://192.168.5.109:55103.
2024-06-27 19:09:39.600 INFO   SessionManager       End insecure session insecure/365234659906123768
2024-06-27 19:09:45.074 INFO   MatterDevice         Announce done fabric: 609805382 fabricIndex: 1
2024-06-27 19:09:45.075 INFO   AttributeServer      Set remote value for fabric scoped attribute "acl" to [{"fabricIndex":1,"privilege":5,"authMode":2,"subjects":["1373515544"],"targets":null}]
2024-06-27 19:09:45.076 INFO   LegacyInte~ionServer ACL updated { fabricIndex: 1, privilege: 5, authMode: 2, subjects: [ 1373515544 ], targets: null }
2024-06-27 19:09:45.077 INFO   Operationa~alsServer addNoc success, adminVendorId 4937, caseAdminSubject 1373515544
[19:09:47.019] [Matterbridge] Setting reachability to true for Matterbridge 
[19:10:07.475] [Matterbridge] WebSocket client disconnected 
2024-06-27 19:10:25.107 INFO   CaseServer           Received pairing request from udp://192.168.5.109:55103
[19:10:25.132] [Matterbridge] Active session changed on fabric 1 id 609805382 vendor 4937 (AppleHome)  for Matterbridge { name: 'secure/35441', nodeId: 3285155451, peerNodeId: 1373515544, fabric: { fabricIndex: 1, fabricId: 609805382, nodeId: 3285155451, rootNodeId: 1373515544, rootVendorId: 4937, label: '' }, isPeerActive: true, secure: true, lastInteractionTimestamp: 1719511825131, lastActiveTimestamp: 1719511825131, numberOfActiveSubscriptions: 0 } 
2024-06-27 19:10:25.132 INFO   CaseServer           session 35441 created with udp://192.168.5.109:55103 for Fabric 00000000C3CF7E7B(index 1) and PeerNode 0000000051DE2F18
2024-06-27 19:10:25.144 INFO   MatterDevice         All announcements expired
2024-06-27 19:10:25.144 INFO   SecureSession        Register Session secure/35440 to send a close when exchange is ended.
2024-06-27 19:10:25.145 INFO   GeneralCom~erHandler Commissioning completed on fabric #609805382 as node #3285155451.
2024-06-27 19:10:25.146 INFO   SessionManager       End insecure session insecure/882906509038602114
[19:10:26.813] [Matterbridge] WebSocketServer client connected 
[19:10:26.823] [Matterbridge] WebSocket received message => Connected to WebSocket: ws://192.168.5.66:8284 
[19:10:30.849] [Matterbridge] WebSocket client disconnected 
[19:10:30.879] [Matterbridge] WebSocketServer client connected 
[19:10:30.889] [Matterbridge] WebSocket received message => Connected to WebSocket: ws://192.168.5.66:8284 
[19:10:32.439] [Matterbridge] WebSocket client disconnected 
[19:10:32.479] [Matterbridge] WebSocketServer client connected 
[19:10:32.495] [Matterbridge] WebSocket received message => Connected to WebSocket: ws://192.168.5.66:8284 
2024-06-27 19:10:33.278 INFO   MatterDevice         Announce done fabric: 1 fabricIndex: 2
2024-06-27 19:10:33.278 INFO   MatterDevice         Announce done fabric: 1 fabricIndex: 2
2024-06-27 19:10:33.279 INFO   AttributeServer      Set remote value for fabric scoped attribute "acl" to [{"fabricIndex":2,"privilege":5,"authMode":2,"subjects":["15984904847917109"],"targets":null}]
2024-06-27 19:10:33.279 INFO   LegacyInte~ionServer ACL updated { fabricIndex: 1, privilege: 5, authMode: 2, subjects: [ 1373515544 ], targets: null } { fabricIndex: 2, privilege: 5, authMode: 2, subjects: [ 15984904847917109 ], targets: null }
2024-06-27 19:10:33.280 INFO   Operationa~alsServer addNoc success, adminVendorId 4996, caseAdminSubject 15984904847917109
2024-06-27 19:11:03.232 INFO   FailsafeContext      Failsafe timer expired, Reset fabric builder.
2024-06-27 19:11:13.404 INFO   CaseServer           Received pairing request from udp://192.168.5.109:55103
2024-06-27 19:11:13.404 ERROR  CaseServer           An error occurred during the commissioning Fabric cannot be found from destinationId
    at FabricManager.findFabricFromDestinationId (file:///usr/local/lib/node_modules/matterbridge/node_modules/@project-chip/matter.js/dist/esm/fabric/FabricManager.js:101:11)
    at MatterDevice.findFabricFromDestinationId (file:///usr/local/lib/node_modules/matterbridge/node_modules/@project-chip/matter.js/dist/esm/MatterDevice.js:293:32)
    at CaseServer.handleSigma1 (file:///usr/local/lib/node_modules/matterbridge/node_modules/@project-chip/matter.js/dist/esm/session/case/CaseServer.js:106:29)
    at async CaseServer.onNewExchange (file:///usr/local/lib/node_modules/matterbridge/node_modules/@project-chip/matter.js/dist/esm/session/case/CaseServer.js:35:7)
    at async SecureChannelProtocol.onNewExchange (file:///usr/local/lib/node_modules/matterbridge/node_modules/@project-chip/matter.js/dist/esm/protocol/securechannel/SecureChannelProtocol.js:107:9)
    at async ExchangeManager.onMessage (file:///usr/local/lib/node_modules/matterbridge/node_modules/@project-chip/matter.js/dist/esm/protocol/ExchangeManager.js:173:9)
2024-06-27 19:11:13.418 INFO   SessionManager       End insecure session insecure/9874749666125061304
2024-06-27 19:11:13.778 INFO   SecureSession        Register Session secure/35441 to send a close when exchange is ended.
2024-06-27 19:11:13.780 INFO   MatterDevice         All announcements expired
2024-06-27 19:11:13.914 INFO   SessionManager       End CASE session secure/35441
2024-06-27 19:11:13.915 INFO   SessionManager       End PASE session secure/35440
2024-06-27 19:11:13.945 ERROR  ExchangeManager      Cannot find a session for ID 35441
    at ExchangeManager.onMessage (file:///usr/local/lib/node_modules/matterbridge/node_modules/@project-chip/matter.js/dist/esm/protocol/ExchangeManager.js:136:13)
    at file:///usr/local/lib/node_modules/matterbridge/node_modules/@project-chip/matter.js/dist/esm/protocol/ExchangeManager.js:73:14
    at file:///usr/local/lib/node_modules/matterbridge/node_modules/@project-chip/matter.js/dist/esm/net/UdpInterface.js:25:52
    at Socket.messageListener (file:///usr/local/lib/node_modules/matterbridge/node_modules/@project-chip/matter-node.js/dist/esm/net/UdpChannelNode.js:101:7)
    at Socket.emit (node:events:517:28)
    at UDP.onMessage [as onmessage] (node:dgram:942:8)
2024-06-27 19:11:13.970 INFO   CommissioningServer  The device was factory reset and restarted.
[19:11:13.970] [Matterbridge] Commissioning removed from fabric 1 for Matterbridge. Resetting the commissioning server ... 
2024-06-27 19:11:14.087 INFO   MatterDevice         All announcements expired
2024-06-27 19:11:14.135 INFO   CommissioningServer  The device was factory reset and restarted.
[19:11:14.153] [Matterbridge] Restart to activate the pairing for Matterbridge 
[19:11:32.459] [Matterbridge] pairingCodes for /api/settings not found 
[19:11:54.152] [Matterbridge] pairingCodes for /api/settings not found 
[19:12:32.564] [Matterbridge] pairingCodes for /api/settings not found

Version

1.3.5

t0bst4r commented 2 days ago

How did you setup your home assistant instance with your VM?

Matter needs some special requirements to work with networks. I am not an export, but it uses some features of the IP-protocol which do not necessarily work with every Virtualization Solution. E.g. for a docker deployment we need to set network_mode to host. With that the container shares its network interface with the host computer and can use every hardware feature as intended.

Maybe that could be the problem with your virtualization? Can you try running it differently, with one of the other deployment options? So... not in a VM?

Additionally it makes sense to have a look at the troubleshooting guide of @project-chip/matter.js.