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

Hard to reconnect back to HomePod when power cycle (CON-825) #679

Open
law-ko opened this issue Oct 12, 2023 · 11 comments
Open

Hard to reconnect back to HomePod when power cycle (CON-825) #679

law-ko opened this issue Oct 12, 2023 · 11 comments

Comments

@law-ko
Copy link

law-ko commented Oct 12, 2023

After commissioning the device and perform a power cycle (power off/power on), sometimes ESP32 cannot automatically connect back to HomePod, with the following error:

I (49741) chip[DIS]: Checking node lookup status after 45000 ms
E (49741) chip[DIS]: OperationalSessionSetup[1:7024177ECA543B43]: operational discovery failed: 32
E (49751) chip[DMG]: Failed to establish CASE for subscription-resumption with error '32'

What is the issue with this?

Environment

  • ESP-Matter Commit Id: release/v1.1 branch
  • ESP-IDF Commit Id: ESP-IDF v5.0.1-dirty
  • SoC (eg: ESP32 or ESP32-C3): ESP32
  • Host Machine OS: Linux
    Any additional details
    We are using Espressif mDNS instead of Matter's own minimal mDNS
Screenshot 2023-10-12 at 1 43 33 PM
@github-actions github-actions bot changed the title Hard to reconnect back to HomePod when power cycle Hard to reconnect back to HomePod when power cycle (CON-825) Oct 12, 2023
@jonsmirl
Copy link
Contributor

The error is earlier in the log. It is saying it can't find the Homepod after 45s. It will print the node id earlier, something like AF67F99EAFC7087E-34C96337C2457B88 then it should be visible on the network.

My MDNS knowledge is minimal, but I believe when it boots it sends out a message asking all of the MDNS devices to identify. It should be able to get the address of the node at that time.

Use an MDNS app on your phone or command line to make sure it is advertising.

jonsmirl@ares:~$ avahi-browse --all | grep matter
+ enp3s0f1 IPv4 _IC7944E937AA07DD5                            _sub._matter._tcp    local
+ enp3s0f1 IPv4 _matter                                       _tcp                 local
+ enp3s0f1 IPv4 _I950545243CFE2D15                            _sub._matter._tcp    local
+ enp3s0f1 IPv6 950545243cfe2d15-000000002e616b1f             _matter._tcp         local
+ enp3s0f1 IPv6 AF67F99EAFC7087E-34C96337C2457B88             _matter._tcp         local
+ enp3s0f1 IPv6 472DC37BCBB11443-AB0DE0000000001B             _matter._tcp         local
+ enp3s0f1 IPv6 9CC0373667C4F408-204B50A898A38F65             _matter._tcp         local
+ enp3s0f1 IPv4 C7944E937AA07DD5-00867AF748BEBA01             _matter._tcp         local
+ enp3s0f1 IPv4 472DC37BCBB11443-AB0DE0000000001C             _matter._tcp         local
+ enp3s0f1 IPv4 AF67F99EAFC7087E-1DADD5FF42FDA442             _matter._tcp         local
+ enp3s0f1 IPv4 C7944E937AA07DD5-008462EE7296AD71             _matter._tcp         local
+ enp3s0f1 IPv4 950545243CFE2D15-00000000CF374D47             _matter._tcp         local
+ enp3s0f1 IPv4 950545243cfe2d15-000000002e616b1f             _matter._tcp         local
+ enp3s0f1 IPv4 AF67F99EAFC7087E-34C96337C2457B88             _matter._tcp         local
+ enp3s0f1 IPv4 472DC37BCBB11443-AB0DE0000000001B             _matter._tcp         local
+ enp3s0f1 IPv4 9CC0373667C4F408-204B50A898A38F65             _matter._tcp         local
+ enp3s0f1 IPv6 _matter                                       _tcp                 local
+ enp3s0f1 IPv6 _IAF67F99EAFC7087E                            _sub._matter._tcp    local
+ enp3s0f1 IPv6 _I472DC37BCBB11443                            _sub._matter._tcp    local
+ enp3s0f1 IPv4 _matterc                                      _udp                 local
+ enp3s0f1 IPv6 _IC7944E937AA07DD5                            _sub._matter._tcp    local
+ enp3s0f1 IPv6 C7944E937AA07DD5-00867AF748BEBA01             _matter._tcp         local
+ enp3s0f1 IPv6 950545243CFE2D15-00000000CF374D47             _matter._tcp         local
+ enp3s0f1 IPv6 472DC37BCBB11443-AB0DE0000000001C             _matter._tcp         local
+ enp3s0f1 IPv6 AF67F99EAFC7087E-1DADD5FF42FDA442             _matter._tcp         local
+ enp3s0f1 IPv6 C7944E937AA07DD5-008462EE7296AD71             _matter._tcp         local
+ enp3s0f1 IPv6 _I950545243CFE2D15                            _sub._matter._tcp    local

@wqx6
Copy link
Contributor

wqx6 commented Oct 13, 2023

Could you please check whether your HomePod has operational advertisement with this command avahi-browse -rt _matter._tcp ? If the HomePod does advertise operational node, could you please capture the mdns query response of the HomePod? In my test, the HomePod will establish CASE session before the device tries to resume the subscription.

@law-ko
Copy link
Author

law-ko commented Oct 16, 2023

How do I know which device is HomePod?

pi@raspberrypi:~ $ avahi-browse --all | grep matter
+   eth0 IPv4 638C92F1B94D5355-0000000002D89C24             _matter._tcp         local
+   eth0 IPv4 0459C5EAC7ADA78D-00000000D23E9BC3             _matter._tcp         local
+   eth0 IPv4 638C92F1B94D5355-000000005C60513F             _matter._tcp         local
+   eth0 IPv4 0459C5EAC7ADA78D-000000006E6CD093             _matter._tcp         local
+   eth0 IPv4 0459C5EAC7ADA78D-000000008EB20A52             _matter._tcp         local
+   eth0 IPv4 638C92F1B94D5355-0000000011277D93             _matter._tcp         local
+   eth0 IPv4 5CD79DBEC2EA81E8-02020BEAF6978151             _matter._tcp         local
+   eth0 IPv6 5CD79DBEC2EA81E8-02020BEAF6978151             _matter._tcp         local
+   eth0 IPv4 0459C5EAC7ADA78D-00000000BDEB4D57             _matter._tcp         local
+   eth0 IPv4 638C92F1B94D5355-0000000074C39B2B             _matter._tcp         local
+   eth0 IPv6 0459C5EAC7ADA78D-00000000D23E9BC3             _matter._tcp         local
+   eth0 IPv6 638C92F1B94D5355-0000000002D89C24             _matter._tcp         local
+   eth0 IPv6 0459C5EAC7ADA78D-000000006E6CD093             _matter._tcp         local
+   eth0 IPv6 638C92F1B94D5355-000000005C60513F             _matter._tcp         local
+   eth0 IPv4 0459C5EAC7ADA78D-00000000D570B3B8             _matter._tcp         local
+   eth0 IPv4 638C92F1B94D5355-00000000955CE965             _matter._tcp         local
+   eth0 IPv4 0459C5EAC7ADA78D-00000000FC814AC9             _matter._tcp         local
+   eth0 IPv4 48980451AC2007BE-0000000059979E62             _matter._tcp         local
+   eth0 IPv4 638C92F1B94D5355-000000009000A37C             _matter._tcp         local
+   eth0 IPv4 638C92F1B94D5355-7024177ECA543B43             _matter._tcp         local
+   eth0 IPv4 0459C5EAC7ADA78D-00000000C8E99552             _matter._tcp         local
+   eth0 IPv4 638C92F1B94D5355-000000001381B26D             _matter._tcp         local

@jonsmirl
Copy link
Contributor

jonsmirl commented Oct 16, 2023

avahi-browse -a -r

Will give you more info. Find the homepod IP address.

avahi-browse _matter._tcp --resolve

This is mine:

= enp3s0f1 IPv6 9CC0373667C4F408-204B50A898A38F65             _matter._tcp         local
   hostname = [52F2EEC6A9E7.local]
   address = [192.168.1.81]
   port = [49322]
   txt = ["T=1"]

@law-ko
Copy link
Author

law-ko commented Oct 19, 2023

Further checking the mDNS service, HomePod is active in _matter._tcp:
image

ESP32 device can also be found:
image
image

If HomePod and ESP32 can both be found in mDNS, is there any other reason why it would not automatically connect back to HomePod?

@dhrishi
Copy link
Collaborator

dhrishi commented Jul 26, 2024

@law-ko Are you still encountering this problem?

@h2zero
Copy link

h2zero commented Oct 17, 2024

I am having the same issue, the CASE session is lost on restart and I need to send 2-3 commands to the device before the HomePod will negotiate a new CASE session, then the esp32 can communicate again.

esp-matter/releasev1.3, IDF v5.2.3

@maenkai
Copy link

maenkai commented Dec 4, 2024

I had the same problem, and even when on standby, homepod would disconnect from time to time

esp-matter: (HEAD -> release/v1.2, origin/release/v1.2)
esp-idf: v5.1.1

@maenkai
Copy link

maenkai commented Dec 4, 2024

[src/lib/address_resolve/AddressResolve_DefaultImpl.cpp][52]I (34237) chip[DIS]: UDP:192.168.5.42%st1:64506: new best score: 2
[src/lib/address_resolve/AddressResolve_DefaultImpl.cpp][52]I (34238) chip[DIS]: UDP:[FE80::1403:D587:15B6:4C96%st1]:64506: new best score: 7
[src/lib/address_resolve/AddressResolve_DefaultImpl.cpp][100]I (34251) chip[DIS]: Checking node lookup status after 81 ms
[src/lib/address_resolve/AddressResolve_DefaultImpl.cpp][105]I (34263) chip[DIS]: Keeping DNSSD lookup active
[src/lib/address_resolve/AddressResolve_DefaultImpl.cpp][100]I (34370) chip[DIS]: Checking node lookup status after 200 ms
[src/protocols/secure_channel/CASESession.cpp][530]I (34371) chip[SC]: Initiating session on local FabricIndex 1 from 0x00000000D197BBC7 -> 0x0000000021635991
[src/transport/SessionManager.cpp][346]I (34439) chip[EM]: <<< [E:30452i S:0 M:201183193] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[FE80::1403:D587:15B6:4C96%st1]:64506] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
[src/app/OperationalSessionSetup.cpp][226]E (34449) chip[-]: Error LwIP:0x03000004 at src/app/OperationalSessionSetup.cpp:226
[src/app/SubscriptionResumptionSessionEstablisher.cpp][122]E (34460) chip[DMG]: Failed to establish CASE for subscription-resumption with error '3000004'

@JonathanWitthoeft
Copy link
Contributor

JonathanWitthoeft commented Dec 20, 2024

Failed to establish CASE for subscription-resumption with error '32'
Any update on this? I am also seeing issues with re-establishing a subscription.
At one point I could send commands to the accessory, but the notifications were not received by the homepod.
After about 6-7 minutes the re-subscription automatically retried and it corrected itself
Found an existing secure session to [1:00000000110B31A8]!

@jonsmirl
Copy link
Contributor

That is normal Matter behavior. I don't like how it works either. The node you are trying to access is receiving those messages but the session number has been changed. If you look at the console of the receiving device it will be printing messages about ignoring packet from an old session. So the first node just continues sending them until it times out, then it establishes a new session. This would be much more efficient if the receiving node sent a NACK type response triggering an immediate new session instead of discarding the packets and causing a timeout. But that is not part of the Matter protocol.

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

No branches or pull requests

7 participants