maximkulkin / esp-homekit

Apple HomeKit accessory server library for ESP-OPEN-RTOS
MIT License
1.12k stars 170 forks source link

Pairing fails with iOS 15 public beta #193

Open AramVartanyan opened 3 years ago

AramVartanyan commented 3 years ago

Dear Maxim,

I have faced an issue with pairing to Apple Home under iOS 15. It turns out that they have changed something in the pairing process with the new version.

I have noticed that right after attempt to send the payload the following error appears:

!!! HomeKit: [Client 1] Failed to write response (errno 104)

It could be a bug related to the unfinished beta, but it could be just another HAP version update.

The full log is bellow.

Regards

...
connected with Wi-Fi Network, channel 1
dhcp client start...
ip:10.0.1.166,mask:255.255.255.0,gw:10.0.1.1
>>> wifi_config: Connected to WiFi network
Connected
>>> HomeKit: Starting server
>>> HomeKit: Using existing accessory ID: 7D:54:51:7D:B3:A2
>>> HomeKit: Configuring mDNS
HomeKit: adding mDNS TXT record md=Window
HomeKit: adding mDNS TXT record pv=1.0
HomeKit: adding mDNS TXT record id=7D:54:51:7D:B3:A2
HomeKit: adding mDNS TXT record c#=1
HomeKit: adding mDNS TXT record s#=1
HomeKit: adding mDNS TXT record ff=0
HomeKit: adding mDNS TXT record sf=1
HomeKit: adding mDNS TXT record ci=14
>>> homekit_run_server: Starting HTTP server
mDNS: Delaying probe until IP is acquired
Got IP, resuming mDNS
mDNS: Probing 1 Window-47661B
mDNS: Probing 1 Window-47661B
mDNS: Probing 2 Window-47661B
mDNS: Probing 3 Window-47661B
mDNS: Probe successful, announcing Window-47661B TXT md=Window pv=1.0 id=7D:54:51:7D:B3:A2 c#=1 s#=1 ff=0 sf=1 ci=14
mDNS: Announcing 1 Window-47661B
mDNS: Announcing 2 Window-47661B
mDNS: Announcing 3 Window-47661B
mDNS: Announcing 4 Window-47661B
>>> homekit_server_accept_client: Free heap: 31948
>>> HomeKit: [Client 1] Got new client connection from 10.0.1.165
>>> homekit_client_process: [Client 1] Got 131 incoming data
>>> homekit_server_on_pair_setup: Pair Setup
>>> homekit_server_on_pair_setup: Free heap: 31976
>>> tlv_debug: Got following TLV values:
>>> tlv_debug: Type 0 value (1 bytes): \x00
>>> tlv_debug: Type 6 value (1 bytes): \x01
>>> HomeKit: [Client 1] Pair Setup Step 1/3
>>> homekit_server_on_pair_setup: Free heap: 31880
>>> crypto_srp_new: Initializing SRP
>>> homekit_server_on_pair_setup: [Client 1] Initializing crypto
>>> homekit_server_on_pair_setup: Free heap: 31216
>>> homekit_server_on_pair_setup: [Client 1] Using user-specified password: 781-92-047
>>> crypto_srp_init: Generating salt
>>> crypto_srp_init: Setting SRP username
>>> crypto_srp_init: Setting SRP params
>>> crypto_srp_init: Setting SRP password
>>> crypto_srp_init: Getting SRP verifier
>>> crypto_srp_init: Setting SRP verifier
>>> crypto_srp_get_public_key: Calculating public key
>>> client_sendv: [Client 1] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/pairing+tlv8\x0D\x0ATransfer-Encoding: chunked\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A
>>> client_sendv: [Client 1] Sending payload: \x31\x39\x39\x0D\x0A\x03\xFF\x80\x51\x0C\x3A\x88\x86\x97\x49\x2F\x97\x91\x38\x8F\x92\x97\x83\xF0\xD5\xC9\x16\xC7\xE4\x31\xF5\x73\x52\xE4\x34\xA0\x3F\xFF\x1F\x57\xA3\x9C\x09\x92\x81\x05\x50\xD6\xF3\x19\x26\x59\x5E\xE2\xA0\xDA\xE6\x80\xF9\x6A\x46\xE2\x2C\xA7\xFC\xBA\xA1\x40\x4B\x83\x07\x42\xB5\x75\x57\x54\xC8\x7F\x85\xFF\x9D\x62\x89\x3C\x61\x67\xBB\x03\x94\x8B\xD2\x83\xF0\x17\x9E\x1D\x87\x82\x5B\x41\x26\x05\x49\xE7\x59\x8E\x77\xD9\x6B\x30\x55\xB4\x33\x32\xEB\x88\xDC\x37\xBE\xE4\x90\xA6\xB7\x14\xA1\xF0\xF3\xC6\xCD\x9C\x7A\xE6\x16\xFE\x60\xA1\xC2\xD2\x4C\x5D\x65\xB6\xE0\x79\x3B\xCB\xA1\x1B\x3D\x75\xAA\x20\x17\x4A\x44\x52\xB8\x52\xE9\xAF\x3B\x6C\x62\xED\x0E\x5B\xCE\x7E\x72\xCE\xA1\x00\xEF\x2D\xFB\xDF\x11\x93\x9C\xC1\xE9\x0B\xBF\x5A\xCF\xE2\x02\x14\x1E\x10\x68\xB0\xB8\xEF\x34\x61\x8D\x62\xCF\x73\x6F\x8A\x15\x43\x6A\x96\xD1\xC2\xD5\x5B\x8C\x47\x7B\xFF\x91\x4E\x55\x3E\xE4\xFF\xD5\xB2\xA7\x86\x9F\x97\x22\x2F\x35\xE4\xAB\x61\xFF\x40\xCA\xBC\x4C\xB3\xE8\x19\x86\xAA\x3D\x54\x7C\x6F\x39\xEB\x62\x02\x57\x63\x19\xC5\x34\x27\x31\x21\x1D\x73\x97\x37\x03\x81\x50\xF6\xF6\x4C\x5B\xB7\x5B\xC8\xBD\xEF\xDC\xD2\x32\xFB\x7C\x47\xBE\x26\x96\xD1\x2D\x09\x4F\x1D\x78\x12\x9B\x5A\xEE\x28\x44\x1F\xF4\xB9\x6D\xCD\x1F\x20\x2F\x1E\x34\xF2\x41\x3F\x77\x49\x9F\x3B\xA6\xF8\xDB\xF6\xC8\xA4\x4D\x80\xC8\xBD\xA9\xBD\xE3\x0A\x3A\xB2\x17\xBA\x1C\x11\xD8\xE1\x70\xD2\x50\x2E\xAB\x1E\x30\x2F\xD8\xA8\xD9\xB1\x01\x6E\x23\x99\x96\xDF\x9E\x6A\xE4\x15\x95\xD3\x76\xC4\xBC\x73\xD8\xA2\xF2\x3E\x26\x53\xC6\xE0\x68\xF9\xE6\x59\x51\xE3\x0B\xBD\x41\x8D\x3D\xC1\xF5\x18\xE5\x25\x49\x81\x27\xB7\xC3\xA8\x9F\x02\x10\x5C\xF6\x10\xA9\x02\x42\xB6\x0A\xD0\xC4\xEF\x0B\xDC\x1A\xB1\x1A\x06\x01\x02\x0D\x0A
!!! HomeKit: [Client 1] Failed to write response (errno 104)
>>> client_sendv: [Client 1] Sending payload: \x30\x0D\x0A\x0D\x0A
!!! HomeKit: [Client 1] Failed to write response (errno 128)
>>> homekit_client_process: [Client 1] Finished processing
>>> homekit_server_accept_client: Free heap: 29072
...

This is an example code, similar to the one running above: https://github.com/AramVartanyan/esp-homekit-demo/blob/master/examples/shelly1/shelly1.c

I have also tested it with a Setup ID and the result is the same.

SmartArduino commented 3 years ago

We have the same problem

renandw commented 3 years ago

I've tried using iOS 15 beta in my iPhone with this results:

phy ver: 273, pp ver: 8.3

Using Sensor at GPIO0.
mode : sta(fc:f5:c4:93:ff:0f)
add if0
>>> HomeKit: Starting server
>>> HomeKit: Formatting HomeKit storage at 0x100000
>>> HomeKit: Generated new accessory ID: 4B:18:2D:74:01:6B
>>> HomeKit: Generated new accessory key
>>> HomeKit: Configuring mDNS
mDNS announcement: Name=Garagentor md=GDOpv=1.0id=4B:18:2D:74:01:6Bc#=1s#=1ff=0sf=1ci=4 Port=5556 TTL=4500
scandone
add 0
aid 8
cnt

connected with HOMEKIT, channel 8
dhcp client start...
ip:192.168.100.78,mask:255.255.255.0,gw:192.168.100.1
>>> HomeKit: Got new client connection: 4 from 192.168.100.35
>>> HomeKit: [Client 4] Pair Setup Step 1/3
>>> HomeKit: Got new client connection: 5 from 192.168.100.35
>>> HomeKit: [Client 4] Closing client connection
>>> HomeKit: [Client 5] Pair Setup Step 1/3
>>> HomeKit: [Client 5] Closing client connection
>>> HomeKit: Got new client connection: 4 from 192.168.100.35
>>> HomeKit: [Client 4] Pair Setup Step 1/3
>>> HomeKit: Got new client connection: 5 from 192.168.100.35
>>> HomeKit: [Client 4] Closing client connection
>>> HomeKit: [Client 5] Pair Setup Step 1/3
>>> HomeKit: [Client 5] Closing client connection

and right after failing, tried with the iPad on iOS14:

>>> HomeKit: Got new client connection: 4 from 192.168.100.27
>>> 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 FF8F5239-0D1E-401F-9801-D108619DFA94
>>> HomeKit: Configuring mDNS
mDNS announcement: Name=Garagentor md=GDOpv=1.0id=4B:18:2D:74:01:6Bc#=1s#=1ff=0sf=0ci=4 Port=5556 TTL=4500
>>> HomeKit: [Client 4] Successfully paired
>>> HomeKit: [Client 4] Closing client connection
>>> HomeKit: Got new client connection: 4 from 192.168.100.27
>>> HomeKit: [Client 4] Pair Verify Step 1/2
>>> HomeKit: [Client 4] Pair Verify Step 2/2
>>> HomeKit: [Client 4] Found pairing with FF8F5239-0D1E-401F-9801-D108619DFA94
>>> HomeKit: [Client 4] Verification successful, secure session established
>>> HomeKit: [Client 4] Get Accessories
returning current door state 'closed'.
Returning target door state 'closed'.
Notifying homekit that target door state is now 'closed'
Notifying changed 'Target Door State'
Notifying homekit that current door state is now 'closed'
Notifying changed 'Current Door State'
returning current door state 'closed'.
returning current door state 'closed'.
Returning target door state 'closed'.
>>> HomeKit: [Client 4] Update Characteristics
>>> HomeKit: [Client 4] Update Characteristics
>>> HomeKit: [Client 4] Get Characteristics
returning current door state 'closed'.
returning current door state 'closed'.
Returning target door state 'closed'.
>>> HomeKit: [Client 4] Add Pairing
>>> HomeKit: Added pairing with EAACB744-8CB3-4EC6-9DEC-E93F2C4A737B
>>> HomeKit: Got new client connection: 5 from 192.168.100.47
>>> HomeKit: [Client 5] Pair Verify Step 1/2
>>> HomeKit: [Client 5] Pair Verify Step 2/2
>>> HomeKit: [Client 5] Found pairing with FF8F5239-0D1E-401F-9801-D108619DFA94
>>> HomeKit: [Client 5] Verification successful, secure session established
>>> HomeKit: [Client 5] Get Accessories
returning current door state 'closed'.
returning current door state 'closed'.
Returning target door state 'closed'.
>>> HomeKit: [Client 5] Update Characteristics
>>> HomeKit: [Client 5] Update Characteristics
>>> HomeKit: [Client 5] Update Characteristics
>>> HomeKit: Got new client connection: 6 from 192.168.100.9
>>> HomeKit: [Client 6] Pair Verify Step 1/2
>>> HomeKit: [Client 6] Pair Verify Step 2/2
>>> HomeKit: [Client 6] Found pairing with FF8F5239-0D1E-401F-9801-D108619DFA94
>>> HomeKit: [Client 6] Verification successful, secure session established
>>> HomeKit: [Client 5] Update Characteristics
>>> HomeKit: [Client 6] Get Accessories
returning current door state 'closed'.
returning current door state 'closed'.
Returning target door state 'closed'.
>>> HomeKit: [Client 6] Update Characteristics
>>> HomeKit: [Client 6] Update Characteristics
>>> HomeKit: [Client 5] Update Characteristics
>>> HomeKit: [Client 5] Update Characteristics
>>> HomeKit: [Client 4] Update Characteristics

in my case, it was the example: https://github.com/maximkulkin/esp-homekit-demo/blob/master/examples/garage/garage.c

anyone got an answer?

renandw commented 3 years ago

@AramVartanyan what beta version are you running?

AramVartanyan commented 3 years ago

@renandw Actually my initial test was with an iPad having the first public beta that Apple released. The situation is unchanged with the current version 19A5307g. Also the error messages are visible with debug enabled. There is no issue pairing with devices having iOS 14 and than the accessory can be controlled by iOS 15 Home app.

HomeACcessoryKid commented 3 years ago

Some tracing done on a working device and one using the esp-homekit repo shows that apple has decided to enforce a 10s timeout on each of the Pair-Setup transactions. This timeout is not part of the R1 spec (HomeKit Accessory Protocol Specification (Non-Commercial Version) Release R1) nor R2 spec (HomeKit Accessory Protocol Specification Non-Commercial Version Release R2) and even in the section 6.5 (R1) or 7.5 (R2) item 37 it says:

37. Accessories must implement a 10 second HAP procedure timeout, all HAP procedures including
Pair-Verify and Pair-Resume (with the exception of Pair-Setup) must complete within 10 seconds,
if a procedure fails to complete within the procedure timeout the accessory must drop the
security session and also drop the Bluetooth link.

This is the only reference to this concept, and it applies only to the bluetooth chapter and even then the Pair-Setup is excluded.

Having found this, can those that are doing beta testing report to Apple that for devices reporting as R1 or R2 in their mdns messages (pv=1.0 or pv=1.1), they should not enforce this timeout as 10s but remain with their timeouts as applied up till iOS14.

Meanwhile we will see if we can accelerate the critical step, but that might not be easy at all... Anyone with ideas how to do that is welcome to contribute ;-)

d4rkmen commented 3 years ago

Hi, esp8266 with current wolfssl version will cross 10s border for sure on pair setup :( it takes 25 seconds approx Meanwhile, mbedtls with optimized build flags shows 12s result Yes its still out of 10s range but at-least not so much far from it.

RavenSystem commented 3 years ago

No. 10s timeout is for each pair stage There are 3 stages, but 2 firsts are the critical.

wolfSSL takes 14s for each one, and mbedtls takes about 5s.

RavenSystem commented 3 years ago

This could help to migrate to MbedTLS: https://github.com/apple/HomeKitADK/blob/master/PAL/Crypto/MbedTLS/HAPMbedTLS.c

pilot1981 commented 3 years ago

Me too interested you @maximkulkin update library!

TriderG75 commented 3 years ago

Highly appreciated if you can solve the problem. Thanks in advance Maxim 👍

gonzabur commented 3 years ago

Please, take a look on this topic. Your library is our salvation for many DIY projects. Thank you very much in advance.

kevinjohncutler commented 3 years ago

+1☝️

renandw commented 3 years ago

Today I've successfully paired 3 examples (garage, sonoff basic and led) in the latest iOS 15 public beta. Apple released the public beta today. Don't know if this is related to the issue: https://9to5mac.com/2021/08/13/apple-home-matter-smart-home-delay/

RavenSystem commented 3 years ago

Issue seems to be solved, but... IMO, migrating to MbedTLS library is a better solution to avoid those issues. Apple uses MbedTLS in Homekit accessory examples instead wolfSSL. If esp-homekit library uses MbedTLS, it will solve any future issue with Apple.

And MbedTLS has better performance than wolfSSL.