esp-homekit icon indicating copy to clipboard operation
esp-homekit copied to clipboard

Need for Half-Paired concept

Open HomeACcessoryKid opened this issue 6 years ago • 59 comments

Today I witnessed that you have a 'trap' in your state machine. If for some reason (I have traced one) the verify step of the pairing process is not executed, then the device is considered paired and refuses to pair again.

Please see my repo for the use of the half-paired concept of how to solve it. Summary: only consider pairing official once the GET /accessories URL has been received (and maybe even deeper in the flow, like the identify that seems to be triggered always nowadays.)

>>> HomeKit: Configuring mDNS
>>> HomeKit: [Client 4] Successfully paired
>>> homekit_client_process: [Client 4] Finished processing
>>> HomeKit: [Client 4] Closing client connection

no verify step follows, and after 22 seconds, iPhone starts again with step1/3

>>> HomeKit: Got new client connection: 4
>>> homekit_client_process: [Client 4] Got 125 incomming data
>>> homekit_server_on_pair_setup: Pair Setup
>>> homekit_server_on_pair_setup: Free heap: 35896
>>> tlv_debug: Got following TLV values:
>>> tlv_debug: Type 6 value (1 bytes): \x01
>>> tlv_debug: Type 0 value (1 bytes): \x00
>>> HomeKit: [Client 4] Pair Setup Step 1/3
>>> homekit_server_on_pair_setup: Free heap: 35800
>>> HomeKit: [Client 4] Refusing to pair: already paired
>>> send_tlv_response: [Client 4] Sending TLV response
>>> tlv_debug: Got following TLV values:
>>> tlv_debug: Type 7 value (1 bytes): \x06
>>> tlv_debug: Type 6 value (1 bytes): \x02
>>> client_send: [Client 4] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/pairing+tlv8\x0D\x0AContent-Length: 6\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A\x07\x01\x06\x06\x01\x02
>>> homekit_client_process: [Client 4] Finished processing
>>> HomeKit: [Client 4] Closing client connection

HomeACcessoryKid avatar Jan 07 '18 14:01 HomeACcessoryKid

Why would client drop verifying and retry?

maximkulkin avatar Jan 07 '18 19:01 maximkulkin

Thing is that in real life, it does. Our mission is to handle real life situations. This does not imply that if you have a way to avoid this situation by fixing the initial condition, that is fine. But for now, it does not hurt to be robust and take care that unless the phone got to the screen where the accessory is really recognised, it is not considered paired.

HomeACcessoryKid avatar Jan 07 '18 20:01 HomeACcessoryKid

As it turns out, with an iPhone X this happens more often. If you're not looking at the screen the device will eventually lock, causing the pairing process to stop on the controller side, which causes the half-paired state.

I've had it twice now with an iPhone X, once in low power mode (so a really short device on duration) and once without.

renssies avatar Jan 16 '18 10:01 renssies

Hey, can you try same with official accessories? On Tue, Jan 16, 2018 at 02:55 Rens Verhoeven [email protected] wrote:

As it turns out, with an iPhone X this happens more often. If you're not looking at the screen the device will eventually lock, causing the pairing process to stop on the controller side, which causes the half-paired state.

I've had it twice now with an iPhone X, once in low power mode (so a really short device on duration) and once without.

— You are receiving this because you commented.

Reply to this email directly, view it on GitHub https://github.com/maximkulkin/esp-homekit/issues/14#issuecomment-357924553, or mute the thread https://github.com/notifications/unsubscribe-auth/AAAqIQOmPLusdVb6Gcd4DgMG9x6nP1_mks5tLIANgaJpZM4RVqqs .

maximkulkin avatar Jan 16 '18 15:01 maximkulkin

I just tried it with new out of the box Koogeek plug (P1EU) and I was able to reproduce it. Once it fails to pair, due to the iPhone falling to sleep (locking). The Koogeek starts flashing red for about 5-10 seconds, after that it's available for pairing again and pairs just fine.

Not sure how they solved the issue, I guess they just reset somehow?

renssies avatar Jan 18 '18 23:01 renssies

See above how I did it in my repo. However that could be improved on by not writing to flash until the confirmation is in.

HomeACcessoryKid avatar Jan 19 '18 11:01 HomeACcessoryKid

I understand that this is a problem, although I do not see an elegant solution to it. As a workaround: can you just make sure your device does not go to sleep when you pair? It's a ONE TIME operation initiated by user and it takes just under a minute.

The other thing is it would be nice to improve "reset" story.

maximkulkin avatar Jan 19 '18 18:01 maximkulkin

I have the following parts that might contribute to an elegant solution.

Whenever a pair-setup finishes successfully, you could keep the relevant information in a RAM variable struct as a cache and set a half-paired flag. On pair-verify you would always start to see if the info matches the cache first.

In the identify accessory routine (it seems to be guaranteed during pairing process) you could check the half-paired flag and then write the cache to flash. If the phone 'ordered' the identify, it seems sure that pairing was successful.

HomeACcessoryKid avatar Jan 22 '18 17:01 HomeACcessoryKid

I believe, accessory is not added to iOS until you review it on screen and press "Add" button. Which obviously happen after it has downloaded info and did identify routine. Thus, even if user manage to prevent device from sleeping while it was pairing but then did not approve addition and device went sleeping, it still won't add accessory (despite accessory having pairing info already).

maximkulkin avatar Jan 22 '18 19:01 maximkulkin

@maximkulkin A accessory is added to the Default room if you skip the "Add" screen. As soon as it's paired it's in the HomeKit database and soon synced over iCloud, just confirmed this with Koogeek plug.

renssies avatar Jan 22 '18 19:01 renssies

Had the problem naturally with iPhoneX. I think a simple timeout for the whole process to happen should be enough.And/or: If pairing is left in the middle. Should be ignored if same client restarts the process. As if never happened. Would that be possible? I’m still studying this whole thing (Apple docs and this code )

affonsoloyola avatar Feb 19 '18 10:02 affonsoloyola

I think I'm having the same issue. I failed to pair, and now I get this log anytime I try to pair:

ip:192.168.1.47,mask:255.255.255.0,gw:192.168.1.1
>>> HomeKit: Got new client connection: 4
>>> HomeKit: [Client 4] Pair Setup Step 1/3
>>> HomeKit: [Client 4] Pair Setup Step 2/3
>>> HomeKit: [Client 4] Pair Setup Step 3/3
>>> HomeKit: Added pairing with 94F4C638-BA4A-41AB-B2E6-15ACAA9D056A
>>> HomeKit: Configuring mDNS
mDNS announcement: Name=AC Controllermd=AC-IRpv=1.0id=90:26:9C:DB:9A:BCc#=1s#=1ff=0sf=0ci=21 Port=5556 TTL=4500
>>> HomeKit: [Client 4] Successfully paired
>>> HomeKit: [Client 4] Closing client connection
>>> HomeKit: Got new client connection: 4
>>> HomeKit: [Client 4] Pair Setup Step 1/3
>>> HomeKit: [Client 4] Refusing to pair: already paired
>>> HomeKit: [Client 4] Closing client connection

Any idea on how to reset it so I can start the pairing process from scratch?

pbendersky avatar Aug 26 '18 00:08 pbendersky

You need to have some way to reset accessory. E.g. sonoff_basic accessory supports reseting accessory configuration if you do long press on it's button. Or you can just erase_flash and re-flash again (or even reset sectors that hold esp-homekit configuration without need to reflash everything, like esptool.py -p $ESPPORT -b 115200 erase_region 0x100000 4096)

maximkulkin avatar Aug 26 '18 04:08 maximkulkin

I did an erase_flash (it's a Wemos D1 Mini, not a Sonoff). The log I attached is right after the erase_flash. I'm using iOS 12 if that helps...

pbendersky avatar Aug 26 '18 13:08 pbendersky

I still consider that a fix on the accessory side is possible and desired. It is clear this happens ever so often in real life and is very annoying.

@maximkulkin Do you want us to help designing the solution in more detail?

HomeACcessoryKid avatar Aug 26 '18 13:08 HomeACcessoryKid

@HomeACcessoryKid Sure, let's talk about that.

maximkulkin avatar Feb 02 '19 16:02 maximkulkin

With the progress of time, I have observed that nowadays there is always an 'identify' command sent from the phone to the accessory once pairing completes. If we use this as a criterium to switch from 'pairing' to 'paired' then I think this issue would be solved.

HomeACcessoryKid avatar Feb 14 '19 20:02 HomeACcessoryKid

Ok, makes sense. Do we have a repro steps or just implement that blindly? I sure can use some client library to emulate the whole process, but if there is a natural way to reproduce this problem, that would help. Maybe like "device locks screen while pairing"?

maximkulkin avatar Feb 14 '19 21:02 maximkulkin

I didn't try to find a way to force it locking up, but your suggestion to lock the screen seems like a good candidate.
Maybe we (I) should first practice to make it fail to learn the way to break it down.
If it is not easy to force it with my older model (I still have an iPhone SE ;-) we need help from others...

HomeACcessoryKid avatar Feb 14 '19 21:02 HomeACcessoryKid

Pairing is still a weak place for this library. One of two times pairing step 1,2 connection dropps and process restarted (try 2), but faced "Another pairing in progress" error, then pairing again (try 3), on this step mDNS error allocating 1460 bytes appear. And need to reset the device. I believe the slow CPU and long responce time make the controller (iphone) to break pairing process but not 100% sure

d4rkmen avatar Jan 08 '20 09:01 d4rkmen

Oh thank you for summing that up.

mDNS allocations is not a bug, it’s a limitation put on the size of requests it can process. Most likely we do not need to process those requests anyways.

A lot of times people writing their own firmwares liberally allocate memory like they have infinite amounts of it and then complain about failed pairings. This is embedded environment boys.

Those “Another pairing is in progress” reports is kind of new and I have heard about it only from one person so far (you’re the second one) and it sounds like something is weird in your environment (why would same device start multiple pairing attempts at the same time?!). Most people I know about (including me) have ZERO problems with pairing. Try applying patch from outstanding PR by @maccoylton, he sent it because he was having similar issues, and let me know if that works for you.

maximkulkin avatar Jan 08 '20 11:01 maximkulkin

I also have faced the above message “Another pairing is in progress“

why would same device start multiple pairing attempts at the same time

It could happen when pairing for whatsoever reason takes too long to complete , and the user can’t wait for the first attempt, decides to cancel the process and tries again from the beginning. Then, in the second attempt that message may show up.

To add in the conversation, I can recall that during one of my tests I achieved to block a device from HomeKit. No matter what, HomeKit reported that my device was already paired although the device were not (message : Refusing to pair: already paired)

I finally was able to pair the device successfully by >

A) changing its mDNS name AND B) change its HomeKit pairing code.

peros550 avatar Jan 08 '20 20:01 peros550

It could happen when pairing for whatsoever reason takes too long to complete , and the user can’t wait for the first attempt, decides to cancel the process and tries again from the beginning. Then, in the second attempt that message may show up.

Well, then it is correct and expected behavior. You cancel process, you'll still have to wait. No cheating there. I believe @maccoylton had a different problem when controller tried to connect, gave up and reconnected without any user intervention.

maximkulkin avatar Jan 08 '20 20:01 maximkulkin

Thats correct Max, my issue was a second connection from the IOS device attempting to pair without any user intervention.

maccoylton avatar Jan 08 '20 21:01 maccoylton

To add in the conversation, I can recall that during one of my tests I achieved to block a device from HomeKit. No matter what, HomeKit reported that my device was already paired although the device were not (message : Refusing to pair: already paired)

Yes, that was the original problem: if you pair and due to long duration of the process controller (iPhone) goes to sleep and unloads Home.app when acccessory was in final stage (step 3) of pairing, then accessory thinks that it all was completed, but iPhone loses state due to unload and does not have that pairing.

maximkulkin avatar Jan 08 '20 21:01 maximkulkin

Oops, wrong button, sorry.

maximkulkin avatar Jan 08 '20 21:01 maximkulkin

To add in the conversation, I can recall that during one of my tests I achieved to block a device from HomeKit. No matter what, HomeKit reported that my device was already paired although the device were not (message : Refusing to pair: already paired)

Yes, that was the original problem: if you pair and due to long duration of the process controller (iPhone) goes to sleep and unloads Home.app when acccessory was in final stage (step 3) of pairing, then accessory thinks that it all was completed, but iPhone loses state due to unload and does not have that pairing.

question is why is it taking so long to pair? I can recall pairing with Sonoff basic examples, 1 year ago, was more like instantaneous. It's quite long when I tried a Sonoff again, but nowadays pairing in my cases takes like 20-30sec.

peros550 avatar Jan 08 '20 21:01 peros550

It was always ~30 seconds on ESP8266. On ESP32 it is about ~3-5 seconds.

maximkulkin avatar Jan 08 '20 21:01 maximkulkin

It was always ~30 seconds on ESP8266

did u ever tested mbedtls for this? interesting to compare

d4rkmen avatar Jan 08 '20 21:01 d4rkmen

I do not believe in fairies and besides the whole process is hard to setup and get right to do experiments for fun.

Oh yeah, also, mbedtls is just TLS implementation, it has no elliptic curves, SRP or hashes.

maximkulkin avatar Jan 08 '20 21:01 maximkulkin