project-chip / connectedhomeip

Matter (formerly Project CHIP) creates more connections between more objects, simplifying development for manufacturers and increasing compatibility for consumers, guided by the Connectivity Standards Alliance.
https://buildwithmatter.com
Apache License 2.0
7.23k stars 1.92k forks source link

[BUG] The issue with multi-admin in the Bridge-App example. #32651

Open djanss0205 opened 4 months ago

djanss0205 commented 4 months ago

Reproduction steps

Steps to reproduce the problem: Connect the Bridge-App example from connectedhomeip to Apple HomePod and Google NestHub. When removing MatterBridge from the Google NestHub controller, both Apple HomePod and MatterBridge lose connection, and it is not possible to establish any communication between them.

Platform: LInux (Ubuntu 20.04) Commit: 181b0cb14ff007ec912f2ba6627e05dfb066c008 Google NestHub version: gen 2 Apple HomPod version: Apple HomePod mini

Bug prevalence

Whenever I do this

GitHub hash of the SDK that was being used

181b0cb14ff007ec912f2ba6627e05dfb066c008

Platform

other

Platform Version(s)

Linux: Ubuntu 20.04

Anything else?

The logs we receive from the Bridge-App example when disconnecting the Google NestHub:

CHIP:FP: Fabric (0x1) deleted. CHIP:IM: Deleting expired ReadHandler for NodeId: 000000007AB214B8, FabricIndex: 1 CHIP:DL: writing settings to file (/tmp/chip_kvs-VjDQz0) CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) CHIP:DL: writing settings to file (/tmp/chip_kvs-N9ppZZ) CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) CHIP:DMG: OnReportConfirm: NumReports = 0 CHIP:DMG: IM RH moving to [AwaitingDestruction] CHIP:ZCL: UserLabel: Last Fabric index 0x1 was removed CHIP:ZCL: OpCreds: Fabric index 0x1 was removed CHIP:DIS: Updating services using commissioning mode 0 CHIP:DIS: CHIP minimal mDNS started advertising. CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to e3ee78ae CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to e3ee78af CHIP:DL: writing settings to file (/tmp/chip_kvs-1G078V) CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) CHIP:DL: writing settings to file (/tmp/chip_kvs-tcHQ1Z) CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) CHIP:DL: writing settings to file (/tmp/chip_kvs-AvFTTZ) CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) CHIP:DL: writing settings to file (/tmp/chip_kvs-vY1VOX) CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) CHIP:DL: writing settings to file (/tmp/chip_kvs-PNjFxZ) CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) CHIP:DL: writing settings to file (/tmp/chip_kvs-WbQbgY) CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) CHIP:DL: writing settings to file (/tmp/chip_kvs-CIgSn0) CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) CHIP:DL: writing settings to file (/tmp/chip_kvs-kdzSRW) CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) CHIP:DL: writing settings to file (/tmp/chip_kvs-f6GJm0) CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) CHIP:DL: writing settings to file (/tmp/chip_kvs-C3L7iX) CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) CHIP:ZCL: OpCreds: RemoveFabric successful CHIP:DMG: Command handler moving to [ Preparing] CHIP:DMG: Command handler moving to [AddingComm] CHIP:DMG: Command handler moving to [AddedComma] CHIP:IN: Expiring all sessions for fabric 0x1!! CHIP:IN: SecureSession[0x55c9cc2dfee0]: MarkForEviction Type:2 LSID:4304 CHIP:SC: SecureSession[0x55c9cc2dfee0, LSID:4304]: State change 'kActive' --> 'kPendingEviction' CHIP:IN: SecureSession[0x55c9cc2f8de0]: MarkForEviction Type:2 LSID:4306 CHIP:SC: SecureSession[0x55c9cc2f8de0, LSID:4306]: State change 'kActive' --> 'kPendingEviction' CHIP:IN: SecureSession[0x55c9cc2f8de0]: Released - Type:2 LSID:4306 CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 CHIP:EM: <<< [E:44369r S:4304 M:113185567 (Ack:114657226)] (S) Msg TX to 1:00000000E22B49ED [0000] [UDP:[fe80::e817:21ff:fe13:adc7%eno1]:50545] --- Type 0001:09 (IM:InvokeCommandResponse) CHIP:DMG: Command handler moving to [CommandSen] CHIP:DMG: Command handler moving to [AwaitingDe] CHIP:EM: >>> [E:44369r S:4304 M:114657227 (Ack:113185567)] (S) Msg RX from 1:00000000E22B49ED [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) CHIP:EM: Found matching exchange: 44369r, Delegate: (nil) CHIP:EM: Rxd Ack; Removing MessageCounter:113185567 from Retrans Table on exchange 44369r CHIP:IN: SecureSession[0x55c9cc2dfee0]: Released - Type:2 LSID:4304 CHIP:IN: Data received on an unknown session (LSID=4306). Dropping it! CHIP:IN: Data received on an unknown session (LSID=4313). Dropping it! CHIP:IN: Data received on an unknown session (LSID=4306). Dropping it! CHIP:IN: Data received on an unknown session (LSID=4313). Dropping it! CHIP:IN: Data received on an unknown session (LSID=4313). Dropping it! CHIP:IN: Data received on an unknown session (LSID=4306). Dropping it! CHIP:IN: Data received on an unknown session (LSID=4313). Dropping it! CHIP:IN: Data received on an unknown session (LSID=4313). Dropping it! CHIP:IN: Data received on an unknown session (LSID=4313). Dropping it! CHIP:IN: Data received on an unknown session (LSID=4306). Dropping it! CHIP:IN: Data received on an unknown session (LSID=4306). Dropping it! CHIP:IN: Data received on an unknown session (LSID=4313). Dropping it! CHIP:IN: Data received on an unknown session (LSID=4313). Dropping it!

After these logs, all communication between the Bridge-App instance and the Apple HomePod Matter Controller is lost.

greenstatic commented 4 months ago

I have seen this behavior as well. But I believe this is a Google issue since if you delete the device from Google Home it will remove all fabrics (iirc). I'll try to confirm that this happens tomorrow when I'll have access to test equipment.

bzbarsky-apple commented 4 months ago

@djanss0205 Can you please attach, not paste, the full log from the bridge-app, not just a snippet that might not include all the things that are going on?

djanss0205 commented 4 months ago

bridge_app_logs.txt

After disconnecting the bridge-app example from Google NestHub, the bridge-app connected to Apple HomePod becomes No Response in the application, and all communication is lost.

bzbarsky-apple commented 4 months ago

Yeah, so that log shows:

CHIP:ZCL: OpCreds: Received a RemoveFabric Command for FabricIndex 0x2
...
CHIP:ZCL: OpCreds: Received a RemoveFabric Command for FabricIndex 0x3
...
CHIP:ZCL: OpCreds: Received a RemoveFabric Command for FabricIndex 0x4
...
CHIP:ZCL: OpCreds: Received a RemoveFabric Command for FabricIndex 0x1

which does in fact look like it's being removed from all fabrics....

tcarmelveilleux commented 3 months ago

How is the bridge "disconnected" from Google hub? Please provide exact steps, and if possible attach a screen capture.

djanss0205 commented 3 months ago

The Bridge-App example is added by default; in the Google Home application, click on the "add device" button, select "matter device," and start the addition with the pairing code "34970112332." When the Bridge-App example is being removed from the Google Home application, click on the Bridge-App device in the Google Home application, then the "settings" button, and after that, the "remove" button, which initiates the process of removing our Bridge-App example from the Google Home application (Google NestHub controller).

djanss0205 commented 3 months ago

If my understanding is correct, this issue is related to the implementation of the Google NestHub controller, as they initiate the removal of all fabrics from the Bridge-App example?