espressif / esp-matter

Espressif's SDK for Matter
Apache License 2.0
686 stars 155 forks source link

Apple Home - Commissions, then No Response - `CASE Session establishment failed: 32` (CON-932) #771

Closed mriksman closed 9 months ago

mriksman commented 10 months ago

Describe the bug Months ago I built a development environment (iOS 16.x and ESP-IDF 4.4 at the time) and loaded the Light example. It worked fine.

I have come back to the project and rebuilt the environment. Running VSCode with ESP-IDF checkout 6b1f40b9bf, used the ESP-IDF extension to install esp-matter and loaded the Light example. It commissioned OK, but shows No Response in the Apple Home App. The terminal shows the following, repeating occasionally.

I (571069) chip[EM]: Retransmitting MessageCounter:249858083 on exchange 6847r Send Cnt 4
I (571249) chip[EM]: Retransmitting MessageCounter:249858084 on exchange 27599r Send Cnt 1
I (571649) chip[EM]: Retransmitting MessageCounter:249858084 on exchange 27599r Send Cnt 2
I (572219) chip[EM]: Retransmitting MessageCounter:249858084 on exchange 27599r Send Cnt 3
E (572469) chip[EM]: Failed to Send CHIP MessageCounter:249858083 on exchange 6847r sendCount: 4 max retries: 4
I (573069) chip[EM]: Retransmitting MessageCounter:249858084 on exchange 27599r Send Cnt 4
E (574539) chip[EM]: Failed to Send CHIP MessageCounter:249858084 on exchange 27599r sendCount: 4 max retries: 4
E (578829) chip[SC]: CASESession timed out while waiting for a response from the peer. Current state was 2
E (578839) chip[IN]: CASE Session establishment failed: 32

Environment

I was able to go to Settings | General | Matter Accessories, click on the 'Matter Accessory' and click 'Remove Accessory'. This appears to have executed correctly

I (1538819) chip[EM]: >>> [E:62976r S:57598 M:248185561] (S) Msg RX from 2:61A31AE3257E956B [4A5F] --- Type 0001:08 (IM:InvokeCommandRequest)
I (1538839) esp_matter_command: Received command 0x0000000A for endpoint 0x0000's cluster 0x0000003E
I (1538839) chip[ZCL]: OpCreds: Received a RemoveFabric Command for FabricIndex 0x2
I (1538849) chip[EM]: <<< [E:62976r S:57598 M:78875993 (Ack:248185561)] (S) Msg TX to 2:61A31AE3257E956B [4A5F] [UDP:[FE80::1C58:CE38:F1ED:8666%st1]:52202] --- Type 0000:10 (SecureChannel:StandaloneAck)
I (1539019) chip[FP]: Fabric (0x2) deleted.
I (1539029) chip[ZCL]: OpCreds: Fabric index 0x2 was removed
I (1539029) chip[DIS]: Updating services using commissioning mode 0
I (1539039) chip[DIS]: CHIP minimal mDNS started advertising.
I (1539049) chip[DIS]: Advertise operational node D8E461579FD4ABCC-00000000F63A645F
I (1539059) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'; instance name: D8E461579FD4ABCC-00000000F63A645F.
I (1539069) chip[DIS]: mDNS service published: _matter._tcp
I (1539299) chip[ZCL]: OpCreds: RemoveFabric successful
I (1539309) chip[SC]: SecureSession[0x3ffc61d0, LSID:57598]: State change 'kActive' --> 'kPendingEviction'
I (1539309) chip[EM]: <<< [E:62976r S:57598 M:78875994 (Ack:248185561)] (S) Msg TX to 2:61A31AE3257E956B [0000] [UDP:[FE80::1C58:CE38:F1ED:8666%st1]:52202] --- Type 0001:09 (IM:InvokeCommandResponse)
I (1539339) app_main: Fabric will be removed
I (1539339) app_main: Fabric removed successfully
I (1539349) chip[EM]: >>> [E:62976r S:57598 M:248185562 (Ack:78875994)] (S) Msg RX from 2:61A31AE3257E956B [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
E (1540889) chip[SC]: CASESession timed out while waiting for a response from the peer. Current state was 2
E (1540899) chip[IN]: CASE Session establishment failed: 32
VaishaliAvhale commented 10 months ago

Please share the complete DUT logs in the file and provide details about the Apple Home (iPad or iOS version and HomePod version). Which DUT are you using, esp32c3, or esp32?

mriksman commented 10 months ago

Attached logs.

ESP32-S AiThinker. iOS 17.2 Multiple HomePods (17.1.1)/Apple TVs (17.1)

Strangest thing - the first log (LogFail.txt) showed the commissioning failing. That was new. Previously it commissioned and then showed 'No Response'. LogFail.txt So I factory reset (shown in the logs) and tried again. This time, it commissioned and appears working in the Apple Home App (Logs.txt). Logs.txt It's concerning that I am getting different results each time I try...

mriksman commented 10 months ago

I went away, came back, unplugged the USB, plugged it back in, and now I am seeing the 'No Response' issue. It eventually came good. Seems to be a few timeout errors. Does it look OK...? Attached log. LogLaterRestart.txt

mriksman commented 10 months ago

At some point during the night, they became unresponsive; showing 'No Response' in Apple Home. See attached logs. LogFailedOvernight.txt I then restarted the device, it it connects to Wi-Fi but I am seeing 'No Response'. LogAfterRestart.txt

shripad621git commented 10 months ago

@mriksman ,I think the discussion over here answers your query.

mriksman commented 10 months ago

Perhaps. I created a new 'Home', moved a HomePod mini over to it, and added the Matter Accessory. So far it has been rock solid/stable.

Perhaps I had/have an issue with my current/old Home? I have noticed other strange things happen besides the above. I might move everything over to the new Home, and monitor it.

If there is nothing obviously wrong in my logs above, then this issue can be closed.