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.22k stars 1.91k forks source link

How to solve the problem of slow Commissioning process? #33966

Open chuckrui opened 3 weeks ago

chuckrui commented 3 weeks ago

In the process of production, we found that when we carried out application testing (add the device to Apple home app-> Test onoff and level control -> Remove the device), we found that it took about 5 minutes to successfully add the device to Apple home app each time. What's the reason, I wonder? Or is there anything that can optimize the speed of the distribution network? It is worth mentioning that our speed will not be so slow at the beginning, but when more and more devices are added, you can obviously feel the speed is getting slower and slower. I was wondering what else could be done to make things faster in terms of production testing? Because so far we've only tested on Apple home, we haven't tried any other ecosystem

we use Nordic52840 and the matter certification version is 1.0. The following is my network log, can you help me see where the response is slow? Commissioning log.txt

bzbarsky-apple commented 3 weeks ago

So looking at that log, the device starts advertising over BLE here:

00> I: 30270 [DL]Chuck:CHIPoBLE advertising started

The BLE connection is established 17 seconds later (assuming those are millisecond timestamps):

00> I: 47306 [DL]BLE connection established (ConnId: 0x00)

Then commissioning starts here:

00> I: 49201 [EM]>>> [E:36424r M:249843416] (U) Msg RX from 0:10EABFD526874AF4 [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)

and completes pretty quickly:

00> I: 60088 [FS]GeneralCommissioning: Received CommissioningComplete

Then there is a second commissioning (one for keychain, one for Home), which completes here:

00> I: 66459 [FS]GeneralCommissioning: Received CommissioningComplete

Then the device hears nothing from the other side for a while until:

00> I: 162148 [EM]>>> [E:36467r M:120959253] (S) Msg RX from 1:00000000457B8B14 [E86A] --- Type 0001:02 (IM:ReadRequest)

Then the other side tries to subscribe to the device:

00> I: 165060 [EM]>>> [E:77r M:77935753] (S) Msg RX from 1:00000000457B8B14 [E86A] --- Type 0001:03 (IM:SubscribeRequest)

and the priming data gets sent, about one packet per 100ms:

00> I: 165620 [EM]<<< [E:77r M:23793268 (Ack:77935764)] (S) Msg TX to 1:00000000457B8B14 [E86A] --- Type 0001:05 (IM:ReportData)
00> I: 165731 [EM]>>> [E:77r M:77935765 (Ack:23793268)] (S) Msg RX from 1:00000000457B8B14 [E86A] --- Type 0001:01 (IM:StatusResponse)
00> I: 165742 [EM]<<< [E:77r M:23793269 (Ack:77935765)] (S) Msg TX to 1:00000000457B8B14 [E86A] --- Type 0001:05 (IM:ReportData)
00> I: 165860 [EM]>>> [E:77r M:77935766 (Ack:23793269)] (S) Msg RX from 1:00000000457B8B14 [E86A] --- Type 0001:01 (IM:StatusResponse)
...etc

This continues until:

00> I: 167645 [EM]<<< [E:77r M:23793286 (Ack:77935782)] (S) Msg TX to 1:00000000457B8B14 [E86A] --- Type 0001:04 (IM:SubscribeResponse)

By this point:

00> I: 191064 [EM]>>> [E:87r M:77935795] (S) Msg RX from 1:00000000457B8B14 [E86A] --- Type 0001:08 (IM:InvokeCommandRequest)

the other side is sending lighting "on" commands to the device.

So it's taking 30s to start advertising over BLE, another 17s to establish the BLE connection, then 20s to do the commissioning, then for close to 100s the client goes off and does ... something. Then subscription takes about 2s, and I would expect the device to be considered "added" at or before that point, at about the 3 minute mark.

bzbarsky-apple commented 3 weeks ago

In terms of why there's that 100s gap: I recommend filing a feedback assistant ticket per the directions below, which would include logs from the Apple device in question that would perhaps allow that to be pinned down. Please mention the ticket ID in this issue, and I will see about getting someone to look at it.

Feedback assistant ticket: