esp-homekit: ESP RTOS sdk paring failed.

Hi!

First of all I want to express words of appreciation for the hard work put into this project.

I have problem with connecting my iPhone to accessory. Apparently everything is fine, gets the connection but according to logs pairing is successful, while the phone shows information that the device cannot be added due to a connection error.

Somebody could help to solve this issue?

I’m using ESP RTOS SDK, branch release/v3.2 and iPhone 8 with latest iOS.

I (457) reset_reason: RTC reset 2 wakeup 0 store 0, reason is 2
STA start
I (5247) event: sta ip: 10.52.0.18, mask: 255.255.255.0, gw: 10.52.0.1
WiFI ready
>>> HomeKit: Starting server
>>> HomeKit: Using existing accessory ID: 8A:5A:C8:14:AE:DB
>>> HomeKit: Configuring mDNS
>>> homekit_setup_mdns: Accessory Setup ID = 1QJ8
>>> homekit_run_server: Staring HTTP server
>>> HomeKit: Got new client connection: 1 from 10.52.0.19
>>> homekit_client_process: [Client 1] Got 131 incomming data
>>> homekit_server_on_pair_setup: Pair Setup
>>> homekit_server_on_pair_setup: Free heap: 49160
>>> 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: 49068
>>> crypto_srp_new: Initializing SRP
>>> homekit_server_on_pair_setup: [Client 1] Initializing crypto
>>> homekit_server_on_pair_setup: Free heap: 48396
>>> homekit_server_on_pair_setup: [Client 1] Using user-specified password: 327-98-547
>>> 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
>>> send_tlv_response: [Client 1] Sending TLV response
>>> tlv_debug: Got following TLV values:
>>> tlv_debug: Type 3 value (384 bytes): \x03;\x91\xB5k!\xEC\xE6\x961w\x02\x03\x8D\xBB\x03\xA09\x9DQ\x8C\x97\x0A#\x92\x09<- o\xB5\xC5\x07s\xACR}\x01\x9Cm"]\xDB%D\x8E\xCD\x92^Q\xC6\xD4\xD2NQ\xCE,\x80\xD2S`\x05Y\xD1\xB5\xA6\xCA,\x95<{l\x09\x0E\xCC\xDC\x8F\xCD\xB2-\xCBN\xDE\x0F\xCD\xBEJt\xD75\x0F\x15\xB8>\x88u\xAF\xA9\xC3\xC0\x82\x1D\x13b\xF2\xC9613\x91\xE7\x88\xC6\xCFK-a`\x8F\x95\xD3#"\x84\x9Bg\x03\x08r\xC6\x1B\x91\xC7\x84\x1C\x9BY\xA1)5\x1D\\\x81\xD9_\xB2\x8B\xF5\x9FL\xC9!\xB5\xBF\xDE*&\xE9\x0AJw!\x12\x8F)\xE2;\x09\x9D\xD9\xBCvtL\xBE~W\xEF\x87\x17\xA1\xC7\xB68\x09\xD6\xA3\x04\xFD\x0E\x14\x11|O\xDE{\xC3\x9B\xC4\xEA\x11\x89\xC5\x07\x16\x89\xC9\x90\xA8\x11\xFA\xCC\xD5\xAF;9\xA2\xE9\x9B;'$;\x17\x9B\x18\xC7\x8DR\xCA\x87\x81\x0B\x06\xF3\xA438\xB6\xAE\xAC\xD4\xB8U\xD7~\xCC\xE2w\x0D\x08:"KT\xC6\xC8}\xE28Fx\xFF\xCDv \xC0\x9F\x9B\xFB/\x17\xBA@\x86\x1F!.\xF6\xB6\xEB\xF2\xF3\x0F\xB1}\x19:\x0CCO\x11\xB1\x12_\xCF\x82\xA0\x9Db\x8F^h*n\x9B5B'"4\xDED\x84w\x8F\x10\xA1uR\x97\xBE,\x81\x94{~\xAD\x1D\xB0]\xBC"\x83\xFC\xEE\xAB \xF7(\x8F\x10\xC9\x0BH=\\\x88Z\xF6\x1Bu\x04\xCD$\xBFi\xE1\xF0\x15D\x16\xF4\xC5\x1Dyi\x10b\x18{y\x831\xFF\xB2L\xCB\xBA\xCD>\xDD
>>> tlv_debug: Type 2 value (16 bytes): B\x16i\x01\xC6\x15\xFD"\x02\x87\x9BWR\xA6{\xDB
>>> tlv_debug: Type 6 value (1 bytes): \x02
>>> client_send: [Client 1] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/pairing+tlv8\x0D\x0AContent-Length: 409\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A\x03\xFF\x03;\x91\xB5k!\xEC\xE6\x961w\x02\x03\x8D\xBB\x03\xA09\x9DQ\x8C\x97\x0A#\x92\x09<- o\xB5\xC5\x07s\xACR}\x01\x9Cm"]\xDB%D\x8E\xCD\x92^Q\xC6\xD4\xD2NQ\xCE,\x80\xD2S`\x05Y\xD1\xB5\xA6\xCA,\x95<{l\x09\x0E\xCC\xDC\x8F\xCD\xB2-\xCBN\xDE\x0F\xCD\xBEJt\xD75\x0F\x15\xB8>\x88u\xAF\xA9\xC3\xC0\x82\x1D\x13b\xF2\xC9613\x91\xE7\x88\xC6\xCFK-a`\x8F\x95\xD3#"\x84\x9Bg\x03\x08r\xC6\x1B\x91\xC7\x84\x1C\x9BY\xA1)5\x1D\\\x81\xD9_\xB2\x8B\xF5\x9FL\xC9!\xB5\xBF\xDE*&\xE9\x0AJw!\x12\x8F)\xE2;\x09\x9D\xD9\xBCvtL\xBE~W\xEF\x87\x17\xA1\xC7\xB68\x09\xD6\xA3\x04\xFD\x0E\x14\x11|O\xDE{\xC3\x9B\xC4\xEA\x11\x89\xC5\x07\x16\x89\xC9\x90\xA8\x11\xFA\xCC\xD5\xAF;9\xA2\xE9\x9B;'$;\x17\x9B\x18\xC7\x8DR\xCA\x87\x81\x0B\x06\xF3\xA438\xB6\xAE\xAC\xD4\xB8U\xD7~\xCC\xE2w\x0D\x08:"K\x03\x81T\xC6\xC8}\xE28Fx\xFF\xCDv \xC0\x9F\x9B\xFB/\x17\xBA@\x86\x1F!.\xF6\xB6\xEB\xF2\xF3\x0F\xB1}\x19:\x0CCO\x11\xB1\x12_\xCF\x82\xA0\x9Db\x8F^h*n\x9B5B'"4\xDED\x84w\x8F\x10\xA1uR\x97\xBE,\x81\x94{~\xAD\x1D\xB0]\xBC"\x83\xFC\xEE\xAB \xF7(\x8F\x10\xC9\x0BH=\\\x88Z\xF6\x1Bu\x04\xCD$\xBFi\xE1\xF0\x15D\x16\xF4\xC5\x1Dyi\x10b\x18{y\x831\xFF\xB2L\xCB\xBA\xCD>\xDD\x02\x10B\x16i\x01\xC6\x15\xFD"\x02\x87\x9BWR\xA6{\xDB\x06\x01\x02
>>> homekit_client_process: [Client 1] Finished processing
>>> homekit_client_process: [Client 1] Got 584 incomming data
>>> homekit_server_on_pair_setup: Pair Setup
>>> homekit_server_on_pair_setup: Free heap: 46208
>>> tlv_debug: Got following TLV values:
>>> tlv_debug: Type 6 value (1 bytes): \x03
>>> tlv_debug: Type 3 value (384 bytes): \xA5nsA\x13y\xEA\x15>\xEEXo*`\x0F\x09U\x1ERh\xEB\x09\x9DKA9\xA9\x82\x08/\xFA`\xB8\xA6!\xFCZ\x86\x05h\xCDt\xAE9q\xE2\x86\xF0\xB8\xEE\xE1\xA9}6\xF38\xA4vrST\xF0\xAF\xFDT\xB1"S\xDB\x9B\xE7A@\xD9\xD8>-\xF4\xD0\x07U\xD1\x8E&\xC4%\xCB\x83#d5m^ \xBCWLK+\xF3\x17U\x16\xA7m\xE3K\xA7=\xC9\x98\xD7\xCF\xCD\x89\xA7\x1AN\xFD\xA2\x12O~\xB5\x883$8ii5n\x16\xEAlEg\x95r\x8C\x86\xE3\x05\x8Dx\xA6\xC3\xC9\x08\\\x15\xF8k\xF2\x83\xA5\xD4\xF1\xBC=\xC4\x08\x0Ca\xC2\xFDd\x9D\xBE\xCE\x95b\xD8\xC3jkV\xF7SU\xFE\x97'0\x04\xAE\x1A\x12\xED\xF8w\xCD+\xF6\xEE#\xEC\x87\xBB_\xC7+^\xB4\x9A\x9F\xBA\xC3\xF7\x85\xE9\x84|\x19\xE8\xFFL\xC1!F\x01\xE9\xFA0\xC8\xB1"\xDF\xEB\xD4\x95\xE1\x11Mu\xF2\x0E\xD0^\xBE/\xFC8\xDA\x13f5\xC9wr\xEC\xA8+\xB2\xBD\x07\xFEL-\xA3\xFA\x10\x0Cq\xB3\xE3\x8B\xBD\xD7\x8A\x9F\x1C\xE9\x1C\xEBnp\xF1\x1B\xA4+\xF8\xD1\x9E?;N\xA9\\\x091Dq\x16\xCC\xE9\x1A\xF9G\x0AlI\x98\x83J\xF5\x07\xCA\xDB\xB9\x93\x8E\xD9\xF7\x04j\xF2H\x0B\x0D{\xC6\xA2\x09!\xF5!\x8C\x86\xF6\x9DaZ`j~\x00\xAA\x94^]&o\xAA\x13\xF7\x01\xA4\x8B\x88\xA2\xD5C\x9D\xF2\x15Qk-\x87\xB7E:hG\x83\x16\x008\xDA}\x81E {3I\xA5\xB3\\\xF6\x97\x00\x02
>>> tlv_debug: Type 4 value (64 bytes): \xD4\xCD\x1B.he\x0Eu\xFF\xAAH\x92WL\x8F\x8C9\x9Ahel\x00z\x92\x9BW/\xD6\xA7\xFC\xBC\xB0F\x8B\x01\xFB\x12\xB4Cz.\xCE\x8Dv\xD5\xDA\x82\x05\xDE\xBB\xBFl\xA9~\xC3!\xA6\x1F\xD1\xB2\xD4\xB6J
>>> HomeKit: [Client 1] Pair Setup Step 2/3
>>> homekit_server_on_pair_setup: Free heap: 45648
>>> homekit_server_on_pair_setup: [Client 1] Computing SRP shared secret
>>> homekit_server_on_pair_setup: Free heap: 45648
>>> homekit_server_on_pair_setup: [Client 1] Verifying peer's proof
>>> homekit_server_on_pair_setup: Free heap: 45968
>>> homekit_server_on_pair_setup: [Client 1] Generating own proof
>>> send_tlv_response: [Client 1] Sending TLV response
>>> tlv_debug: Got following TLV values:
>>> tlv_debug: Type 6 value (1 bytes): \x04
>>> tlv_debug: Type 4 value (64 bytes): \x09\x0DK$*\xC4\x87X}\x16\x1B\xC3\x9DS\x8DVf7=\x0DNg\xA2\x8F\x88\x1F\xB0\xA6\xAE\x93;n5"14M5\xBA;>kQ\xBD\x08J.\xF0p\x971b|J\x07O"\xB7G\xA2X\x00\xCEs
>>> client_send: [Client 1] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/pairing+tlv8\x0D\x0AContent-Length: 69\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A\x06\x01\x04\x04@\x09\x0DK$*\xC4\x87X}\x16\x1B\xC3\x9DS\x8DVf7=\x0DNg\xA2\x8F\x88\x1F\xB0\xA6\xAE\x93;n5"14M5\xBA;>kQ\xBD\x08J.\xF0p\x971b|J\x07O"\xB7G\xA2X\x00\xCEs
>>> homekit_client_process: [Client 1] Finished processing
>>> homekit_client_process: [Client 1] Got 286 incomming data
>>> homekit_server_on_pair_setup: Pair Setup
>>> homekit_server_on_pair_setup: Free heap: 46828
>>> tlv_debug: Got following TLV values:
>>> tlv_debug: Type 5 value (154 bytes): \xDB8cf%2\xD5\xB4\xAA\x8C?\xD7\xB0*\xA7\xE1\x88\xC3(\xF1\xBD\xC3xQ\xA1A\xD7\x1D/\x03\x0Ay\xAA\xB8\xDF8\x8C\xC15\x8C\x06g\xF8\x8A\xD6i\xCE\xBC\x0D2\x86\x9A\xB9\xAA.\xB9\xA8\x83\x15\x8C4\xE0\x19\xD1\xAB\xA0\xC2}\xDE\xB5\x8FOb\x1ER\x0E\x8F\x06\x06\xBA\xC5\xA45P@\xCAJ\x1Er\xE0'$z{\xCEC\x8B\x09(\x0D,\xA2\xBA\xD3\xCA\xC8X1\xA3\x03d\x1D\xF5R\xAB=\xDB$#6\x8C\xA0\xB2\xB7\xC8h\xB9\xB3\xB0or7CN\xCB\xBD\xF2\xAC{\x15\xB3\x1F\x0E\xAD9+\x8B\x08\x08*\xDD]\\
>>> tlv_debug: Type 6 value (1 bytes): \x05
>>> HomeKit: [Client 1] Pair Setup Step 3/3
>>> homekit_server_on_pair_setup: Free heap: 46592
>>> homekit_server_on_pair_setup: [Client 1] Calculating shared secret
>>> homekit_server_on_pair_setup: [Client 1] Decrypting payload
>>> homekit_server_on_pair_setup: [Client 1] Importing device public key
>>> homekit_server_on_pair_setup: [Client 1] Calculating DeviceX
>>> homekit_server_on_pair_setup: [Client 1] Verifying device signature
>>> HomeKit: Added pairing with 9B1C8220-E0E5-4272-A9FC-4A841A296F92
>>> homekit_server_on_pair_setup: [Client 1] Exporting accessory public key
>>> homekit_server_on_pair_setup: [Client 1] Calculating AccessoryX
>>> homekit_server_on_pair_setup: [Client 1] Generating accessory signature
>>> homekit_server_on_pair_setup: Free heap: 46460
>>> tlv_debug: Got following TLV values:
>>> tlv_debug: Type 1 value (17 bytes): 8A:5A:C8:14:AE:DB
>>> tlv_debug: Type 3 value (32 bytes): \xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF
>>> tlv_debug: Type 10 value (64 bytes): \xB5\xEF3\x15\xD7\xF7\x9E\xB1\xDA\xCBp\x9E\xEB?6#\x89\x82\xD5>0\xF9`vx\xD9\x173|\x86/\xEF\xEF\xB5\xCEZ\xF9\x8D\xA9\x8BT\x0B<V\xF4"\x11G\xBE\x04]uQ\x00K.\x14\x16\x0D\x8A\x97\\\x0C\x07
>>> homekit_server_on_pair_setup: [Client 1] Encrypting response
>>> send_tlv_response: [Client 1] Sending TLV response
>>> tlv_debug: Got following TLV values:
>>> tlv_debug: Type 6 value (1 bytes): \x06
>>> tlv_debug: Type 5 value (135 bytes): U^D2\x83F\x06\x11\xB1\xE7\xE3X>\x80\xCAV\x88\xEF\xB4o\xE8\x97\xC0\xD4^xb\x06\xAD\xBF\xEF6|\xEA\x9D\xC1%Fw|iL&HZ3\x0B:\xD4\xCC8\xE5\x93A\xF3\x0B\xB4A\x1A\xA7"\xFF\xC4&1\xD2\xB0\x06\x85\x8D\xB8\x857z\x81\xEBD\x89\x00\xC43>-\x1B\xCB\xF4[x\xBBi\x8AE.\x0E?\x9C\x08EM\xB9\x1A3\x1B\x94\x9F\xF0\xD9Nj\xC8\xA3\xD9\xB6N\xEFH\xF2\xF0\x81q\xD41\x0F9\xC4Q\xC6\x9A\xF1\xF3L9\x1C
>>> client_send: [Client 1] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/pairing+tlv8\x0D\x0AContent-Length: 140\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A\x06\x01\x06\x05\x87U^D2\x83F\x06\x11\xB1\xE7\xE3X>\x80\xCAV\x88\xEF\xB4o\xE8\x97\xC0\xD4^xb\x06\xAD\xBF\xEF6|\xEA\x9D\xC1%Fw|iL&HZ3\x0B:\xD4\xCC8\xE5\x93A\xF3\x0B\xB4A\x1A\xA7"\xFF\xC4&1\xD2\xB0\x06\x85\x8D\xB8\x857z\x81\xEBD\x89\x00\xC43>-\x1B\xCB\xF4[x\xBBi\x8AE.\x0E?\x9C\x08EM\xB9\x1A3\x1B\x94\x9F\xF0\xD9Nj\xC8\xA3\xD9\xB6N\xEFH\xF2\xF0\x81q\xD41\x0F9\xC4Q\xC6\x9A\xF1\xF3L9\x1C
>>> HomeKit: Configuring mDNS
>>> homekit_setup_mdns: Accessory Setup ID = 1QJ8
>>> HomeKit: [Client 1] Successfully paired
>>> homekit_client_process: [Client 1] Finished processing
>>> HomeKit: [Client 1] Closing client connection
>>> HomeKit: Got new client connection: 1 from 10.52.0.19
>>> homekit_client_process: [Client 1] Got 131 incomming data
>>> homekit_server_on_pair_setup: Pair Setup
>>> homekit_server_on_pair_setup: Free heap: 49168
>>> 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: 49076
>>> HomeKit: [Client 1] Refusing to pair: already paired
>>> send_tlv_response: [Client 1] Sending TLV response
>>> tlv_debug: Got following TLV values:
>>> tlv_debug: Type 6 value (1 bytes): \x02
>>> tlv_debug: Type 7 value (1 bytes): \x06
>>> client_send: [Client 1] 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\x06\x01\x02\x07\x01\x06
>>> homekit_client_process: [Client 1] Finished processing
>>> HomeKit: [Client 1] Closing client connection

Maybe problem is that after flash at first boot I always get kernel panic?

WiFI ready
>>> HomeKit: Starting server
>>> HomeKit: Formatting HomeKit storage at 0x200000
>>> HomeKit: Generated new accessory ID: E8:22:BE:83:67:16


Task stack [HomeKit Server] stack from [0x3fff4590] to [0x3fff758c], total [12288] size

                   0          4          8          c         10         14         18         1c         20         24         28         2c         30         34         38         3c

3fff7480  0x00000022 0x401077ec 0x00000000 0x00000000 0x401077fe 0x401077fe 0x4010781e 0x4025eb0c 0x00000000 0x401077fe 0x401077fe 0x4024be45 0x00000083 0x00000067 0x00000016 0x00000000
0x4025eb0c: wc_ed25519_make_key at /Users/maczek/esp_sdk/esp-homekit-demo/components/common/wolfssl/wolfssl-4.1.0/wolfcrypt/src/ed25519.c:713

0x4024be45: crypto_ed25519_generate at /Users/maczek/esp_sdk/esp-homekit-demo/components/common/homekit/src/crypto.c:363

3fff74c0  0x00000000 0x00000000 0x401077ec 0x4024a60c 0xa5a5a5a5 0xa5a5a5a5 0x401077ec 0x4024a67c 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5
0x4024a60c: homekit_accessory_key_generate at /Users/maczek/esp_sdk/esp-homekit-demo/components/common/homekit/src/server.c:3387

0x4024a67c: homekit_server_task at /Users/maczek/esp_sdk/esp-homekit-demo/components/common/homekit/src/server.c:3421

3fff7500  0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5
3fff7540  0x40105430 0x4024a630 0x00000030 0x00000000 0x3fff7590 0x401077ec 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000
0x40105430: _xt_user_exit at /Users/maczek/esp_sdk/ESP8266_RTOS_SDK/components/freertos/port/esp8266/xtensa_vectors.S:715

0x4024a630: homekit_server_task at /Users/maczek/esp_sdk/esp-homekit-demo/components/common/homekit/src/server.c:3398

3fff7580  0x00000000 0x00000000 0x00000000 0x00000000


        PC: 0x40260b84        PS: 0x00000030        A0: 0x40260b84        A1: 0x3fff7480
0x40260b84: hwrand_generate_block at /Users/maczek/esp_sdk/esp-homekit-demo/components/common/wolfssl/wolfssl-4.1.0/wolfcrypt/src/random.c:943
 (inlined by) wc_RNG_GenerateBlock at /Users/maczek/esp_sdk/esp-homekit-demo/components/common/wolfssl/wolfssl-4.1.0/wolfcrypt/src/random.c:883

0x40260b84: hwrand_generate_block at /Users/maczek/esp_sdk/esp-homekit-demo/components/common/wolfssl/wolfssl-4.1.0/wolfcrypt/src/random.c:943
 (inlined by) wc_RNG_GenerateBlock at /Users/maczek/esp_sdk/esp-homekit-demo/components/common/wolfssl/wolfssl-4.1.0/wolfcrypt/src/random.c:883

        A2: 0xc9901094        A3: 0xfddb92a8        A4: 0x0000001e        A5: 0x4010783e
        A6: 0x40107830        A7: 0x00000001        A8: 0x00000000        A9: 0x0000ffff
       A10: 0x00000000       A11: 0xffffffff       A12: 0x4010781e       A13: 0x00000000
       A14: 0x00000004       A15: 0x00000020       SAR: 0x00000013  EXCCAUSE: 0x00000009

 ets Jan  8 2013,rst cause:2, boot mode:(3,6)

load 0x40100000, len 7176, room 16
0x40100000: _stext at ??:?