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

ESPHap unable to process client connections after restarting HomeBridge instance in network #64

Closed
eford321 opened this issue Feb 28, 2021 · 81 comments

Comments

@eford321
Copy link
Contributor

eford321 commented Feb 28, 2021

Running v.1.0.7 on ESP8266 with multiple example sketches. Devices function properly until a Homebridge is restarted. Afterward all client connections from any device are accepted and then immediately disconnected. All ESPHap devices go unresponsive until they are rebooted. This does not effect other native Homekit devices in the network. I am attempting to log events from the homebridge side, but the log is huge.

Here is the ESPHap device log running sketch EspHapLed8266. Device is paired and functional.
Notes: Homebridge is 192.168.1.213. Homebridge restarted after 14:11:21.444 timestamp. Message from homebridge processed at 14:11:51.555 breaks ESPHap.
...
14:10:58.887 -> IP address:
14:10:58.887 -> 192.168.1.23
14:10:58.887 -> Free heap: 34056
14:10:58.887 -> init_hap_storage>>> HomeKit: init_storage_ex size 0x1c1
14:10:58.923 -> >>> Home Integration: hap_services added chararacteristic 0: 23
14:10:58.923 -> >>> Home Integration: hap_services added chararacteristic 1: 25
14:10:58.923 -> >>> Home Integration: homekit_is_paired 1
14:10:58.923 -> >>> HomeKit: Free heap: 32072
14:10:58.923 -> >>> server_new: WiFiServer begin at port: 5556
14:10:58.923 ->
14:10:58.923 -> >>> HomeKit: Starting server
14:10:58.923 -> >>> HomeKit: storage init 0
14:10:58.923 -> >>> HomeKit: Using existing accessory ID: B1:E8:4D:32:98:71
14:10:58.923 -> >>> HomeKit: find pairings
14:10:58.957 -> >>> HomeKit: Found admin pairing with 6FDD5BE0-78E1-4A4C-B5D7-98277EEFA239, disabling pair setup
14:10:58.957 -> >>> HomeKit: Configuring mDNS
14:10:58.957 -> >>> HomeKit: MDNS.begin: ES-B1E8, IP: 192.168.1.23
14:10:58.957 -> >>> homekit_mdns_init: Accessory Setup ID = YK72
14:10:58.957 -> >>> HomeKit: Init server over
14:11:06.422 -> pm open,type:2 0
14:11:12.872 -> >>> HomeKit: WiFiServer receives a new client (current 0, max 8)
14:11:12.906 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.13:58362
14:11:12.906 -> >>> HomeKit: [Client 1073699420] Got client content from the cache 0
14:11:12.906 -> >>> HomeKit: [Client 1073699420] new client accepted
14:11:12.906 -> >>> homekit_client_process: [Client 1073699420] Reading 158 bytes
14:11:12.906 -> >>> homekit_server_on_message_complete: http_parser message_complete
14:11:12.940 -> >>> homekit_server_on_pair_verify: HomeKit Pair Verify
14:11:12.940 -> >>> homekit_server_on_pair_verify: Free heap: 24320
14:11:12.940 -> >>> tlv_debug: Got following TLV values:
14:11:12.940 -> >>> tlv_debug: Type 6 value (1 bytes): \x01
14:11:12.940 -> >>> tlv_debug: Type 3 value (32 bytes): \x8E\x16\x11a\xB7\xD9\xD5\x1E3\xE5<\x98\x15+\x88Z\xA4\x00~\xEEU\x86\xD3E\xC7\xA2\xB5\xF8\xDC\x9Ad~
14:11:12.940 -> >>> HomeKit: [Client 1073699420] Pair Verify Step 1/2
14:11:12.974 -> >>> homekit_server_on_pair_verify: [Client 1073699420] Importing device Curve25519 public key
14:11:12.974 -> >>> homekit_server_on_pair_verify: [Client 1073699420] Generating accessory Curve25519 key
14:11:13.085 -> >>> homekit_server_on_pair_verify: [Client 1073699420] Exporting accessory Curve25519 public key
14:11:13.120 -> >>> homekit_server_on_pair_verify: [Client 1073699420] Generating Curve25519 shared secret
14:11:13.230 -> >>> homekit_server_on_pair_verify: [Client 1073699420] Generating signature
14:11:13.298 -> >>> homekit_server_on_pair_verify: [Client 1073699420] Generating proof
14:11:13.335 -> >>> homekit_server_on_pair_verify: [Client 1073699420] Encrypting response
14:11:13.335 -> >>> send_tlv_response: [Client 1073699420] Sending TLV response
14:11:13.335 -> >>> tlv_debug: Got following TLV values:
14:11:13.335 -> >>> tlv_debug: Type 6 value (1 bytes): \x02
14:11:13.335 -> >>> tlv_debug: Type 3 value (32 bytes): \xF3\x12O\x83\x1D\x08\x920\xAF\xB1#O\x84\xB2\x16\x99\xA2\x98#\x18\x1E\xE86'D\xBB\x0A\xDA\xDA\x0B\xB5k
14:11:13.369 -> >>> tlv_debug: Type 5 value (101 bytes): \xEA\x183+\xC2g\x83\x15\x98\x81>\x02E\x02z�;{\x0A\xEAq\x18\x10O\x03\xFE\x0A\xCD\x83\xEDGeC\x085W\xB4\xD1\xE9\xBE\x19\x98W\x95\xB0\x9C-\xB1\xD5\xF4\xA3\x1F\xF0\xD0\x9E\xAE\xCB\xA6@\xBB\x87\x1Bf\xA7\xD2\x89\x1A\xE0=@\xFA\xBE\xBCw8B\x12uZ\x10ys*\xE7\xFA#\xE6\x1Cj\x95R 0+ppz\x91\x1C V
14:11:13.369 -> >>> client_send: [Client 1073699420] send data size=244, encrypted=false
14:11:13.406 -> >>> client_send: [Client 1073699420] 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\x02\x03 \xF3\x12O\x83\x1D\x08\x920\xAF\xB1#O\x84\xB2\x16\x99\xA2\x98#\x18\x1E\xE86'D\xBB\x0A\xDA\xDA\x0B\xB5k\x05e\xEA\x183+\xC2g\x83\x15\x98\x81>\x02E\x02z�;{\x0A\xEAq\x18\x10O\x03\xFE\x0A\xCD\x83\xEDGeC\x085W\xB4\xD1\xE9\xBE\x19\x98W\x95\xB0\x9C-\xB1\xD5\xF4\xA3\x1F\xF0\xD0\x9E\xAE\xCB\xA6@\xBB\x87\x1Bf\xA7\xD2\x89\x1A\xE0=@\xFA\xBE\xBCw8B\x12uZ\x10ys*\xE7\xFA#\xE6\x1Cj\x95R 0+ppz\x91\x1C V
14:11:13.444 -> >>> HomeKit: Free heap: 24080
14:11:13.444 -> >>> homekit_client_process: [Client 1073699420] Reading 247 bytes
14:11:13.444 -> >>> homekit_server_on_message_complete: http_parser message_complete
14:11:13.511 -> >>> homekit_server_on_pair_verify: HomeKit Pair Verify
14:11:13.511 -> >>> homekit_server_on_pair_verify: Free heap: 23992
14:11:13.511 -> >>> tlv_debug: Got following TLV values:
14:11:13.511 -> >>> tlv_debug: Type 5 value (120 bytes): $Rn\x99\xFA\x8D\x98\x8A\xF4o\x9Dc\xA3\x97J\x98\xB8\x09\xE6v\x1F\x90\xDA1U<.F\xBF&\x14\x14\xD4<\x91\x80\x80e\\xDA1\xBA\xD7+\x0F\xFA\xA4\xC9\xED\x98\x8Ap\x1B\x9E\x89\xD7\xBB\xFBi+\x08N\x0D\x0F\xD5?\xAA[\xB4-\xA08L\xB5\x05\x0CM\x9B\xC0\xD5\xEC\x83\x83\x8A\xA4\xD9I\x08\xE9\xE4Q\xEF\x8CL\xB1�\x89)R\x9F\xE9\x19O\xF7\x91g\xEE\xE5="&X\xBD\x16[\xF3\xAFk\x8D\xFF
14:11:13.511 -> >>> tlv_debug: Type 6 value (1 bytes): \x03
14:11:13.511 -> >>> HomeKit: [Client 1073699420] Pair Verify Step 2/2
14:11:13.511 -> >>> homekit_server_on_pair_verify: [Client 1073699420] Decrypting payload
14:11:13.511 -> >>> homekit_server_on_pair_verify: [Client 1073699420] Searching pairing with 6FDD5BE0-78E1-4A4C-B5D7-98277EEFA239
14:11:13.554 -> >>> HomeKit: [Client 1073699420] Found pairing with 6FDD5BE0-78E1-4A4C-B5D7-98277EEFA239
14:11:13.554 -> >>> homekit_server_on_pair_verify: [Client 1073699420] Verifying device signature
14:11:14.322 -> >>> send_tlv_response: [Client 1073699420] Sending TLV response
14:11:14.322 -> >>> tlv_debug: Got following TLV values:
14:11:14.322 -> >>> tlv_debug: Type 6 value (1 bytes): \x04
14:11:14.322 -> >>> client_send: [Client 1073699420] send data size=105, encrypted=false
14:11:14.356 -> >>> client_send: [Client 1073699420] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/pairing+tlv8\x0D\x0AContent-Length: 3\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A\x06\x01\x04
14:11:14.356 -> >>> HomeKit: [Client 1073699420] Verification successful, secure session established
14:11:14.391 -> >>> HomeKit: Free heap: 24224
14:11:14.391 -> >>> homekit_client_process: [Client 1073699420] Reading 78 bytes
14:11:14.391 -> >>> homekit_client_process: [Client 1073699420] Decrypted 60 bytes, available 0
14:11:14.391 -> Decrypted data (60 bytes): "GET /accessories HTTP/1.1\x0D\x0AHost: ES-B1E8.hap.tcp.local\x0D\x0A\x0D\x0A"
14:11:14.391 -> >>> homekit_server_on_message_complete: http_parser message_complete
14:11:14.391 -> >>> HomeKit: [Client 1073699420] Get Accessories
14:11:14.429 -> >>> homekit_server_on_get_accessories: Free heap: 24368
14:11:14.429 -> >>> client_send: [Client 1073699420] send data size=107, encrypted=true
14:11:14.429 -> >>> client_send: [Client 1073699420] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A
14:11:14.429 -> >>> client_send_encrypted
: [Client 1073699420] client_send_encrypted
size=107
14:11:14.466 -> >>> homekit_server_on_get_accessories: [Client 1073699420] Get Accessories, start send json body
14:11:14.466 -> >>> client_send_chunk: [Client 1073699420] client_send_chunk, size=1012, offset=5
14:11:14.466 -> >>> client_send: [Client 1073699420] send data size=1019, encrypted=true
14:11:14.466 -> >>> client_send: [Client 1073699420] Sending payload: 3f4\x0D\x0A{"accessories":[{"aid":1,"services":[{"iid":1,"type":"3E","hidden":false,"primary":false,"characteristics":[{"aid":1,"iid":2,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"ES"},{"aid":1,"iid":3,"type":"20","perms":["pr"],"description":"Manufacturer","format":"string","value":"Yurik72"},{"aid":1,"iid":4,"type":"30","perms":["pr"],"description":"Serial Number","format":"string","value":"0"},{"aid":1,"iid":5,"type":"21","perms":["pr"],"description":"Model","format":"string","value":"EspHapLed"},{"aid":1,"iid":6,"type":"52","perms":["pr"],"description":"Firmware Revision","format":"string","value":"1.0"},{"aid":1,"iid":7,"type":"14","perms":["pw"],"description":"Identify","format":"bool"}]},{"iid":8,"type":"43","hidden":false,"primary":true,"characteristics":[{"aid":1,"iid":9,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"Led"},{"aid":1,"iid":10,"type":"25","perms":["pr","pw","ev"],"ev":false,"description":"On","format":"bool","value":true}]}]}]}\x0D\x0A
14:11:14.576 -> >>> client_send_encrypted_: [Client 1073699420] client_send_encrypted_ size=1019
14:11:14.613 -> >>> client_send_chunk: [Client 1073699420] client_send_chunk, size=0, offset=3
14:11:14.613 -> >>> client_send: [Client 1073699420] send data size=5, encrypted=true
14:11:14.613 -> >>> client_send: [Client 1073699420] Sending payload: 0\x0D\x0A\x0D\x0A
14:11:14.613 -> >>> client_send_encrypted_: [Client 1073699420] client_send_encrypted_ size=5
14:11:14.648 -> >>> homekit_client_process: [Client 1073699420] Reading 90 bytes
14:11:14.648 -> >>> homekit_client_process: [Client 1073699420] Decrypted 72 bytes, available 0
14:11:14.648 -> Decrypted data (72 bytes): "GET /characteristics?id=1.10 HTTP/1.1\x0D\x0AHost: ES-B1E8.hap.tcp.local\x0D\x0A\x0D\x0A"
14:11:14.648 -> >>> homekit_server_on_message_complete: http_parser message_complete
14:11:14.685 -> >>> HomeKit: [Client 1073699420] Get Characteristics
14:11:14.685 -> >>> homekit_server_on_get_characteristics: Free heap: 24160
14:11:14.685 -> >>> homekit_server_on_get_characteristics: [Client 1073699420] Query paramter id = 1.10
14:11:14.685 -> >>> homekit_server_on_get_characteristics: [Client 1073699420] Requested characteristic info for 1.10
14:11:14.685 -> >>> client_send: [Client 1073699420] send data size=107, encrypted=true
14:11:14.685 -> >>> client_send: [Client 1073699420] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A
14:11:14.719 -> >>> client_send_encrypted
: [Client 1073699420] client_send_encrypted
size=107
14:11:14.719 -> >>> homekit_server_on_get_characteristics: [Client 1073699420] Requested characteristic info for 1.10
14:11:14.753 -> >>> client_send_chunk: [Client 1073699420] client_send_chunk, size=53, offset=4
14:11:14.753 -> >>> client_send: [Client 1073699420] send data size=59, encrypted=true
14:11:14.753 -> >>> client_send: [Client 1073699420] Sending payload: 35\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"value":true}]}\x0D\x0A
14:11:14.753 -> >>> client_send_encrypted_: [Client 1073699420] client_send_encrypted_ size=59
14:11:14.802 -> >>> client_send_chunk: [Client 1073699420] client_send_chunk, size=0, offset=3
14:11:14.802 -> >>> client_send: [Client 1073699420] send data size=5, encrypted=true
14:11:14.802 -> >>> client_send: [Client 1073699420] Sending payload: 0\x0D\x0A\x0D\x0A
14:11:14.802 -> >>> client_send_encrypted_: [Client 1073699420] client_send_encrypted_ size=5
14:11:14.802 -> >>> homekit_client_process: [Client 1073699420] Reading 188 bytes
14:11:14.802 -> >>> homekit_client_process: [Client 1073699420] Decrypted 170 bytes, available 0
14:11:14.839 -> Decrypted data (170 bytes): "PUT /characteristics HTTP/1.1\x0D\x0AHost: ES-B1E8.hap.tcp.local\x0D\x0AContent-Length: 50\x0D\x0AContent-Type: application/hap+json\x0D\x0A\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"ev":true}]}"
14:11:14.839 -> >>> homekit_server_on_message_complete: http_parser message_complete
14:11:14.839 -> >>> HomeKit: [Client 1073699420] Update Characteristics
14:11:14.839 -> >>> homekit_server_on_update_characteristics: Free heap: 24296
14:11:14.907 -> >>> HomeKit: Free heap: 24272
14:11:14.907 -> >>> homekit_server_on_update_characteristics: [Client 1073699420] There were no processing errors, sending No Content response
14:11:14.907 -> >>> client_send: [Client 1073699420] send data size=27, encrypted=true
14:11:14.907 -> >>> client_send: [Client 1073699420] Sending payload: HTTP/1.1 204 No Content\x0D\x0A\x0D\x0A
14:11:14.907 -> >>> client_send_encrypted
: [Client 1073699420] client_send_encrypted
size=27
14:11:18.302 -> >>> homekit_client_process: [Client 1073699420] Reading 188 bytes
14:11:18.302 -> >>> homekit_client_process: [Client 1073699420] Decrypted 170 bytes, available 0
14:11:18.338 -> Decrypted data (170 bytes): "PUT /characteristics HTTP/1.1\x0D\x0AHost: ES-B1E8.hap.tcp.local\x0D\x0AContent-Length: 50\x0D\x0AContent-Type: application/hap+json\x0D\x0A\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"value":0}]}"
14:11:18.338 -> >>> homekit_server_on_message_complete: http_parser message_complete
14:11:18.338 -> >>> HomeKit: [Client 1073699420] Update Characteristics
14:11:18.338 -> >>> homekit_server_on_update_characteristics: Free heap: 24272
14:11:18.379 -> >>> HomeKit: Free heap: 24248
14:11:18.379 -> >>> process_characteristics_update: [Client 1073699420] Updating characteristic 1.10 with boolean false
14:11:18.379 -> led_callback
14:11:18.379 -> set_led
14:11:18.379 -> notify hap
14:11:18.379 -> found characteristic
14:11:18.379 -> >>> client_notify_characteristic: [Client 1073699420] This value is set by this client, no need to send notification
14:11:18.379 -> >>> homekit_server_on_update_characteristics: [Client 1073699420] There were no processing errors, sending No Content response
14:11:18.434 -> >>> client_send: [Client 1073699420] send data size=27, encrypted=true
14:11:18.434 -> >>> client_send: [Client 1073699420] Sending payload: HTTP/1.1 204 No Content\x0D\x0A\x0D\x0A
14:11:18.434 -> >>> client_send_encrypted
: [Client 1073699420] client_send_encrypted
size=27
14:11:21.305 -> >>> homekit_client_process: [Client 1073699420] Reading 188 bytes
14:11:21.305 -> >>> homekit_client_process: [Client 1073699420] Decrypted 170 bytes, available 0
14:11:21.342 -> Decrypted data (170 bytes): "PUT /characteristics HTTP/1.1\x0D\x0AHost: ES-B1E8.hap.tcp.local\x0D\x0AContent-Length: 50\x0D\x0AContent-Type: application/hap+json\x0D\x0A\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"value":1}]}"
14:11:21.342 -> >>> homekit_server_on_message_complete: http_parser message_complete
14:11:21.342 -> >>> HomeKit: [Client 1073699420] Update Characteristics
14:11:21.342 -> >>> homekit_server_on_update_characteristics: Free heap: 24280
14:11:21.444 -> >>> HomeKit: Free heap: 24256
14:11:21.444 -> >>> process_characteristics_update: [Client 1073699420] Updating characteristic 1.10 with boolean true
14:11:21.444 -> led_callback
14:11:21.444 -> set_led
14:11:21.444 -> notify hap
14:11:21.444 -> found characteristic
14:11:21.444 -> >>> client_notify_characteristic: [Client 1073699420] This value is set by this client, no need to send notification
14:11:21.444 -> >>> homekit_server_on_update_characteristics: [Client 1073699420] There were no processing errors, sending No Content response
14:11:21.444 -> >>> client_send: [Client 1073699420] send data size=27, encrypted=true
14:11:21.444 -> >>> client_send: [Client 1073699420] Sending payload: HTTP/1.1 204 No Content\x0D\x0A\x0D\x0A
14:11:21.444 -> >>> client_send_encrypted
: [Client 1073699420] client_send_encrypted
size=27
14:11:51.513 -> >>> HomeKit: WiFiServer receives a new client (current 1, max 8)
14:11:51.513 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.213:56194
14:11:51.513 -> >>> HomeKit: [Client 1073700276] Got client content from the cache 1
14:11:51.513 -> >>> HomeKit: [Client 1073700276] new client accepted
14:11:51.555 -> >>> homekit_client_process: [Client 1073700276] Reading 142 bytes
14:11:51.555 -> >>> homekit_server_on_message_complete: http_parser message_complete
14:11:51.555 -> >>> homekit_server_on_message_complete: Unknown endpoint
14:11:51.555 -> >>> client_send: [Client 1073700276] send data size=26, encrypted=false
14:11:51.555 -> >>> client_send: [Client 1073700276] Sending payload: HTTP/1.1 404 Not Found\x0D\x0A\x0D\x0A
14:12:21.322 -> >>> homekit_client_process: [Client 1073699420] Reading 188 bytes
14:12:21.322 -> >>> homekit_client_process: [Client 1073699420] Decrypted 170 bytes, available 0
14:12:21.322 -> Decrypted data (170 bytes): "PUT /characteristics HTTP/1.1\x0D\x0AHost: ES-B1E8._hap._tcp.local\x0D\x0AContent-Length: 50\x0D\x0AContent-Type: application/hap+json\x0D\x0A\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"value":0}]}"
14:12:31.793 -> >>> HomeKit: [Client 1073699420] Disconnected!
14:12:36.805 -> >>> HomeKit: [Client 1073699420] Closing client connection
14:12:36.805 -> >>> homekit_server_close_client: [Client 1073699420] The sockect is stoped
14:12:36.805 -> >>> HomeKit: [Client 0] client content free
14:12:58.156 -> >>> HomeKit: WiFiServer receives a new client (current 1, max 8)
14:12:58.156 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.13:58495
14:12:58.231 -> >>> HomeKit: [Client 1073700644] Got client content from the cache 0
14:12:58.231 -> >>> HomeKit: [Client 1073700644] new client accepted
14:12:58.231 -> >>> homekit_client_process: [Client 1073700644] Reading 158 bytes
14:13:59.555 -> >>> HomeKit: [Client 1073700644] Disconnected!
14:13:59.555 -> >>> HomeKit: WiFiServer receives a new client (current 2, max 8)
14:13:59.555 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.13:58568
14:13:59.555 -> >>> HomeKit: [Client 1073699356] Got client content from the cache 2
14:13:59.555 -> >>> HomeKit: [Client 1073699356] new client accepted
14:13:59.555 -> >>> homekit_client_process: [Client 1073699356] Reading 158 bytes
14:14:03.191 -> >>> HomeKit: [Client 1073700644] Closing client connection
14:14:03.191 -> >>> homekit_server_close_client: [Client 1073700644] The sockect is stoped
14:14:03.191 -> >>> HomeKit: [Client 0] client content free
14:14:58.197 -> >>> HomeKit: [Client 1073699356] Disconnected!
14:15:03.198 -> >>> HomeKit: [Client 1073699356] Closing client connection
14:15:03.198 -> >>> homekit_server_close_client: [Client 1073699356] The sockect is stoped
14:15:03.198 -> >>> HomeKit: [Client 0] client content free

@Yurik72
Copy link
Owner

Yurik72 commented Feb 28, 2021 via email

@eford321
Copy link
Contributor Author

Sorry, I meant to check which commit. The log was from c822ae8. I just recompiled with 1f3a5cb
and the behavior is the same.

@Yurik72
Copy link
Owner

Yurik72 commented Feb 28, 2021 via email

@EIBHomeControl
Copy link
Contributor

Same behavior here. Tested with the lastet version.

@Yurik72
Copy link
Owner

Yurik72 commented Mar 1, 2021

I'm trust you however can't reproduce and need your explanation

  1. I can't understnad at all why is https://github.com/homebridge/homebridge impacted on esp8266. You have been restarted this one, means it lost and establish connection again to your Apple Home (apple hub or apple tv) but, why is related to connection between esp and apple tv. Because i did't use a HomeBridge, maybe short explanation will be helpfull

  2. What i see in the logs
    14:13:59.555 -> >>> homekit_client_process: [Client 1073699356] Reading 158 bytes
    14:14:03.191 -> >>> HomeKit: [Client 1073700644] Closing client connection

ESP trying to read 158 bytes from the socket, and ( due to not other records) after 3.5 secs it was unsuccessfull WiFiClient.connected()==false. Meand TCP state !=established. I can imagine that ESP get a packet from remote host
WiFiClient.available() returns 158 bytes.
Next line is
WiFiClient.read()
means ESP TCP socket/buffer must be readed and ACK must be sent to remote host ,

What happens in the reality i don't know without network sniffers....

I found very similar issues, but they are not the same, howere advice is to put yield(), to break loop for background processes,
I did this, therefore you can try latest commit.
As weel any ideas appreciated

@eford321
Copy link
Contributor Author

eford321 commented Mar 1, 2021

Same result with 4ff7540.

I am trying to gather more information from my homebridge. I have to be careful not to mess up my configuration and lose 33 devices running on the bridge.

I can't understnad at all why is https://github.com/homebridge/homebridge impacted on esp8266. You have been restarted this one, means it lost and establish connection again to your Apple Home (apple hub or apple tv) but, why is related to connection between esp and apple tv. Because i did't use a HomeBridge, maybe short explanation will be helpfull

My guess is the bridge connects to ESPHap as a client to allow communications from bridged devices.

I wonder why ESPHap is losing connections with all clients after homebridge tries to reconnect.

Here is the reconnection:

09:42:32.006 -> >>> HomeKit: WiFiServer receives a new client (current 2, max 8)
09:42:32.006 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.213:43492
09:42:32.006 -> >>> HomeKit: [Client 1073701172] Got client content from the cache 2
09:42:32.006 -> >>> HomeKit: [Client 1073701172] new client accepted
09:42:32.121 -> >>> homekit_client_process: [Client 1073701172] Reading 142 bytes
09:42:32.121 -> >>> homekit_server_on_message_complete: http_parser message_complete

09:42:32.121 -> >>> homekit_server_on_message_complete: Unknown endpoint

09:42:32.121 -> >>> client_send: [Client 1073701172] send data size=26, encrypted=false
09:42:32.121 -> >>> client_send: [Client 1073701172] Sending payload: HTTP/1.1 404 Not Found\x0D\x0A\x0D\x0A
09:42:46.162 -> >>> HomeKit: [Client 1073701172] Disconnected!
09:42:51.198 -> >>> HomeKit: [Client 1073701172] Closing client connection
09:42:51.198 -> >>> homekit_server_close_client: [Client 1073701172] The sockect is stoped
09:42:51.198 -> >>> HomeKit: [Client 0] client content free
09:43:02.814 -> >>> HomeKit: WiFiServer receives a new client (current 2, max 8)
09:43:02.814 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.213:43774
09:43:02.814 -> >>> HomeKit: [Client 1073700708] Got client content from the cache 2
09:43:02.934 -> >>> HomeKit: [Client 1073700708] new client accepted
09:43:02.934 -> >>> homekit_client_process: [Client 1073700708] Reading 142 bytes
09:43:12.851 -> >>> HomeKit: [Client 1073700708] Disconnected!

Then I try to turn the LED off from the home app on my Mac, and it fails with "no response"

09:43:14.793 -> >>> homekit_client_process: [Client 1073699812] Reading 188 bytes
09:43:14.793 -> >>> homekit_client_process: [Client 1073699812] Decrypted 170 bytes, available 0
09:43:14.793 -> Decrypted data (170 bytes): "PUT /characteristics HTTP/1.1\x0D\x0AHost: ES-B1E8._hap._tcp.local\x0D\x0AContent-Length: 50\x0D\x0AContent-Type: application/hap+json\x0D\x0A\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"value":0}]}"
09:43:17.868 -> >>> HomeKit: [Client 1073700708] Closing client connection
09:43:17.868 -> >>> homekit_server_close_client: [Client 1073700708] The sockect is stoped
09:43:17.868 -> >>> HomeKit: [Client 0] client content free
09:43:24.830 -> >>> HomeKit: [Client 1073699812] Disconnected!
09:43:29.831 -> >>> HomeKit: [Client 1073699812] Closing client connection
09:43:29.831 -> >>> homekit_server_close_client: [Client 1073699812] The sockect is stoped
09:43:29.831 -> >>> HomeKit: [Client 0] client content free

@Yurik72
Copy link
Owner

Yurik72 commented Mar 1, 2021 via email

@Yurik72
Copy link
Owner

Yurik72 commented Mar 1, 2021 via email

@eford321
Copy link
Contributor Author

eford321 commented Mar 1, 2021 via email

@eford321
Copy link
Contributor Author

eford321 commented Mar 1, 2021

More info. It appears homebridge does some type of status requests of each HAP device discovered via bonjour. Homebridge does keep active sessions with the homekit hub and alternate hubs. It does not keep sessions connected to any other homekit devices.

When it statuses ESPHap,

09:42:32.121 -> >>> homekit_client_process: [Client 1073701172] Reading 142 bytes
09:42:32.121 -> >>> homekit_server_on_message_complete: http_parser message_complete
09:42:32.121 -> >>> homekit_server_on_message_complete: Unknown endpoint

ESPHap returns 404 and disconnects

09:42:32.121 -> >>> client_send: [Client 1073701172] send data size=26, encrypted=false
09:42:32.121 -> >>> client_send: [Client 1073701172] Sending payload: HTTP/1.1 404 Not Found\x0D\x0A\x0D\x0A
09:42:46.162 -> >>> HomeKit: [Client 1073701172] Disconnected!

Something breaks and all reconnects from homebridge or other clients fail and aren't parsed?

09:43:02.814 -> >>> HomeKit: WiFiServer receives a new client (current 2, max 8)
09:43:02.814 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.213:43774
09:43:02.814 -> >>> HomeKit: [Client 1073700708] Got client content from the cache 2
09:43:02.934 -> >>> HomeKit: [Client 1073700708] new client accepted
09:43:02.934 -> >>> homekit_client_process: [Client 1073700708] Reading 142 bytes
09:43:12.851 -> >>> HomeKit: [Client 1073700708] Disconnected!
09:43:14.793 -> >>> homekit_client_process: [Client 1073699812] Reading 188 bytes
09:43:14.793 -> >>> homekit_client_process: [Client 1073699812] Decrypted 170 bytes, available 0
09:43:14.793 -> Decrypted data (170 bytes): "PUT /characteristics HTTP/1.1\x0D\x0AHost: ES-B1E8._hap._tcp.local\x0D\x0AContent-Length: 50\x0D\x0AContent-Type: application/hap+json\x0D\x0A\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"value":0}]}"
09:43:17.868 -> >>> HomeKit: [Client 1073700708] Closing client connection
09:43:17.868 -> >>> homekit_server_close_client: [Client 1073700708] The sockect is stoped
09:43:17.868 -> >>> HomeKit: [Client 0] client content free
09:43:24.830 -> >>> HomeKit: [Client 1073699812] Disconnected!
09:43:29.831 -> >>> HomeKit: [Client 1073699812] Closing client connection
09:43:29.831 -> >>> homekit_server_close_client: [Client 1073699812] The sockect is stoped
09:43:29.831 -> >>> HomeKit: [Client 0] client content free

@eford321
Copy link
Contributor Author

eford321 commented Mar 1, 2021

Is there a way to capture/debug the http request coming from homebridge?

@Yurik72
Copy link
Owner

Yurik72 commented Mar 1, 2021 via email

@Yurik72
Copy link
Owner

Yurik72 commented Mar 1, 2021 via email

@eford321
Copy link
Contributor Author

eford321 commented Mar 1, 2021

From looking at Wireshark captures, Homebridge does not connect to ESP. It appears homebridge sends an MDNS query when it is restarted. ESPHap doesn't respond to this query, does say the following:

15:20:20.365 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.213:37292
15:20:20.402 -> >>> HomeKit: [Client 1073699420] Got client content from the cache 0
15:20:20.402 -> >>> HomeKit: [Client 1073699420] new client accepted

ESP doesn't respond, but my other homekit devices do. Here is the packet:
Screen Shot 2021-03-01 at 3 34 36 PM

@eford321
Copy link
Contributor Author

eford321 commented Mar 1, 2021

Captured again and do so see ESP responding. This is the only communications I see between ESP and homebridge.....
Screen Shot 2021-03-01 at 4 11 28 PM

Yurik72 added a commit that referenced this issue Mar 2, 2021
Yurik72 added a commit that referenced this issue Mar 2, 2021
@Yurik72
Copy link
Owner

Yurik72 commented Mar 2, 2021

Hi All,
I hope i see a light at the end of the tunnel :)
Thanks for your help and logs. Now i want to explain my understanding what is happening.

When your home bridge is restarted it always send http request to the ESP. HTTP request is wrong (from Apple communication point of view). But maybe I'm wrong and ESP should reply some correct answers
Currently reply is HTPP 404....

So, what i did. Due to I do not have proper instance of HomeBridge with all plugins, I'm trying to simulate this from normal browser by putting URL http://192.168.88.14:5556/blablabla, where 192.168.88.14 is IP address of my ESP (/blablabla is wrong query). And defintelly by killing ESP by such request my ESP some times is not available (No response) for normal Apple devices.. Hovewer is not always....

What i did. In case of wrong request, now I still send HTTP404 response , than immediatelly disconnect. As well if new request comming at this moment from the same IP address, i simple do not accept them

Simulating this from normal browser shows much improves and my ESP is always reliable

So, you can try latest commits.

If situation will be reproduced again, you can help me by explanation what kind of request is send by HomeBridge and probably what kind of response should be instead of 404, probably normal Apple devices sending something other

As well as the next attempts, we can try to ignore any request from HomeBridge if previous doesn't help
It can be easilly done by checking IP address, i have prepared and commented a few lines for that
See arduino_homekit_server.cpp line 3622
If this will help I will try to find proper solution

@Yurik72
Copy link
Owner

Yurik72 commented Mar 2, 2021

Small additions to previous. Official docs says about allowed command and responses
hap_http

@eford321
Copy link
Contributor Author

eford321 commented Mar 2, 2021 via email

@eford321
Copy link
Contributor Author

eford321 commented Mar 2, 2021

Still failing with 1583e16. Here is the trace showing the response from ESP and also a Leviton homekit switch for comparison. Note the Leviton also sends IPv6, since it can't be configured to only use IPv4.
Screen Shot 2021-03-02 at 9 29 39 AM

Detailed ESP response:
Screen Shot 2021-03-02 at 9 33 03 AM

Detailed Leviton response:
Screen Shot 2021-03-02 at 9 33 50 AM

@Yurik72
Copy link
Owner

Yurik72 commented Mar 2, 2021 via email

@eford321
Copy link
Contributor Author

eford321 commented Mar 2, 2021

black list? not sure what you mean.

The only traffic from homebridge is the mdns query.

The response seems to be ok, the problem is the ESP doesn't recover after the response.

Any idea why ESP goes unresponsive for all clients after the homebridge QM query?

@EIBHomeControl
Copy link
Contributor

EIBHomeControl commented Mar 2, 2021

Just set my homebridge to the blscklist. Seems to work. After a restart of the homebridge the device is still running.

@eford321 see line 3622 at arduino_homekit_server.cpp

@eford321
Copy link
Contributor Author

eford321 commented Mar 2, 2021

gotcha! @EIBHomeControl

What format are you using for the IP address for xxxx? I can't get it to compile.

Yurik72 added a commit that referenced this issue Mar 2, 2021
@Yurik72
Copy link
Owner

Yurik72 commented Mar 2, 2021 via email

@eford321
Copy link
Contributor Author

eford321 commented Mar 2, 2021

Compile problem is with client info line..
Using:

String yourIP = "192.168.1.213"; // IP Bridge
if(wifiClient->remoteIP().toString() ==yourIP) // this is a bridge
{
CLIENT_INFO(ct, "Home bridge IGNORED");
wifiClient->stop();
delete wifiClient;
return NULL;

}

Getting the following compilation errors:

Arduino: 1.8.13 (Mac OS X), Board: "LOLIN(WEMOS) D1 R2 & mini, 80 MHz, Flash, Legacy (new can return nullptr), Basic SSL ciphers (lower ROM use), 4MB (FS:2MB OTA:~1019KB), v2 Lower Memory, Serial, None, Only Sketch, 921600"

In file included from /Users/evan/Documents/Arduino/libraries/ESPHap/arduino_homekit_server.cpp:30:0:
/Users/evan/Documents/Arduino/libraries/ESPHap/arduino_homekit_server.cpp: In function 'client_context_t* homekit_server_accept_client(homekit_server_t*)':
/Users/evan/Documents/Arduino/libraries/ESPHap/arduino_homekit_server.cpp:3628:15: error: 'ct' was not declared in this scope
CLIENT_INFO(ct, "Home bridge IGNORED");
^
/Users/evan/Documents/Arduino/libraries/ESPHap/debug.h:27:75: note: in definition of macro 'INFO'
#define INFO(message, ...) printf_P(PSTR(">>> HomeKit: " message "\n"), ##VA_ARGS)
^
/Users/evan/Documents/Arduino/libraries/ESPHap/arduino_homekit_server.cpp:3628:3: note: in expansion of macro 'CLIENT_INFO'
CLIENT_INFO(ct, "Home bridge IGNORED");
^
exit status 1
Error compiling for board LOLIN(WEMOS) D1 R2 & mini.

@eford321
Copy link
Contributor Author

eford321 commented Mar 2, 2021

Changed to

String yourIP = "192.168.1.213"; // IP Bridge
if(wifiClient->remoteIP().toString() ==yourIP) // this is a bridge
{
//CLIENT_INFO(ct, "Home bridge IGNORED");
Serial.println("Home bridge IGNORED");
wifiClient->stop();
delete wifiClient;
return NULL;
}

Ran with the following log. ESP does continue functioning after Query from Homebridge.

3:02:35.001 -> init_hap_storage>>> HomeKit: init_storage_ex size 0x1c1
13:02:35.001 -> >>> Home Integration: hap_services added chararacteristic 0: 23
13:02:35.001 -> >>> Home Integration: hap_services added chararacteristic 1: 25
13:02:35.001 -> >>> Home Integration: homekit_is_paired 1
13:02:35.001 -> >>> HomeKit: Free heap: 31960
13:02:35.001 -> >>> server_new: WiFiServer begin at port: 5556
13:02:35.001 ->
13:02:35.001 -> >>> HomeKit: Starting server
13:02:35.034 -> >>> HomeKit: storage init 0
13:02:35.034 -> >>> HomeKit: Using existing accessory ID: B1:E8:4D:32:98:71
13:02:35.034 -> >>> HomeKit: find pairings
13:02:35.034 -> >>> HomeKit: Found admin pairing with 6FDD5BE0-78E1-4A4C-B5D7-98277EEFA239, disabling pair setup
13:02:35.034 -> >>> HomeKit: Configuring mDNS
13:02:35.034 -> >>> HomeKit: MDNS.begin: ES-B1E8, IP: 192.168.1.23
13:02:35.034 -> >>> homekit_mdns_init: Accessory Setup ID = YK72
13:02:35.068 -> >>> HomeKit: Init server over
13:02:42.521 -> pm open,type:2 0
13:03:09.605 -> >>> HomeKit: WiFiServer receives a new client (current 0, max 8)
13:03:09.605 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.213:37760
13:03:09.605 -> Home bridge IGNORED
13:03:16.631 -> >>> HomeKit: WiFiServer receives a new client (current 0, max 8)
13:03:16.631 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.13:64000
13:03:16.631 -> >>> HomeKit: [Client 1073699020] Got client content from the cache 0
13:03:16.668 -> >>> HomeKit: [Client 1073699020] new client accepted
13:03:16.668 -> >>> homekit_client_process: [Client 1073699020] Reading 158 bytes
13:03:16.668 -> >>> homekit_server_on_message_complete: http_parser message_complete
13:03:16.668 -> >>> homekit_server_on_pair_verify: HomeKit Pair Verify
13:03:16.668 -> >>> homekit_server_on_pair_verify: Free heap: 24536
13:03:16.668 -> >>> tlv_debug: Got following TLV values:
13:03:16.668 -> >>> tlv_debug: Type 6 value (1 bytes): \x01
13:03:16.701 -> >>> tlv_debug: Type 3 value (32 bytes): =+t**UX\xD3\xE1\xA6\xCE\x93\x90\xE9\x9F\x80Y\xC4<"a\xDC)\x85\xB2\x01\xE5\xF7\x8B\x82\xCEl
13:03:16.701 -> >>> HomeKit: [Client 1073699020] Pair Verify Step 1/2
13:03:16.701 -> >>> homekit_server_on_pair_verify: [Client 1073699020] Importing device Curve25519 public key
13:03:16.701 -> >>> homekit_server_on_pair_verify: [Client 1073699020] Generating accessory Curve25519 key
13:03:16.840 -> >>> homekit_server_on_pair_verify: [Client 1073699020] Exporting accessory Curve25519 public key
13:03:16.840 -> >>> homekit_server_on_pair_verify: [Client 1073699020] Generating Curve25519 shared secret
13:03:16.980 -> >>> homekit_server_on_pair_verify: [Client 1073699020] Generating signature
13:03:17.054 -> >>> homekit_server_on_pair_verify: [Client 1073699020] Generating proof
13:03:17.054 -> >>> homekit_server_on_pair_verify: [Client 1073699020] Encrypting response
13:03:17.091 -> >>> send_tlv_response: [Client 1073699020] Sending TLV response
13:03:17.091 -> >>> tlv_debug: Got following TLV values:
13:03:17.091 -> >>> tlv_debug: Type 6 value (1 bytes): \x02
13:03:17.091 -> >>> tlv_debug: Type 3 value (32 bytes): \x84\x0D\x0C\xF4\x95\xEA\xD7g\xA3\xFE\xD2\xEA+\x96\xCB \x81Y\xE2V\x91\x08\x93bDE\x99-\xB2\x8B( 13:03:17.091 -> >>> tlv_debug: Type 5 value (101 bytes): y\xB2\x0D\x13E@\x0B\x9Ep\x86<\xBE]\xE4\xCD\xEE\xAF?~\x91\xD4HS\xD4\x8E\xFA\xCBN\x1A\x91\xA3\x1C\x08\x84I\xEAZar\xDDq\xEE\xB2Ad\xA8a\xF1\xAAx\x10v\xDA\xC5$hq\x18k1\xD1s\xE5\xC8\x1DI5\x0D,\xE0\x01\xB6\xD0G4\xF3\x87\x95\x15\x9Aun\x8E\xFFecV\xDAsp\xEA(\xC3\xE2\xB3%\x15{>
13:03:17.124 -> >>> client_send: [Client 1073699020] send data size=244, encrypted=false
13:03:17.124 -> >>> client_send: [Client 1073699020] 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\x02\x03 \x84\x0D\x0C\xF4\x95\xEA\xD7g\xA3\xFE\xD2\xEA+\x96\xCB \x81Y\xE2V\x91\x08\x93bDE\x99-\xB2\x8B(\x05ey\xB2\x0D\x13E@\x0B\x9Ep\x86<\xBE]\xE4\xCD\xEE\xAF?~\x91\xD4HS\xD4\x8E\xFA\xCBN\x1A\x91\xA3\x1C\x08\x84I\xEAZar\xDDq\xEE\xB2Ad\xA8a\xF1\xAAx\x10v\xDA\xC5$hq\x18k1\xD1s\xE5\xC8\x1DI5\x0D,\xE0\x01\xB6\xD0G
4\xF3\x87\x95\x15\x9Aun\x8E\xFFecV\xDAsp\xEA(\xC3\xE2\xB3%\x15{>
13:03:17.246 -> >>> HomeKit: Free heap: 24296
13:03:17.246 -> >>> homekit_client_process: [Client 1073699020] Reading 247 bytes
13:03:17.246 -> >>> homekit_server_on_message_complete: http_parser message_complete
13:03:17.246 -> >>> homekit_server_on_pair_verify: HomeKit Pair Verify
13:03:17.246 -> >>> homekit_server_on_pair_verify: Free heap: 24208
13:03:17.246 -> >>> tlv_debug: Got following TLV values:
13:03:17.246 -> >>> tlv_debug: Type 5 value (120 bytes): \xB0\x02\xB4\x8EW\xF4\xA2\x8FNs\xD9\xC2\x9E?$n3\xEB\xFC\x1BDu\xCA\x8Bf\xEC/$\xA2\x06a2\xC04\x00\xC0\xD0\x94\xD05\x13\xB6&\x1D\xD2m\x14{-K\x9C\x92b\x0Ah\xBE\x15\xC4\xF4P\x9E\xFB\x0Fk3h\x00\xC3-\xF8qL\x8A\xD3\xD8\x85\xFE\xF6\xB9\xD89\xFC{�\x82hX\xF7\xAB\xFF\xE1\x85\xFC\x92\xC1s\xD1\xCFl\x90gat\xED\xBE\x80\xEE\xA1\xD7\xF3\x9C\x8E\x03\x1Cb9m^\xBC\x84
13:03:17.246 -> >>> tlv_debug: Type 6 value (1 bytes): \x03
13:03:17.246 -> >>> HomeKit: [Client 1073699020] Pair Verify Step 2/2
13:03:17.301 -> >>> homekit_server_on_pair_verify: [Client 1073699020] Decrypting payload
13:03:17.301 -> >>> homekit_server_on_pair_verify: [Client 1073699020] Searching pairing with 6FDD5BE0-78E1-4A4C-B5D7-98277EEFA239
13:03:17.301 -> >>> HomeKit: [Client 1073699020] Found pairing with 6FDD5BE0-78E1-4A4C-B5D7-98277EEFA239
13:03:17.301 -> >>> homekit_server_on_pair_verify: [Client 1073699020] Verifying device signature
13:03:18.054 -> >>> send_tlv_response: [Client 1073699020] Sending TLV response
13:03:18.054 -> >>> tlv_debug: Got following TLV values:

@eford321
Copy link
Contributor Author

eford321 commented Mar 2, 2021

One query response from ESP...
Screen Shot 2021-03-02 at 1 08 58 PM

@eford321
Copy link
Contributor Author

eford321 commented Mar 4, 2021

My questions are
2. What kind of http request is sends by Hopmebridge to ESP, can you get it captured from WireShark ?

I don't see http from Homebridge to ESP, only MDNS QM. There is no unicast traffic to/from homebridge & ESP. Only the multicast QM message. Is ESP interpreting this as http?

Here is the Wireshark capture of the QM request:
Screen Shot 2021-03-04 at 10 00 37 AM

@Yurik72
Copy link
Owner

Yurik72 commented Mar 4, 2021 via email

@Yurik72
Copy link
Owner

Yurik72 commented Mar 4, 2021 via email

@eford321
Copy link
Contributor Author

eford321 commented Mar 4, 2021

But this is definitely good news and my first assumption that HTTP request from Homebridge to ESP killing ESP. Maybe is not HTTP but request came to Homekit port Otherwise I do not see any other problem for instance mDNS. You can help me by capturing exact HTTP request by wireshark, it will save my time. Is that possible ? As well I recently committed additional traces Please uncomment them line 3507 and send me a result after HomeBridge restarting , it will capture all requests coming to _hap port Thanks in advance

I assume it is being passed to homekit port, because Homebridge is asking for _hap._tcp.local devices.
Do you want the raw frame? Sorry I clipped it earlier.
Screen Shot 2021-03-04 at 9 55 52 AM

Here is the trace with new commit. line 3507 in arduino_homekit_server.cpp is uncommented.

12:20:09.819 -> init_hap_storage>>> HomeKit: init_storage_ex size 0x1c1
12:20:09.855 -> >>> Home Integration: hap_services added chararacteristic 0: 23
12:20:09.855 -> >>> Home Integration: hap_services added chararacteristic 1: 25
12:20:09.855 -> >>> Home Integration: homekit_is_paired 1
12:20:09.855 -> >>> HomeKit: Free heap: 32576
12:20:09.855 -> >>> server_new: WiFiServer begin at port: 5556
12:20:09.855 ->
12:20:09.855 -> >>> HomeKit: Starting server
12:20:09.855 -> >>> HomeKit: storage init 0
12:20:09.855 -> >>> HomeKit: Using existing accessory ID: B1:E8:4D:32:98:71
12:20:09.855 -> >>> HomeKit: find pairings
12:20:09.893 -> >>> HomeKit: Found admin pairing with 6FDD5BE0-78E1-4A4C-B5D7-98277EEFA239, disabling pair setup
12:20:09.893 -> >>> HomeKit: Configuring mDNS
12:20:09.893 -> >>> HomeKit: Wifi Sleep type:2
12:20:09.893 -> >>> HomeKit: Set Wifi Sleep type :0
12:20:09.893 -> >>> HomeKit: MDNS.begin: ES-B1E8, IP: 192.168.1.23
12:20:09.893 -> >>> homekit_mdns_init: Accessory Setup ID = YK72
12:20:09.893 -> >>> HomeKit: Init server over
12:20:12.068 -> >>> HomeKit: WiFiServer receives a new client (current 0, max 8)
12:20:12.068 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.13:57300
12:20:12.068 -> >>> HomeKit: [Client 1073697532] Got client content from the cache 0
12:20:12.102 -> >>> HomeKit: [Client 1073697532] new client accepted
12:20:12.102 -> >>> homekit_client_process: [Client 1073697532] Reading 158 bytes
12:20:12.102 -> >>> homekit_server_on_message_complete: http_parser message_complete
12:20:12.102 -> >>> homekit_server_on_pair_verify: HomeKit Pair Verify
12:20:12.102 -> >>> homekit_server_on_pair_verify: Free heap: 26288
12:20:12.138 -> >>> tlv_debug: Got following TLV values:
12:20:12.138 -> >>> tlv_debug: Type 6 value (1 bytes): \x01
12:20:12.138 -> >>> tlv_debug: Type 3 value (32 bytes): \xE4:\x0AY\x8ED"\xD7\xF8\xDF\x17\xC9a\x1C6\x0D\xC518\xF8\xE3\xF4\x94]H\x80\x9D\xC3\x81\xA8\xECy
12:20:12.138 -> >>> HomeKit: [Client 1073697532] Pair Verify Step 1/2
12:20:12.138 -> >>> homekit_server_on_pair_verify: [Client 1073697532] Importing device Curve25519 public key
12:20:12.138 -> >>> homekit_server_on_pair_verify: [Client 1073697532] Generating accessory Curve25519 key
12:20:12.282 -> >>> homekit_server_on_pair_verify: [Client 1073697532] Exporting accessory Curve25519 public key
12:20:12.282 -> >>> homekit_server_on_pair_verify: [Client 1073697532] Generating Curve25519 shared secret
12:20:12.421 -> >>> homekit_server_on_pair_verify: [Client 1073697532] Generating signature
12:20:12.495 -> >>> homekit_server_on_pair_verify: [Client 1073697532] Generating proof
12:20:12.495 -> >>> homekit_server_on_pair_verify: [Client 1073697532] Encrypting response
12:20:12.495 -> >>> send_tlv_response: [Client 1073697532] Sending TLV response
12:20:12.532 -> >>> tlv_debug: Got following TLV values:
12:20:12.532 -> >>> tlv_debug: Type 6 value (1 bytes): \x02
12:20:12.532 -> >>> tlv_debug: Type 3 value (32 bytes): \xC3fC\xFC\xDBeS\xF9_\xAB\xA7\xBA \x06 \x97\xEFU\x91\x0C\xFB\xF7\x98\x99E0\xE5\xE0\x95g\xCE/
12:20:12.532 -> >>> tlv_debug: Type 5 value (101 bytes): \x8Ca\xEF#Q\xA3\xD68V>V\x0D6\xF5M>\xC5m\x11\xE8\x1E\xF2&\xCA\x92\x1B\x8D\x9E\x0B8\xBF\xB5!Thh*\xC6\xDE\xD6\xD2\xC9\xF3]p\xB3\x82\xECu\x93\x1AJM\x07\xE6\xB1k>L\xCB^K\xD9\xA4\x82\xA7\x18\xBD/aYt\xD1\x11b\x94\x08\x17\x17\x13?\xD8\xBF\xE8\xBAdp\xC0PF\x00\x95k\x12[ I#]I 12:20:12.569 -> >>> client_send: [Client 1073697532] send data size=244, encrypted=false 12:20:12.569 -> >>> client_send: [Client 1073697532] 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\x02\x03 \xC3fC\xFC\xDBeS\xF9_\xAB\xA7\xBA \x06 \x97\xEFU\x91\x0C\xFB\xF7\x98\x99E0\xE5\xE0\x95g\xCE/\x05e\x8Ca\xEF#Q\xA3\xD68V>V\x0D6\xF5M>\xC5m\x11\xE8\x1E\xF2&\xCA\x92\x1B\x8D\x9E\x0B8\xBF\xB5!Thh*\xC6\xDE\xD6\xD2\xC9\xF3]p\xB3\x82\xECu\x93\x1AJM\x07\xE6\xB1k>L\xCB^K\xD9\xA4\x82\xA7\x18\xBD/aYt\xD1\x11b\x94\x08\x17\x17\x13?\xD8\xBF\xE8\xBAdp\xC0PF\x00\x95k\x12[ I#]I
12:20:12.640 -> >>> HomeKit: Free heap: 25944
12:20:12.640 -> >>> HomeKit: WiFiServer receives a new client (current 1, max 8)
12:20:12.640 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.37:54753
12:20:12.640 -> >>> HomeKit: [Client 1073697892] Got client content from the cache 1
12:20:12.671 -> >>> HomeKit: [Client 1073697892] new client accepted
12:20:12.671 -> >>> homekit_client_process: [Client 1073697892] Reading 158 bytes
12:20:12.671 -> >>> homekit_server_on_message_complete: http_parser message_complete
12:20:12.671 -> >>> homekit_server_on_pair_verify: HomeKit Pair Verify
12:20:12.671 -> >>> homekit_server_on_pair_verify: Free heap: 25816
12:20:12.671 -> >>> tlv_debug: Got following TLV values:
12:20:12.705 -> >>> tlv_debug: Type 6 value (1 bytes): \x01
12:20:12.705 -> >>> tlv_debug: Type 3 value (32 bytes): \xB02\x9E\xE2p\xDC'U.\x10\xCCm\xE2;\xD0\xC9E\x8A\x95\x98\xB9\xCE\xFC\xA0a\x9A\xE5mn<g\x14
12:20:12.705 -> >>> HomeKit: [Client 1073697892] Pair Verify Step 1/2
12:20:12.705 -> >>> homekit_server_on_pair_verify: [Client 1073697892] Importing device Curve25519 public key
12:20:12.705 -> >>> homekit_server_on_pair_verify: [Client 1073697892] Generating accessory Curve25519 key
12:20:12.853 -> >>> homekit_server_on_pair_verify: [Client 1073697892] Exporting accessory Curve25519 public key
12:20:12.853 -> >>> homekit_server_on_pair_verify: [Client 1073697892] Generating Curve25519 shared secret
12:20:13.003 -> >>> homekit_server_on_pair_verify: [Client 1073697892] Generating signature
12:20:13.072 -> >>> homekit_server_on_pair_verify: [Client 1073697892] Generating proof
12:20:13.072 -> >>> homekit_server_on_pair_verify: [Client 1073697892] Encrypting response
12:20:13.072 -> >>> send_tlv_response: [Client 1073697892] Sending TLV response
12:20:13.072 -> >>> tlv_debug: Got following TLV values:
12:20:13.072 -> >>> tlv_debug: Type 6 value (1 bytes): \x02
12:20:13.109 -> >>> tlv_debug: Type 3 value (32 bytes): s\xB2\x89$#[)\xFC"\xE9\x90\xB5C\xF6\xE7\xA6\xAF\xA2\xDC\xDD>\xA0e{#\xB34\xC9\x16\xBD\x12\x12
12:20:13.109 -> >>> tlv_debug: Type 5 value (101 bytes): -\xC4]\x1E\xC8\x8EPXE\xD0\x19\xE1\xD6w[ae^+Wy\x01(ZU>\xC2\xBA\xDER\x91\xB4t\xA2\x8FI\xE84+[7\x0Dp\x12\x0D\x177\xE4\x12\xF6^\xEA\x89\x1CT?Q\x15?\x99LJY\x99\xB7\x87.\xE0\x0E\x85[\x9BC\x87>.\xAD6\x9C\xB0\x89\x8A\x08\xEE\xC3\x0E8\x17p\xE3\xB5\xF1\x80\xD4E\x90\xE8\x10\xBC=
12:20:13.146 -> >>> client_send: [Client 1073697892] send data size=244, encrypted=false
12:20:13.146 -> >>> client_send: [Client 1073697892] 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\x02\x03 s\xB2\x89$#[)\xFC"\xE9\x90\xB5C\xF6\xE7\xA6\xAF\xA2\xDC\xDD>\xA0e{#\xB34\xC9\x16\xBD\x12\x12\x05e-\xC4]\x1E\xC8\x8EPXE\xD0\x19\xE1\xD6w[ae^+Wy\x01(ZU>\xC2\xBA\xDER\x91\xB4t\xA2\x8FI\xE84+[7\x0Dp\x12\x0D\x177\xE4\x12\xF6^\xEA\x89\x1CT?Q\x15?\x99LJY\x99\xB7\x87.\xE0\x0E\x85[
\x9BC\x87>.\xAD6\x9C\xB0\x89\x8A\x08\xEE\xC3\x0E8\x17p\xE3\xB5\xF1\x80\xD4E\x90\xE8\x10\xBC=
12:20:13.289 -> >>> HomeKit: Free heap: 25936
12:20:13.289 -> >>> homekit_client_process: [Client 1073697532] Reading 247 bytes
12:20:13.289 -> >>> homekit_server_on_message_complete: http_parser message_complete
12:20:13.289 -> >>> homekit_server_on_pair_verify: HomeKit Pair Verify
12:20:13.327 -> >>> homekit_server_on_pair_verify: Free heap: 26176
12:20:13.327 -> >>> tlv_debug: Got following TLV values:
12:20:13.327 -> >>> tlv_debug: Type 5 value (120 bytes): \xEE\xB8\x99\xE6y\x82\x1F\x0C\xAF"[\xAB\xA4x\x03\x81\xD7B\xF1\xB0\x8D!\xFF\xBA\xC8\x0F\xEEB{h\xF7\xDA\xCE\xDB\x1CD\xF1\xF2\xA1\x0B\x82\xD1\xE5\x8D\xB6y\x0FL\xFA\xCB\x0E\xBA\x99\x1F\x8C\x994\x05\xF0\x1B\xB44\x19C\x0C\xD7\x8A\xE5\xD7\xB2\x99\xE52\x9FR\xED\xF3\xF4\xCA\xCB{o#\xACu\xB0>\x05o\xD1\x19\x13\x14$e\x1B,D\xF2\x07v$h\x8Au%u\xCF\x10\x9C\x05<\x83\xBB\xE2r_\xFB
12:20:13.364 -> >>> tlv_debug: Type 6 value (1 bytes): \x03
12:20:13.364 -> >>> HomeKit: [Client 1073697532] Pair Verify Step 2/2
12:20:13.364 -> >>> homekit_server_on_pair_verify: [Client 1073697532] Decrypting payload
12:20:13.364 -> >>> homekit_server_on_pair_verify: [Client 1073697532] Searching pairing with 6FDD5BE0-78E1-4A4C-B5D7-98277EEFA239
12:20:13.364 -> >>> HomeKit: [Client 1073697532] Found pairing with 6FDD5BE0-78E1-4A4C-B5D7-98277EEFA239
12:20:13.402 -> >>> homekit_server_on_pair_verify: [Client 1073697532] Verifying device signature
12:20:14.157 -> >>> send_tlv_response: [Client 1073697532] Sending TLV response
12:20:14.157 -> >>> tlv_debug: Got following TLV values:
12:20:14.157 -> >>> tlv_debug: Type 6 value (1 bytes): \x04
12:20:14.157 -> >>> client_send: [Client 1073697532] send data size=105, encrypted=false
12:20:14.194 -> >>> client_send: [Client 1073697532] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/pairing+tlv8\x0D\x0AContent-Length: 3\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A\x06\x01\x04
12:20:14.194 -> >>> HomeKit: [Client 1073697532] Verification successful, secure session established
12:20:14.194 -> >>> HomeKit: Free heap: 26048
12:20:14.232 -> >>> homekit_client_process: [Client 1073697892] Reading 247 bytes
12:20:14.232 -> >>> homekit_server_on_message_complete: http_parser message_complete
12:20:14.232 -> >>> homekit_server_on_pair_verify: HomeKit Pair Verify
12:20:14.232 -> >>> homekit_server_on_pair_verify: Free heap: 26224
12:20:14.232 -> >>> tlv_debug: Got following TLV values:
12:20:14.232 -> >>> tlv_debug: Type 5 value (120 bytes): \x8B\x0B\xC8\xDB~\xDB\x145/\xF601a\xCF\xF8IAE\x18;\x07\x09\xE7\x93d%\xD1�\x91\xB4\xBA\xBD!\x80\xA6\x07\x95B\xA2Ol\x04~s\xBFp\xC5\xE3\xC0\xCF\x0AtHY\xC5\xB5\x95\xCB\xC1\x06J\x8F\xA7#c3\xBC\xFD\xC3\xB7&H\xE65\xBFxj\xC1\x82\xA4\xB6\x9A\xB3\xD4V\x8A\xF2qT\x18\xF8\x98=1\xE4w\xDDx\xF3U\xBF\xD6�\x9E\x19\x0D\x9Et\xD5\xE8\x83S\xF7v\xE4K\xDC
12:20:14.267 -> >>> tlv_debug: Type 6 value (1 bytes): \x03
12:20:14.267 -> >>> HomeKit: [Client 1073697892] Pair Verify Step 2/2
12:20:14.267 -> >>> homekit_server_on_pair_verify: [Client 1073697892] Decrypting payload
12:20:14.301 -> >>> homekit_server_on_pair_verify: [Client 1073697892] Searching pairing with 0F8927F8-0F84-44E7-8181-8714ED73BD51
12:20:14.301 -> >>> HomeKit: [Client 1073697892] Found pairing with 0F8927F8-0F84-44E7-8181-8714ED73BD51
12:20:14.301 -> >>> homekit_server_on_pair_verify: [Client 1073697892] Verifying device signature
12:20:15.084 -> >>> send_tlv_response: [Client 1073697892] Sending TLV response
12:20:15.084 -> >>> tlv_debug: Got following TLV values:
12:20:15.084 -> >>> tlv_debug: Type 6 value (1 bytes): \x04
12:20:15.084 -> >>> client_send: [Client 1073697892] send data size=105, encrypted=false
12:20:15.119 -> >>> client_send: [Client 1073697892] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/pairing+tlv8\x0D\x0AContent-Length: 3\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A\x06\x01\x04
12:20:15.228 -> >>> HomeKit: [Client 1073697892] Verification successful, secure session established
12:20:15.228 -> >>> HomeKit: Free heap: 26424
12:20:15.228 -> >>> homekit_client_process: [Client 1073697532] Reading 78 bytes
12:20:15.266 -> >>> homekit_client_process: [Client 1073697532] Decrypted 60 bytes, available 0
12:20:15.266 -> Decrypted data (60 bytes): "GET /accessories HTTP/1.1\x0D\x0AHost: ES-B1E8.hap.tcp.local\x0D\x0A\x0D\x0A"
12:20:15.266 -> >>> homekit_server_on_message_complete: http_parser message_complete
12:20:15.266 -> >>> HomeKit: [Client 1073697532] Get Accessories
12:20:15.266 -> >>> homekit_server_on_get_accessories: Free heap: 26560
12:20:15.266 -> >>> client_send: [Client 1073697532] send data size=107, encrypted=true
12:20:15.300 -> >>> client_send: [Client 1073697532] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A
12:20:15.300 -> >>> client_send_encrypted
: [Client 1073697532] client_send_encrypted
size=107
12:20:15.341 -> >>> homekit_server_on_get_accessories: [Client 1073697532] Get Accessories, start send json body
12:20:15.341 -> >>> client_send_chunk: [Client 1073697532] client_send_chunk, size=1012, offset=5
12:20:15.341 -> >>> client_send: [Client 1073697532] send data size=1019, encrypted=true
12:20:15.341 -> >>> client_send: [Client 1073697532] Sending payload: 3f4\x0D\x0A{"accessories":[{"aid":1,"services":[{"iid":1,"type":"3E","hidden":false,"primary":false,"characteristics":[{"aid":1,"iid":2,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"ES"},{"aid":1,"iid":3,"type":"20","perms":["pr"],"description":"Manufacturer","format":"string","value":"Yurik72"},{"aid":1,"iid":4,"type":"30","perms":["pr"],"description":"Serial Number","format":"string","value":"0"},{"aid":1,"iid":5,"type":"21","perms":["pr"],"description":"Model","format":"string","value":"EspHapLed"},{"aid":1,"iid":6,"type":"52","perms":["pr"],"description":"Firmware Revision","format":"string","value":"1.0"},{"aid":1,"iid":7,"type":"14","perms":["pw"],"description":"Identify","format":"bool"}]},{"iid":8,"type":"43","hidden":false,"primary":true,"characteristics":[{"aid":1,"iid":9,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"Led"},{"aid":1,"iid":10,"type":"25","perms":["pr","pw","ev"],"ev":false,"description":"On","format":"bool","value":true}]}]}]}\x0D\x0A
12:20:15.443 -> >>> client_send_encrypted
: [Client 1073697532] client_send_encrypted_ size=1019
12:20:15.490 -> >>> client_send_chunk: [Client 1073697532] client_send_chunk, size=0, offset=3
12:20:15.490 -> >>> client_send: [Client 1073697532] send data size=5, encrypted=true
12:20:15.490 -> >>> client_send: [Client 1073697532] Sending payload: 0\x0D\x0A\x0D\x0A
12:20:15.490 -> >>> client_send_encrypted_: [Client 1073697532] client_send_encrypted_ size=5
12:20:15.490 -> >>> homekit_client_process: [Client 1073697892] Reading 78 bytes
12:20:15.490 -> >>> homekit_client_process: [Client 1073697892] Decrypted 60 bytes, available 0
12:20:15.547 -> Decrypted data (60 bytes): "GET /accessories HTTP/1.1\x0D\x0AHost: ES-B1E8.hap.tcp.local\x0D\x0A\x0D\x0A"
12:20:15.547 -> >>> homekit_server_on_message_complete: http_parser message_complete
12:20:15.547 -> >>> HomeKit: [Client 1073697892] Get Accessories
12:20:15.547 -> >>> homekit_server_on_get_accessories: Free heap: 26160
12:20:15.547 -> >>> client_send: [Client 1073697892] send data size=107, encrypted=true
12:20:15.547 -> >>> client_send: [Client 1073697892] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A
12:20:15.547 -> >>> client_send_encrypted
: [Client 1073697892] client_send_encrypted
size=107
12:20:15.609 -> >>> homekit_server_on_get_accessories: [Client 1073697892] Get Accessories, start send json body
12:20:15.609 -> >>> client_send_chunk: [Client 1073697892] client_send_chunk, size=1012, offset=5
12:20:15.609 -> >>> client_send: [Client 1073697892] send data size=1019, encrypted=true
12:20:15.609 -> >>> client_send: [Client 1073697892] Sending payload: 3f4\x0D\x0A{"accessories":[{"aid":1,"services":[{"iid":1,"type":"3E","hidden":false,"primary":false,"characteristics":[{"aid":1,"iid":2,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"ES"},{"aid":1,"iid":3,"type":"20","perms":["pr"],"description":"Manufacturer","format":"string","value":"Yurik72"},{"aid":1,"iid":4,"type":"30","perms":["pr"],"description":"Serial Number","format":"string","value":"0"},{"aid":1,"iid":5,"type":"21","perms":["pr"],"description":"Model","format":"string","value":"EspHapLed"},{"aid":1,"iid":6,"type":"52","perms":["pr"],"description":"Firmware Revision","format":"string","value":"1.0"},{"aid":1,"iid":7,"type":"14","perms":["pw"],"description":"Identify","format":"bool"}]},{"iid":8,"type":"43","hidden":false,"primary":true,"characteristics":[{"aid":1,"iid":9,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"Led"},{"aid":1,"iid":10,"type":"25","perms":["pr","pw","ev"],"ev":false,"description":"On","format":"bool","value":true}]}]}]}\x0D\x0A
12:20:15.687 -> >>> client_send_encrypted_: [Client 1073697892] client_send_encrypted_ size=1019
12:20:15.720 -> >>> client_send_chunk: [Client 1073697892] client_send_chunk, size=0, offset=3
12:20:15.720 -> >>> client_send: [Client 1073697892] send data size=5, encrypted=true
12:20:15.720 -> >>> client_send: [Client 1073697892] Sending payload: 0\x0D\x0A\x0D\x0A
12:20:15.758 -> >>> client_send_encrypted_: [Client 1073697892] client_send_encrypted_ size=5
12:20:15.758 -> >>> homekit_client_process: [Client 1073697532] Reading 188 bytes
12:20:15.758 -> >>> homekit_client_process: [Client 1073697532] Decrypted 170 bytes, available 0
12:20:15.758 -> Decrypted data (170 bytes): "PUT /characteristics HTTP/1.1\x0D\x0AHost: ES-B1E8.hap.tcp.local\x0D\x0AContent-Length: 50\x0D\x0AContent-Type: application/hap+json\x0D\x0A\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"ev":true}]}"
12:20:15.798 -> >>> homekit_server_on_message_complete: http_parser message_complete
12:20:15.798 -> >>> HomeKit: [Client 1073697532] Update Characteristics
12:20:15.798 -> >>> homekit_server_on_update_characteristics: Free heap: 26544
12:20:15.798 -> >>> HomeKit: Free heap: 26536
12:20:15.798 -> >>> homekit_server_on_update_characteristics: [Client 1073697532] There were no processing errors, sending No Content response
12:20:15.837 -> >>> client_send: [Client 1073697532] send data size=27, encrypted=true
12:20:15.837 -> >>> client_send: [Client 1073697532] Sending payload: HTTP/1.1 204 No Content\x0D\x0A\x0D\x0A
12:20:15.837 -> >>> client_send_encrypted
: [Client 1073697532] client_send_encrypted
size=27
12:20:18.173 -> >>> homekit_client_process: [Client 1073697532] Reading 90 bytes
12:20:18.173 -> >>> homekit_client_process: [Client 1073697532] Decrypted 72 bytes, available 0
12:20:18.173 -> Decrypted data (72 bytes): "GET /characteristics?id=1.10 HTTP/1.1\x0D\x0AHost: ES-B1E8.hap.tcp.local\x0D\x0A\x0D\x0A"
12:20:18.208 -> >>> homekit_server_on_message_complete: http_parser message_complete
12:20:18.208 -> >>> HomeKit: [Client 1073697532] Get Characteristics
12:20:18.208 -> >>> homekit_server_on_get_characteristics: Free heap: 26152
12:20:18.208 -> >>> homekit_server_on_get_characteristics: [Client 1073697532] Query paramter id = 1.10
12:20:18.208 -> >>> homekit_server_on_get_characteristics: [Client 1073697532] Requested characteristic info for 1.10
12:20:18.247 -> >>> client_send: [Client 1073697532] send data size=107, encrypted=true
12:20:18.247 -> >>> client_send: [Client 1073697532] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A
12:20:18.247 -> >>> client_send_encrypted
: [Client 1073697532] client_send_encrypted
size=107
12:20:18.285 -> >>> homekit_server_on_get_characteristics: [Client 1073697532] Requested characteristic info for 1.10
12:20:18.285 -> >>> client_send_chunk: [Client 1073697532] client_send_chunk, size=53, offset=4
12:20:18.285 -> >>> client_send: [Client 1073697532] send data size=59, encrypted=true
12:20:18.285 -> >>> client_send: [Client 1073697532] Sending payload: 35\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"value":true}]}\x0D\x0A
12:20:18.285 -> >>> client_send_encrypted_: [Client 1073697532] client_send_encrypted_ size=59
12:20:18.325 -> >>> client_send_chunk: [Client 1073697532] client_send_chunk, size=0, offset=3
12:20:18.325 -> >>> client_send: [Client 1073697532] send data size=5, encrypted=true
12:20:18.325 -> >>> client_send: [Client 1073697532] Sending payload: 0\x0D\x0A\x0D\x0A
12:20:18.325 -> >>> client_send_encrypted_: [Client 1073697532] client_send_encrypted_ size=5
12:20:20.192 -> >>> HomeKit: WiFiServer receives a new client (current 2, max 8)
12:20:20.192 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.15:60690
12:20:20.192 -> >>> HomeKit: [Client 1073699308] Got client content from the cache 2
12:20:20.192 -> >>> HomeKit: [Client 1073699308] new client accepted
12:20:20.192 -> >>> homekit_client_process: [Client 1073699308] Reading 158 bytes
12:20:20.230 -> >>> homekit_server_on_message_complete: http_parser message_complete
12:20:20.230 -> >>> homekit_server_on_pair_verify: HomeKit Pair Verify
12:20:20.230 -> >>> homekit_server_on_pair_verify: Free heap: 25616
12:20:20.230 -> >>> tlv_debug: Got following TLV values:
12:20:20.230 -> >>> tlv_debug: Type 6 value (1 bytes): \x01
12:20:20.230 -> >>> tlv_debug: Type 3 value (32 bytes): \xC2m\xB8+\xCE\xFCZT\x1E\x85\xEE^\x03\xE9\xF8\xC6\xFC\xD4\x80Kt\x975\xFB\xF2K\x1A\x9Ej3\xE4\x19
12:20:20.230 -> >>> HomeKit: [Client 1073699308] Pair Verify Step 1/2
12:20:20.267 -> >>> homekit_server_on_pair_verify: [Client 1073699308] Importing device Curve25519 public key
12:20:20.267 -> >>> homekit_server_on_pair_verify: [Client 1073699308] Generating accessory Curve25519 key
12:20:20.412 -> >>> homekit_server_on_pair_verify: [Client 1073699308] Exporting accessory Curve25519 public key
12:20:20.412 -> >>> homekit_server_on_pair_verify: [Client 1073699308] Generating Curve25519 shared secret
12:20:20.520 -> >>> homekit_server_on_pair_verify: [Client 1073699308] Generating signature
12:20:20.590 -> >>> homekit_server_on_pair_verify: [Client 1073699308] Generating proof
12:20:20.624 -> >>> homekit_server_on_pair_verify: [Client 1073699308] Encrypting response
12:20:20.624 -> >>> send_tlv_response: [Client 1073699308] Sending TLV response
12:20:20.624 -> >>> tlv_debug: Got following TLV values:
12:20:20.624 -> >>> tlv_debug: Type 6 value (1 bytes): \x02
12:20:20.624 -> >>> tlv_debug: Type 3 value (32 bytes): \xBA$\xB2\xD6\xFC\xF0X\x95\xE0t_\xF1\xFB"\xFF\xA2\xEB\xE0\xED\x01\xAD\xA3\xC4\x1A\xA0\xA2\xED\xCCn\xB6y%
12:20:20.660 -> >>> tlv_debug: Type 5 value (101 bytes): \xA9"\xD8k\xAFO\xDF\xD4N]\xAB\xCF\x07p\x11s\xF0\x88\xE8\x86R\x04\x10\xC2\xDC\xCB\xF4\xE2\xCF\xED:\x91\xA3\x15\xE7\x07\x9A\xF5\xBA\xF1\x12}\xE51\x83\xCE\x00\xB0\x136\xD1\x1A\xC0\xB1\x97\xD9\x06TD\xAB\xC1N|\xF1\xE4G\x9Bn?M\x8D<\x0E\xBF\xC2\xE0\xB8sT\x96t\x13\xA7t\x94\xD1\xF5\xE5r\xA2\xC4\xB4p\xF1\xD7b'c\x0C\x813
12:20:20.660 -> >>> client_send: [Client 1073699308] send data size=244, encrypted=false
12:20:20.698 -> >>> client_send: [Client 1073699308] 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\x02\x03 \xBA$\xB2\xD6\xFC\xF0X\x95\xE0t_\xF1\xFB"\xFF\xA2\xEB\xE0\xED\x01\xAD\xA3\xC4\x1A\xA0\xA2\xED\xCCn\xB6y%\x05e\xA9"\xD8k\xAFO\xDF\xD4N]\xAB\xCF\x07p\x11s\xF0\x88\xE8\x86R\x04\x10\xC2\xDC\xCB\xF4\xE2\xCF\xED:\x91\xA3\x15\xE7\x07\x9A\xF5\xBA\xF1\x12}\xE51\x83\xCE\x00\xB0\x136\xD1\x1A\xC0\xB1\x97\xD9\x06TD\xAB\xC1N|\xF1\xE4G\x9Bn?M\x8D<\x0E\xBF\xC2\xE0\xB8sT\x96t\x13\xA7t\x94\xD1\xF5\xE5r\xA2\xC4\xB4p\xF1\xD7b'c\x0C\x813
12:20:20.773 -> >>> HomeKit: Free heap: 25216
12:20:20.830 -> >>> homekit_client_process: [Client 1073699308] Reading 247 bytes
12:20:20.830 -> >>> homekit_server_on_message_complete: http_parser message_complete
12:20:20.830 -> >>> homekit_server_on_pair_verify: HomeKit Pair Verify
12:20:20.830 -> >>> homekit_server_on_pair_verify: Free heap: 25240
12:20:20.830 -> >>> tlv_debug: Got following TLV values:
12:20:20.830 -> >>> tlv_debug: Type 5 value (120 bytes): D\xF0\x96\x00\xA2\xCC$V\x14\xF4\x14n\xDF\xCB\xC1\xCC,X#Y6b\xE0j\xA4 \xCF7}\xCD0\x01\xA1i\xB0sm\x11\xB1\xE4GV"\x9B"\xBA\xBD\xB6\xB0WT^\xC2\xAEB\xED\xE1\x9A<{tg\xF0\xC7O\xCB\xBF \xA8\xF0\xAD\xD7\xF2\xC7\xF6Av\xE3|\xE3Cx\x07d\xA0\xEC\x0C\xC6\xDF\xE8pj\x97\xFF\\x1C\xEA\xC7\x1E\x8B:Cp\xA0e\xDBoDn\x85\x9F\x81w}L\xB1\xC3\xF3\xDCr
12:20:20.874 -> >>> tlv_debug: Type 6 value (1 bytes): \x03
12:20:20.874 -> >>> HomeKit: [Client 1073699308] Pair Verify Step 2/2
12:20:20.912 -> >>> homekit_server_on_pair_verify: [Client 1073699308] Decrypting payload
12:20:20.912 -> >>> homekit_server_on_pair_verify: [Client 1073699308] Searching pairing with 6FDD5BE0-78E1-4A4C-B5D7-98277EEFA239
12:20:20.912 -> >>> HomeKit: [Client 1073699308] Found pairing with 6FDD5BE0-78E1-4A4C-B5D7-98277EEFA239
12:20:20.912 -> >>> homekit_server_on_pair_verify: [Client 1073699308] Verifying device signature
12:20:21.691 -> >>> send_tlv_response: [Client 1073699308] Sending TLV response
12:20:21.691 -> >>> tlv_debug: Got following TLV values:
12:20:21.691 -> >>> tlv_debug: Type 6 value (1 bytes): \x04
12:20:21.691 -> >>> client_send: [Client 1073699308] send data size=105, encrypted=false
12:20:21.691 -> >>> client_send: [Client 1073699308] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/pairing+tlv8\x0D\x0AContent-Length: 3\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A\x06\x01\x04
12:20:21.728 -> >>> HomeKit: [Client 1073699308] Verification successful, secure session established
12:20:21.728 -> >>> HomeKit: Free heap: 24896
12:20:21.728 -> >>> homekit_client_process: [Client 1073699308] Reading 78 bytes
12:20:21.764 -> >>> homekit_client_process: [Client 1073699308] Decrypted 60 bytes, available 0
12:20:21.764 -> Decrypted data (60 bytes): "GET /accessories HTTP/1.1\x0D\x0AHost: ES-B1E8.hap.tcp.local\x0D\x0A\x0D\x0A"
12:20:21.764 -> >>> homekit_server_on_message_complete: http_parser message_complete
12:20:21.764 -> >>> HomeKit: [Client 1073699308] Get Accessories
12:20:21.764 -> >>> homekit_server_on_get_accessories: Free heap: 25032
12:20:21.801 -> >>> client_send: [Client 1073699308] send data size=107, encrypted=true
12:20:21.801 -> >>> client_send: [Client 1073699308] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A
12:20:21.801 -> >>> client_send_encrypted
: [Client 1073699308] client_send_encrypted
size=107
12:20:21.835 -> >>> homekit_server_on_get_accessories: [Client 1073699308] Get Accessories, start send json body
12:20:21.835 -> >>> client_send_chunk: [Client 1073699308] client_send_chunk, size=1012, offset=5
12:20:21.835 -> >>> client_send: [Client 1073699308] send data size=1019, encrypted=true
12:20:21.835 -> >>> client_send: [Client 1073699308] Sending payload: 3f4\x0D\x0A{"accessories":[{"aid":1,"services":[{"iid":1,"type":"3E","hidden":false,"primary":false,"characteristics":[{"aid":1,"iid":2,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"ES"},{"aid":1,"iid":3,"type":"20","perms":["pr"],"description":"Manufacturer","format":"string","value":"Yurik72"},{"aid":1,"iid":4,"type":"30","perms":["pr"],"description":"Serial Number","format":"string","value":"0"},{"aid":1,"iid":5,"type":"21","perms":["pr"],"description":"Model","format":"string","value":"EspHapLed"},{"aid":1,"iid":6,"type":"52","perms":["pr"],"description":"Firmware Revision","format":"string","value":"1.0"},{"aid":1,"iid":7,"type":"14","perms":["pw"],"description":"Identify","format":"bool"}]},{"iid":8,"type":"43","hidden":false,"primary":true,"characteristics":[{"aid":1,"iid":9,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"Led"},{"aid":1,"iid":10,"type":"25","perms":["pr","pw","ev"],"ev":false,"description":"On","format":"bool","value":true}]}]}]}\x0D\x0A
12:20:21.947 -> >>> client_send_encrypted_: [Client 1073699308] client_send_encrypted_ size=1019
12:20:21.985 -> >>> client_send_chunk: [Client 1073699308] client_send_chunk, size=0, offset=3
12:20:21.985 -> >>> client_send: [Client 1073699308] send data size=5, encrypted=true
12:20:21.985 -> >>> client_send: [Client 1073699308] Sending payload: 0\x0D\x0A\x0D\x0A
12:20:21.985 -> >>> client_send_encrypted_: [Client 1073699308] client_send_encrypted_ size=5
12:20:56.652 -> >>> homekit_client_process: [Client 1073697532] Reading 188 bytes
12:20:56.652 -> >>> homekit_client_process: [Client 1073697532] Decrypted 170 bytes, available 0
12:20:56.652 -> Decrypted data (170 bytes): "PUT /characteristics HTTP/1.1\x0D\x0AHost: ES-B1E8.hap.tcp.local\x0D\x0AContent-Length: 50\x0D\x0AContent-Type: application/hap+json\x0D\x0A\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"value":0}]}"
12:20:56.896 -> >>> homekit_server_on_message_complete: http_parser message_complete
12:20:56.896 -> >>> HomeKit: [Client 1073697532] Update Characteristics
12:20:56.896 -> >>> homekit_server_on_update_characteristics: Free heap: 25824
12:20:56.896 -> >>> HomeKit: Free heap: 25816
12:20:56.896 -> >>> process_characteristics_update: [Client 1073697532] Updating characteristic 1.10 with boolean false
12:20:56.896 -> led_callback
12:20:56.896 -> set_led
12:20:56.896 -> notify hap
12:20:56.896 -> found characteristic
12:20:56.896 -> >>> client_notify_characteristic: [Client 1073697532] This value is set by this client, no need to send notification
12:20:56.896 -> >>> homekit_server_on_update_characteristics: [Client 1073697532] There were no processing errors, sending No Content response
12:20:56.896 -> >>> client_send: [Client 1073697532] send data size=27, encrypted=true
12:20:56.896 -> >>> client_send: [Client 1073697532] Sending payload: HTTP/1.1 204 No Content\x0D\x0A\x0D\x0A
12:20:56.896 -> >>> client_send_encrypted
: [Client 1073697532] client_send_encrypted
size=27

Homebridge mDNS here

12:21:06.738 -> >>> HomeKit: WiFiServer receives a new client (current 3, max 8)
12:21:06.738 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.213:47622
12:21:06.738 -> >>> HomeKit: [Client 1073698420] Got client content from the cache 3
12:21:06.846 -> >>> HomeKit: [Client 1073698420] new client accepted
12:21:06.846 -> >>> homekit_client_process: [Client 1073698420] Reading 142 bytes
12:21:06.846 -> >>> homekit_server_on_message_complete: http_parser message_complete
12:21:06.846 -> !!! HomeKit: Unknown endpoint
12:21:06.846 -> >>> client_send: [Client 1073698420] send data size=26, encrypted=false
12:21:06.846 -> >>> client_send: [Client 1073698420] Sending payload: HTTP/1.1 404 Not Found\x0D\x0A\x0D\x0A
12:21:11.784 -> >>> HomeKit: [Client 1073698420] Closing client connection
12:21:11.822 -> >>> homekit_server_close_client: [Client 1073698420] The sockect is stoped
12:21:11.822 -> >>> HomeKit: [Client 0] client content free
12:21:28.717 -> >>> homekit_client_process: [Client 1073697532] Reading 188 bytes
12:21:28.717 -> >>> homekit_client_process: [Client 1073697532] Decrypted 170 bytes, available 0
12:21:28.717 -> Decrypted data (170 bytes): "PUT /characteristics HTTP/1.1\x0D\x0AHost: ES-B1E8._hap._tcp.local\x0D\x0AContent-Length: 50\x0D\x0AContent-Type: application/hap+json\x0D\x0A\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"value":1}]}"
12:21:39.214 -> >>> HomeKit: [Client 1073697532] Disconnected!
12:21:44.215 -> >>> HomeKit: [Client 1073697532] Closing client connection
12:21:44.215 -> >>> homekit_server_close_client: [Client 1073697532] The sockect is stoped
12:21:44.410 -> >>> HomeKit: [Client 0] client content free

@eford321
Copy link
Contributor Author

eford321 commented Mar 4, 2021

Also, ESP responds to mDNS from Homebridge _hap._tcp.local QM. (.213 is homebridge, .23 is ESP)
Screen Shot 2021-03-04 at 12 31 29 PM

But ESP ignores mdns QM requests looking for _arduino._tcp.local coming from other devices when I don't have OTA in sketch. This packet is ignored:
Screen Shot 2021-03-04 at 12 32 22 PM

@Yurik72
Copy link
Owner

Yurik72 commented Mar 4, 2021 via email

@Yurik72
Copy link
Owner

Yurik72 commented Mar 4, 2021 via email

@eford321
Copy link
Contributor Author

eford321 commented Mar 4, 2021

most recent test was ESP8266.

@Yurik72
Copy link
Owner

Yurik72 commented Mar 4, 2021 via email

@eford321
Copy link
Contributor Author

eford321 commented Mar 4, 2021

12:21:06.738 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.213:47622

This is the mDNS from HomeBridge.

@eford321
Copy link
Contributor Author

eford321 commented Mar 4, 2021

But I didn’t see a log according my suggestions Line 3507 /* Uncomment this block for trace

Which file?

@eford321
Copy link
Contributor Author

eford321 commented Mar 4, 2021

Nevermind, I found it. Sorry I accidentally overwrote the file earlier. working on it now

@Yurik72
Copy link
Owner

Yurik72 commented Mar 4, 2021 via email

@eford321
Copy link
Contributor Author

eford321 commented Mar 4, 2021

Here is correct log.

First connection from .13 is Home app on MacOS

13:37:43.094 -> >>> HomeKit: WiFiServer receives a new client (current 0, max 8)
13:37:43.094 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.13:61507
13:37:43.094 -> >>> HomeKit: [Client 1073698420] Got client content from the cache 0
13:37:43.094 -> >>> HomeKit: [Client 1073698420] new client accepted
13:37:43.132 -> >>> homekit_client_process: [Client 1073698420] Reading 158 bytes
13:37:43.132 -> >>> HomeKit: [Client 1073698420] payload=<POST /pair-verify HTTP/1.1
13:37:43.132 -> Host: ES-B1E8._hap.tcp.local
13:37:43.132 -> Content-Length: 37
13:37:43.132 -> Content-Type: application/pairing+tlv8
13:37:43.132 ->
13:37:43.132 -> ���� ⸮⸮̼8<c⸮⸮��⸮+⸮n��ҕ⸮��⸮J5⸮QD e>
13:37:43.132 -> >>> homekit_server_on_message_complete: http_parser message_complete
13:37:43.132 -> >>> homekit_server_on_pair_verify: HomeKit Pair Verify
13:37:43.132 -> >>> homekit_server_on_pair_verify: Free heap: 26120
13:37:43.167 -> >>> tlv_debug: Got following TLV values:
13:37:43.167 -> >>> tlv_debug: Type 6 value (1 bytes): \x01
13:37:43.167 -> >>> tlv_debug: Type 3 value (32 bytes): \xE7
\xFF\xCC\xBC8<c\xE0\xAF\xEB\x08\x05\x8A+\xE7n\x11\x03\xD2\x95\x88\x1E\x08\xEBJ5\xB7QD e
13:37:43.167 -> >>> HomeKit: [Client 1073698420] Pair Verify Step 1/2
13:37:43.167 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Importing device Curve25519 public key
13:37:43.201 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Generating accessory Curve25519 key
13:37:43.308 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Exporting accessory Curve25519 public key
13:37:43.346 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Generating Curve25519 shared secret
13:37:43.455 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Generating signature
13:37:43.523 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Generating proof
13:37:43.523 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Encrypting response
13:37:43.558 -> >>> send_tlv_response: [Client 1073698420] Sending TLV response
13:37:43.558 -> >>> tlv_debug: Got following TLV values:
13:37:43.558 -> >>> tlv_debug: Type 6 value (1 bytes): \x02
13:37:43.558 -> >>> tlv_debug: Type 3 value (32 bytes): \xD4O\xF3}3-s\x0A\xA8I\xEFs]\x1C{\x10\x99\xEC\xD4CR\xDFNL\\xB5$0OL\xC9^
13:37:43.558 -> >>> tlv_debug: Type 5 value (101 bytes): \xE8z!q]B\x81\x96U\xAC\xAB\x87\xD4t\xB2\xA2\x984\xC3\xC08\xF9\xE0\x1E\x97U\xC1XL\xA7&3\xEDa\xED\xE5/4\x00OH\xDF~�\x95O0\xACStu\x17\xCA\xC4�*\x05O\xE3.\xB6+\x15\x00\xCBc|$\xEB*\x05\xA7u;\x14\xD7\x09\x86\x11\xC1\xC1\x06O\x98\x9D\xA5\xDC\xDA\xCB\x9C2G\xF0\x899\xBD\xC8\xC7\xAC
13:37:43.592 -> >>> client_send: [Client 1073698420] send data size=244, encrypted=false
13:37:43.592 -> >>> client_send: [Client 1073698420] 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\x02\x03 \xD4O\xF3}3-s\x0A\xA8I\xEFs]\x1C{\x10\x99\xEC\xD4CR\xDFNL\\xB5$0OL\xC9^\x05e\xE8z!q]B\x81\x96U\xAC\xAB\x87\xD4t\xB2\xA2\x984\xC3\xC08\xF9\xE0\x1E\x97U\xC1XL\xA7&3\xEDa\xED\xE5/4\x00OH\xDF~�\x95O0\xACStu\x17\xCA\xC4�*\x05O\xE3.\xB6+\x15\x00\xCBc|$\xEB*\x05\xA7u;\x14\xD7\x09\x86\x11\xC1\xC1\x06O\x98\x9D\xA5\xDC\xDA\xCB\x9C2G\xF0\x899\xBD\xC8\xC7\xAC
13:37:43.664 -> >>> HomeKit: Free heap: 25920
13:37:43.664 -> >>> homekit_client_process: [Client 1073698420] Reading 247 bytes
13:37:43.664 -> >>> HomeKit: [Client 1073698420] payload=<POST /pair-verify HTTP/1.1
13:37:43.664 -> Host: ES-B1E8.hap.tcp.local
13:37:43.664 -> Content-Length: 125
13:37:43.664 -> Content-Type: application/pairing+tlv8
13:37:43.701 ->
13:37:43.701 -> �x⸮DE⸮�ƻ⸮~⸮
13:37:43.701 -> �̀⸮�z⸮⸮P⸮⸮⸮⸮v⸮�F⸮6w⸮t⸮v��@>⸮㪝�+Tż��⸮⸮⸮A⸮⸮⸮�_K{⸮|l'C%⸮Sc�}⸮⸮⸮b �⸮[q⸮,⸮⸮)⸮⸮]�zv⸮q3�1pYx!⸮�⸮.⸮5?⸮⸮C⸮��j⸮���> 13:37:43.701 -> >>> homekit_server_on_message_complete: http_parser message_complete 13:37:43.701 -> >>> homekit_server_on_pair_verify: HomeKit Pair Verify 13:37:43.701 -> >>> homekit_server_on_pair_verify: Free heap: 25832 13:37:43.701 -> >>> tlv_debug: Got following TLV values: 13:37:43.701 -> >>> tlv_debug: Type 5 value (120 bytes): \xD6DE\xF5\x04\xC6\xBB\xF4~\xEA\xA5\x0A\x1B\xCD\x80\xC2_\x0Fz\xBD\xE7P\xBE\xBB\xB3\xAAv\xF2\x14F\x886w\x91t\xB9v\x05\x11@>\xD3\xE3\xAA\x9D\x1D+T\xC5\xBC\x1E\x07\x9A\xA9\x86A\xFD\xC6\xD8\x06_K{\xA0\\|l'C%\xE4Sc\x17}\xB3\xD2\xC9b\x0C\x1D\xD4[q\xBE,\x80\x84)\x99\xFC]\x03zv\xBCq3\x1C1pYx!\xAA\x18\xD6.\x845?\xF9\xDDC\xD1\x07\x1Dj\xB1
13:37:43.750 -> >>> tlv_debug: Type 6 value (1 bytes): \x03
13:37:43.750 -> >>> HomeKit: [Client 1073698420] Pair Verify Step 2/2
13:37:43.750 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Decrypting payload
13:37:43.750 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Searching pairing with 6FDD5BE0-78E1-4A4C-B5D7-98277EEFA239
13:37:43.772 -> >>> HomeKit: [Client 1073698420] Found pairing with 6FDD5BE0-78E1-4A4C-B5D7-98277EEFA239
13:37:43.772 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Verifying device signature
13:37:44.548 -> >>> send_tlv_response: [Client 1073698420] Sending TLV response
13:37:44.548 -> >>> tlv_debug: Got following TLV values:
13:37:44.548 -> >>> tlv_debug: Type 6 value (1 bytes): \x04
13:37:44.582 -> >>> client_send: [Client 1073698420] send data size=105, encrypted=false
13:37:44.582 -> >>> client_send: [Client 1073698420] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/pairing+tlv8\x0D\x0AContent-Length: 3\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A\x06\x01\x04
13:37:44.615 -> >>> HomeKit: [Client 1073698420] Verification successful, secure session established
13:37:44.615 -> >>> HomeKit: Free heap: 26032
13:37:44.615 -> >>> homekit_client_process: [Client 1073698420] Reading 78 bytes
13:37:44.615 -> >>> homekit_client_process: [Client 1073698420] Decrypted 60 bytes, available 0
13:37:44.615 -> Decrypted data (60 bytes): "GET /accessories HTTP/1.1\x0D\x0AHost: ES-B1E8.hap.tcp.local\x0D\x0A\x0D\x0A"
13:37:44.653 -> >>> HomeKit: [Client 1073698420] payload=<GET /accessories HTTP/1.1
13:37:44.653 -> Host: ES-B1E8.hap.tcp.local
13:37:44.653 ->
13:37:44.653 -> >
13:37:44.653 -> >>> homekit_server_on_message_complete: http_parser message_complete
13:37:44.653 -> >>> HomeKit: [Client 1073698420] Get Accessories
13:37:44.653 -> >>> homekit_server_on_get_accessories: Free heap: 26168
13:37:44.653 -> >>> client_send: [Client 1073698420] send data size=107, encrypted=true
13:37:44.653 -> >>> client_send: [Client 1073698420] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A
13:37:44.688 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=107
13:37:44.688 -> >>> homekit_server_on_get_accessories: [Client 1073698420] Get Accessories, start send json body
13:37:44.721 -> >>> client_send_chunk: [Client 1073698420] client_send_chunk, size=1012, offset=5
13:37:44.721 -> >>> client_send: [Client 1073698420] send data size=1019, encrypted=true
13:37:44.721 -> >>> client_send: [Client 1073698420] Sending payload: 3f4\x0D\x0A{"accessories":[{"aid":1,"services":[{"iid":1,"type":"3E","hidden":false,"primary":false,"characteristics":[{"aid":1,"iid":2,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"ES"},{"aid":1,"iid":3,"type":"20","perms":["pr"],"description":"Manufacturer","format":"string","value":"Yurik72"},{"aid":1,"iid":4,"type":"30","perms":["pr"],"description":"Serial Number","format":"string","value":"0"},{"aid":1,"iid":5,"type":"21","perms":["pr"],"description":"Model","format":"string","value":"EspHapLed"},{"aid":1,"iid":6,"type":"52","perms":["pr"],"description":"Firmware Revision","format":"string","value":"1.0"},{"aid":1,"iid":7,"type":"14","perms":["pw"],"description":"Identify","format":"bool"}]},{"iid":8,"type":"43","hidden":false,"primary":true,"characteristics":[{"aid":1,"iid":9,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"Led"},{"aid":1,"iid":10,"type":"25","perms":["pr","pw","ev"],"ev":false,"description":"On","format":"bool","value":true}]}]}]}\x0D\x0A
13:37:44.833 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=1019
13:37:44.833 -> >>> client_send_chunk: [Client 1073698420] client_send_chunk, size=0, offset=3
13:37:44.833 -> >>> client_send: [Client 1073698420] send data size=5, encrypted=true
13:37:44.833 -> >>> client_send: [Client 1073698420] Sending payload: 0\x0D\x0A\x0D\x0A
13:37:44.871 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=5
13:37:44.871 -> >>> homekit_client_process: [Client 1073698420] Reading 90 bytes
13:37:44.871 -> >>> homekit_client_process: [Client 1073698420] Decrypted 72 bytes, available 0
13:37:44.871 -> Decrypted data (72 bytes): "GET /characteristics?id=1.10 HTTP/1.1\x0D\x0AHost: ES-B1E8.hap.tcp.local\x0D\x0A\x0D\x0A"
13:37:44.908 -> >>> HomeKit: [Client 1073698420] payload=<GET /characteristics?id=1.10 HTTP/1.1
13:37:44.908 -> Host: ES-B1E8.hap.tcp.local
13:37:44.908 ->
13:37:44.908 -> >
13:37:44.908 -> >>> homekit_server_on_message_complete: http_parser message_complete
13:37:44.908 -> >>> HomeKit: [Client 1073698420] Get Characteristics
13:37:44.908 -> >>> homekit_server_on_get_characteristics: Free heap: 26016
13:37:44.908 -> >>> homekit_server_on_get_characteristics: [Client 1073698420] Query paramter id = 1.10
13:37:44.942 -> >>> homekit_server_on_get_characteristics: [Client 1073698420] Requested characteristic info for 1.10
13:37:44.942 -> >>> client_send: [Client 1073698420] send data size=107, encrypted=true
13:37:44.942 -> >>> client_send: [Client 1073698420] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A
13:37:44.942 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=107
13:37:44.979 -> >>> homekit_server_on_get_characteristics: [Client 1073698420] Requested characteristic info for 1.10
13:37:44.979 -> >>> client_send_chunk: [Client 1073698420] client_send_chunk, size=53, offset=4
13:37:44.979 -> >>> client_send: [Client 1073698420] send data size=59, encrypted=true
13:37:44.979 -> >>> client_send: [Client 1073698420] Sending payload: 35\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"value":true}]}\x0D\x0A
13:37:45.014 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=59
13:37:45.014 -> >>> client_send_chunk: [Client 1073698420] client_send_chunk, size=0, offset=3
13:37:45.014 -> >>> client_send: [Client 1073698420] send data size=5, encrypted=true
13:37:45.052 -> >>> client_send: [Client 1073698420] Sending payload: 0\x0D\x0A\x0D\x0A
13:37:45.052 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=5
13:37:45.052 -> >>> homekit_client_process: [Client 1073698420] Reading 188 bytes
13:37:45.052 -> >>> homekit_client_process: [Client 1073698420] Decrypted 170 bytes, available 0
13:37:45.052 -> Decrypted data (170 bytes): "PUT /characteristics HTTP/1.1\x0D\x0AHost: ES-B1E8._hap._tcp.local\x0D\x0AContent-Length: 50\x0D\x0AContent-Type: application/hap+json\x0D\x0A\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"ev":true}]}"
13:37:45.090 -> >>> HomeKit: [Client 1073698420] payload=<PUT /characteristics HTTP/1.1
13:37:45.090 -> Host: ES-B1E8.hap.tcp.local
13:37:45.090 -> Content-Length: 50
13:37:45.090 -> Content-Type: application/hap+json
13:37:45.090 ->
13:37:45.090 -> {"characteristics":[{"aid":1,"iid":10,"ev":true}]}>
13:37:45.136 -> >>> homekit_server_on_message_complete: http_parser message_complete
13:37:45.136 -> >>> HomeKit: [Client 1073698420] Update Characteristics
13:37:45.136 -> >>> homekit_server_on_update_characteristics: Free heap: 26112
13:37:45.136 -> >>> HomeKit: Free heap: 26104
13:37:45.136 -> >>> homekit_server_on_update_characteristics: [Client 1073698420] There were no processing errors, sending No Content response
13:37:45.136 -> >>> client_send: [Client 1073698420] send data size=27, encrypted=true
13:37:45.136 -> >>> client_send: [Client 1073698420] Sending payload: HTTP/1.1 204 No Content\x0D\x0A\x0D\x0A
13:37:45.178 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=27

Homebridge mDNS

13:37:58.565 -> >>> HomeKit: WiFiServer receives a new client (current 1, max 8)
13:37:58.565 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.213:58442
13:37:58.565 -> >>> HomeKit: [Client 1073699428] Got client content from the cache 1
13:37:58.565 -> >>> HomeKit: [Client 1073699428] new client accepted
13:37:58.602 -> >>> homekit_client_process: [Client 1073699428] Reading 142 bytes
13:37:58.602 -> >>> HomeKit: [Client 1073699428] payload=<GET /accessories HTTP/1.1
13:37:58.602 -> Accept: application/json, text/plain, /
13:37:58.602 -> User-Agent: axios/0.21.1
13:37:58.602 -> Host: 192.168.1.23:5556
13:37:58.602 -> Connection: close
13:37:58.602 ->
13:37:58.602 -> >
13:37:58.602 -> >>> homekit_server_on_message_complete: http_parser message_complete
13:37:58.602 -> !!! HomeKit: Unknown endpoint
13:37:58.602 -> >>> client_send: [Client 1073699428] send data size=26, encrypted=false
13:37:58.635 -> >>> client_send: [Client 1073699428] Sending payload: HTTP/1.1 404 Not Found\x0D\x0A\x0D\x0A
13:38:03.630 -> >>> HomeKit: [Client 1073699428] Closing client connection
13:38:03.630 -> >>> homekit_server_close_client: [Client 1073699428] The sockect is stoped
13:38:03.666 -> >>> HomeKit: [Client 0] client content free
13:38:10.466 -> >>> homekit_client_process: [Client 1073698420] Reading 188 bytes
13:38:10.466 -> >>> homekit_client_process: [Client 1073698420] Decrypted 170 bytes, available 0
13:38:10.466 -> Decrypted data (170 bytes): "PUT /characteristics HTTP/1.1\x0D\x0AHost: ES-B1E8._hap._tcp.local\x0D\x0AContent-Length: 50\x0D\x0AContent-Type: application/hap+json\x0D\x0A\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"value":0}]}"
13:38:10.505 -> >>> HomeKit: [Client 1073698420] payload=<PUT /characteristics HTTP/1.1
13:38:10.505 -> Host: ES-B1E8._hap._tcp.local
13:38:10.505 -> Content-Length: 50
13:38:10.505 -> Content-Type: application/hap+json
13:38:10.505 ->
13:38:10.505 -> {"characteristics":[{"aid":1,"iid":10,"value":0}]}>
13:38:20.590 -> >>> HomeKit: [Client 1073698420] Disconnected!

Clicked the LED in home app on Mac

13:38:21.232 -> >>> HomeKit: WiFiServer receives a new client (current 1, max 8)
13:38:21.232 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.13:61752
13:38:21.232 -> >>> HomeKit: [Client 1073699924] Got client content from the cache 1
13:38:21.284 -> >>> HomeKit: [Client 1073699924] new client accepted
13:38:21.284 -> >>> homekit_client_process: [Client 1073699924] Reading 158 bytes
13:38:21.284 -> >>> HomeKit: [Client 1073699924] payload=<POST /pair-verify HTTP/1.1
13:38:21.284 -> Host: ES-B1E8._hap._tcp.local
13:38:21.284 -> Content-Length: 37
13:38:21.284 -> Content-Type: application/pairing+tlv8
13:38:21.284 ->
13:38:21.284 -> ���� �=⸮z⸮;d⸮*@b⸮⸮iVk�⸮⸮��@⸮Q⸮⸮R⸮⸮i>
13:38:25.575 -> >>> HomeKit: [Client 1073698420] Closing client connection
13:38:25.575 -> >>> homekit_server_close_client: [Client 1073698420] The sockect is stoped
13:38:25.678 -> >>> HomeKit: [Client 0] client content free

Tried to connect with home app on iPhone

13:38:32.665 -> >>> HomeKit: WiFiServer receives a new client (current 1, max 8)
13:38:32.698 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.15:60741
13:38:32.698 -> >>> HomeKit: [Client 1073698420] Got client content from the cache 0
13:38:32.698 -> >>> HomeKit: [Client 1073698420] new client accepted
13:38:32.698 -> >>> homekit_client_process: [Client 1073698420] Reading 158 bytes
13:38:32.698 -> >>> HomeKit: [Client 1073698420] payload=<POST /pair-verify HTTP/1.1
13:38:32.698 -> Host: ES-B1E8._hap._tcp.local
13:38:32.822 -> Content-Length: 37
13:38:32.822 -> Content-Type: application/pairing+tlv8
13:38:32.822 ->
13:38:32.822 -> ���� t"⸮?⸮ ⸮�9 �⸮⸮?I⸮�㶵 ⸮5r⸮��⸮⸮
⸮^>
13:38:52.587 -> >>> HomeKit: WiFiServer receives a new client (current 2, max 8)
13:38:52.587 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.28:53276
13:38:52.587 -> >>> HomeKit: [Client 1073699556] Got client content from the cache 2
13:38:52.701 -> >>> HomeKit: [Client 1073699556] new client accepted
13:38:52.701 -> >>> homekit_client_process: [Client 1073699556] Reading 158 bytes
13:38:52.701 -> >>> HomeKit: [Client 1073699556] payload=<POST /pair-verify HTTP/1.1
13:38:52.701 -> Host: ES-B1E8._hap._tcp.local
13:38:52.701 -> Content-Length: 37
13:38:52.701 -> Content-Type: application/pairing+tlv8
13:38:52.701 ->
13:38:52.701 -> ���� ⸮�⸮��J⸮�⸮��⸮l⸮
13:38:52.701 -> ⸮⸮⸮⸮vH⸮Hϖ⸮⸮⸮⸮x⸮6>
13:39:21.237 -> >>> HomeKit: [Client 1073699924] Disconnected!
13:39:21.237 -> >>> HomeKit: WiFiServer receives a new client (current 3, max 8)
13:39:21.237 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.13:62069
13:39:21.237 -> >>> HomeKit: [Client 1073699588] Got client content from the cache 3
13:39:21.488 -> >>> HomeKit: [Client 1073699588] new client accepted
13:39:21.488 -> >>> homekit_client_process: [Client 1073699588] Reading 158 bytes
13:39:21.488 -> >>> HomeKit: [Client 1073699588] payload=<POST /pair-verify HTTP/1.1
13:39:21.488 -> Host: ES-B1E8._hap._tcp.local
13:39:21.488 -> Content-Length: 37
13:39:21.488 -> Content-Type: application/pairing+tlv8
13:39:21.488 ->
13:39:21.488 -> ���� H⸮⸮ԧ^⸮25⸮U亷�p⸮Y⸮⸮�z@⸮
13:39:21.488 -> ⸮⸮⸮rH:>
13:39:21.488 -> >>> HomeKit: WiFiServer receives a new client (current 4, max 8)
13:39:21.488 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.213:58860
13:39:21.488 -> >>> HomeKit: [Client 1073699212] Got client content from the cache 4
13:39:21.588 -> >>> HomeKit: [Client 1073699212] new client accepted
13:39:21.588 -> >>> homekit_client_process: [Client 1073699212] Reading 142 bytes
13:39:21.588 -> >>> HomeKit: [Client 1073699212] payload=<GET /accessories HTTP/1.1
13:39:21.588 -> Accept: application/json, text/plain, /
13:39:21.588 -> User-Agent: axios/0.21.1
13:39:21.588 -> Host: 192.168.1.23:5556
13:39:21.588 -> Connection: close
13:39:21.588 ->
13:39:21.588 -> >
13:39:26.232 -> >>> HomeKit: [Client 1073699924] Closing client connection
13:39:26.232 -> >>> homekit_server_close_client: [Client 1073699924] The sockect is stoped
13:39:26.312 -> >>> HomeKit: [Client 0] client content free
13:39:31.481 -> >>> HomeKit: [Client 1073699212] Disconnected!
13:39:32.767 -> >>> HomeKit: [Client 1073698420] Disconnected!
13:39:32.767 -> >>> HomeKit: WiFiServer receives a new client (current 4, max 8)
13:39:32.859 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.15:60748
13:39:32.859 -> >>> HomeKit: [Client 1073699692] Got client content from the cache 1
13:39:32.859 -> >>> HomeKit: [Client 1073699692] new client accepted
13:39:32.859 -> >>> homekit_client_process: [Client 1073699692] Reading 158 bytes
13:39:32.859 -> >>> HomeKit: [Client 1073699692] payload=<POST /pair-verify HTTP/1.1
13:39:32.859 -> Host: ES-B1E8._hap._tcp.local
13:39:32.859 -> Content-Length: 37
13:39:32.859 -> Content-Type: application/pairing+tlv8
13:39:32.859 ->
13:39:32.859 -> ���� |⸮⸮⸮j⸮@o⸮�⸮۝e⸮�⸮⸮��⸮⸮i⸮⸮⸮⸮�ԷsX>
13:39:36.495 -> >>> HomeKit: [Client 1073699212] Closing client connection
13:39:36.495 -> >>> homekit_server_close_client: [Client 1073699212] The sockect is stoped
13:39:36.495 -> >>> HomeKit: [Client 0] client content free
13:39:37.780 -> >>> HomeKit: [Client 1073698420] Closing client connection
13:39:37.780 -> >>> homekit_server_close_client: [Client 1073698420] The sockect is stoped
13:39:37.780 -> >>> HomeKit: [Client 0] client content free

@eford321
Copy link
Contributor Author

eford321 commented Mar 4, 2021

The is the mDNS from homebridge and then a response from ESP port 5556 to
NO !!! 5556 is my Apple Port ! MDNS port is 5353

There is no unicast traffic between ESP and Homebridge. ESP might think there is, but Wireshark doesn't see it.
Here is capture of Mac Home app(.13) and ESP(.23) with homebridge(.213). Wireshark filter is any unicast from ESP and (mdns from homebridge).
Screen Shot 2021-03-04 at 2 35 27 PM

Here is the matching log. Note there is no unicast to/from ESP:5556 and Homebridge:37498, even though ESP says there is:

14:02:29.567 -> 192.168.1.23
14:02:29.567 -> Free heap: 34320
14:02:29.567 -> init_hap_storage>>> HomeKit: init_storage_ex size 0x1c1
14:02:29.567 -> >>> Home Integration: hap_services added chararacteristic 0: 23
14:02:29.567 -> >>> Home Integration: hap_services added chararacteristic 1: 25
14:02:29.567 -> >>> Home Integration: homekit_is_paired 1
14:02:29.567 -> >>> HomeKit: Free heap: 32576
14:02:29.567 -> >>> server_new: WiFiServer begin at port: 5556
14:02:29.607 ->
14:02:29.607 -> >>> HomeKit: Starting server
14:02:29.607 -> >>> HomeKit: storage init 0
14:02:29.607 -> >>> HomeKit: Using existing accessory ID: B1:E8:4D:32:98:71
14:02:29.607 -> >>> HomeKit: find pairings
14:02:29.607 -> >>> HomeKit: Found admin pairing with 6FDD5BE0-78E1-4A4C-B5D7-98277EEFA239, disabling pair setup
14:02:29.607 -> >>> HomeKit: Configuring mDNS
14:02:29.607 -> >>> HomeKit: Wifi Sleep type:2
14:02:29.607 -> >>> HomeKit: Set Wifi Sleep type :0
14:02:29.607 -> >>> HomeKit: MDNS.begin: ES-B1E8, IP: 192.168.1.23
14:02:29.607 -> >>> homekit_mdns_init: Accessory Setup ID = YK72
14:02:29.690 -> >>> HomeKit: Init server over
14:02:40.751 -> >>> HomeKit: WiFiServer receives a new client (current 0, max 8)
14:02:40.751 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.13:63634
14:02:40.789 -> >>> HomeKit: [Client 1073698420] Got client content from the cache 0
14:02:40.789 -> >>> HomeKit: [Client 1073698420] new client accepted
14:02:40.969 -> >>> homekit_client_process: [Client 1073698420] Reading 158 bytes
14:02:40.969 -> >>> HomeKit: [Client 1073698420] payload=<POST /pair-verify HTTP/1.1
14:02:40.969 -> Host: ES-B1E8.hap.tcp.local
14:02:40.969 -> Content-Length: 37
14:02:40.969 -> Content-Type: application/pairing+tlv8
14:02:40.969 ->
14:02:40.969 -> ���� J8r⸮p⸮d 5a⸮�g�(c>⸮SY⸮;q⸮�Ok<h⸮>B>
14:02:40.969 -> >>> homekit_server_on_message_complete: http_parser message_complete
14:02:40.969 -> >>> homekit_server_on_pair_verify: HomeKit Pair Verify
14:02:41.006 -> >>> homekit_server_on_pair_verify: Free heap: 26120
14:02:41.006 -> >>> tlv_debug: Got following TLV values:
14:02:41.006 -> >>> tlv_debug: Type 6 value (1 bytes): \x01
14:02:41.006 -> >>> tlv_debug: Type 3 value (32 bytes): J8r\x94p\xBBd 5a\xFE\x14g�(c>\xC7SY\xA2;q\xB1\x01Ok<h\x92>B
14:02:41.006 -> >>> HomeKit: [Client 1073698420] Pair Verify Step 1/2
14:02:41.006 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Importing device Curve25519 public key
14:02:41.130 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Generating accessory Curve25519 key
14:02:41.293 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Exporting accessory Curve25519 public key
14:02:41.293 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Generating Curve25519 shared secret
14:02:41.293 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Generating signature
14:02:41.377 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Generating proof
14:02:41.377 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Encrypting response
14:02:41.377 -> >>> send_tlv_response: [Client 1073698420] Sending TLV response
14:02:41.377 -> >>> tlv_debug: Got following TLV values:
14:02:41.377 -> >>> tlv_debug: Type 6 value (1 bytes): \x02
14:02:41.432 -> >>> tlv_debug: Type 3 value (32 bytes): \xAF\xDD\xDD3rN\xEE\x9C\x94\xE6\xB2\x16\xA6\x80\x0F\xDA\xE5"\xD1i\x0E\xD6\xF5E\xFE4\xE3{\x06\xC3\x92
14:02:41.432 -> >>> tlv_debug: Type 5 value (101 bytes): ;j\xB5\x0Bq\x87T\xB3g\xBE&\x1E\xEA\xB0\xE8\xC3\xDD\x02\x86\xAC\x03\x09\xEE)\xE8\xBDm\xB7u\xA2\xB6\xC6%\xCF\xBA\x95\x09 B\x89\xD5f\xBD\xA6\x91"\x85*FQ\x83\x9DZz~0(3\x15 yg\xE9\xF1-\xD5T\x00.\xFBz\xFB\x19\x97\xF1\xB94\xBC\x8EI\xC9\x83i\xF4:-\xCC\xD4\xD4w&\xA5\x81\x0D\x0D@\xDE"\xE0\x11 14:02:41.432 -> >>> client_send: [Client 1073698420] send data size=244, encrypted=false 14:02:41.432 -> >>> client_send: [Client 1073698420] 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\x02\x03 \xAF\xDD\xDD3rN\xEE\x9C\x94\xE6\xB2\x16\xA6\x80\x0F\xDA\xE5"\xD1i\x0E\xD6\xF5E\xFE4\xE3{\x06\xC3\x92 \x05e;j\xB5\x0Bq\x87T\xB3g\xBE&\x1E\xEA\xB0\xE8\xC3\xDD\x02\x86\xAC\x03\x09\xEE)\xE8\xBDm\xB7u\xA2\xB6\xC6%\xCF\xBA\x95\x09 B\x89\xD5f\xBD\xA6\x91"\x85*FQ\x83\x9DZz~0(3\x15 yg\xE9\xF1-\xD5T\x00.\xFBz\xFB\x19\x97\xF1\xB94\xBC\x8EI\xC9\x83i\xF4:-\xCC\xD4\xD4w&\xA5\x81\x0D\x0D@\xDE"\xE0\x11
14:02:41.723 -> >>> HomeKit: Free heap: 25920
14:02:41.723 -> >>> homekit_client_process: [Client 1073698420] Reading 247 bytes
14:02:41.723 -> >>> HomeKit: [Client 1073698420] payload=<POST /pair-verify HTTP/1.1
14:02:41.761 -> Host: ES-B1E8.hap.tcp.local
14:02:41.761 -> Content-Length: 125
14:02:41.761 -> Content-Type: application/pairing+tlv8
14:02:41.761 ->
14:02:41.761 -> �x⸮LJ⸮y⸮�T%Ut⸮⸮⸮�&h⸮�⸮⸮⸮6B⸮⸮yDd⸮⸮�⸮⸮⸮u⸮7⸮n⸮c⸮ ⸮⸮⸮E��⸮�&W⸮�ʼ⸮ u⸮⸮�⸮Bɏ⸮⸮o8⸮⸮⸮⸮⸮DУ⸮5r⸮;�⸮⸮⸮s⸮O�$⸮V⸮⸮q⸮⸮⸮ّ⸮⸮⸮⸮J⸮Yf��⸮���>
14:02:41.761 -> >>> homekit_server_on_message_complete: http_parser message_complete
14:02:41.761 -> >>> homekit_server_on_pair_verify: HomeKit Pair Verify
14:02:41.761 -> >>> homekit_server_on_pair_verify: Free heap: 25832
14:02:41.761 -> >>> tlv_debug: Got following TLV values:
14:02:41.807 -> >>> tlv_debug: Type 5 value (120 bytes): \xD0LJ\xDFy\xDC\x0BT%Ut\xC1\x9B\xF6\x12&h\xA9\x1D\xB7\x90\xE9\xA26B\xB1\x9ByDd\x87\xFF\x01\xFC\xB4\xFEu\xB47\xEAn\xACc\xB8\x09\xA8\xA4\xCDE\x15\x14\xDB\x10&W\xF2\xB4\x1E\xCA\xBC\xC9 u\xC4\xF8\x1E\xF8B\xC9\x8F\xCA\xEFo8\xDD\xF6\xDA\xDB\xCFD\xD0\xA3\xF65r\xE7;\x05\x8D\xD9\xF4s\xC1O\x1A$\xA6V\xBF\x97q\xEB\xF6\xAF\xEF\x8D\xB8\xD9\x91\x8E\xB0\xFA\xE0J\xB0Yf\x03\x08\x91
14:02:41.807 -> >>> tlv_debug: Type 6 value (1 bytes): \x03
14:02:41.807 -> >>> HomeKit: [Client 1073698420] Pair Verify Step 2/2
14:02:41.839 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Decrypting payload
14:02:41.839 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Searching pairing with 6FDD5BE0-78E1-4A4C-B5D7-98277EEFA239
14:02:41.839 -> >>> HomeKit: [Client 1073698420] Found pairing with 6FDD5BE0-78E1-4A4C-B5D7-98277EEFA239
14:02:41.839 -> >>> homekit_server_on_pair_verify: [Client 1073698420] Verifying device signature
14:02:42.640 -> >>> send_tlv_response: [Client 1073698420] Sending TLV response
14:02:42.640 -> >>> tlv_debug: Got following TLV values:
14:02:42.640 -> >>> tlv_debug: Type 6 value (1 bytes): \x04
14:02:42.640 -> >>> client_send: [Client 1073698420] send data size=105, encrypted=false
14:02:42.640 -> >>> client_send: [Client 1073698420] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/pairing+tlv8\x0D\x0AContent-Length: 3\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A\x06\x01\x04
14:02:42.753 -> >>> HomeKit: [Client 1073698420] Verification successful, secure session established
14:02:42.753 -> >>> HomeKit: Free heap: 26032
14:02:42.753 -> >>> homekit_client_process: [Client 1073698420] Reading 78 bytes
14:02:42.753 -> >>> homekit_client_process: [Client 1073698420] Decrypted 60 bytes, available 0
14:02:42.753 -> Decrypted data (60 bytes): "GET /accessories HTTP/1.1\x0D\x0AHost: ES-B1E8.hap.tcp.local\x0D\x0A\x0D\x0A"
14:02:42.789 -> >>> HomeKit: [Client 1073698420] payload=<GET /accessories HTTP/1.1
14:02:42.789 -> Host: ES-B1E8.hap.tcp.local
14:02:42.789 ->
14:02:42.789 -> >
14:02:42.789 -> >>> homekit_server_on_message_complete: http_parser message_complete
14:02:42.789 -> >>> HomeKit: [Client 1073698420] Get Accessories
14:02:42.789 -> >>> homekit_server_on_get_accessories: Free heap: 26168
14:02:42.789 -> >>> client_send: [Client 1073698420] send data size=107, encrypted=true
14:02:42.789 -> >>> client_send: [Client 1073698420] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A
14:02:42.824 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=107
14:02:42.824 -> >>> homekit_server_on_get_accessories: [Client 1073698420] Get Accessories, start send json body
14:02:42.857 -> >>> client_send_chunk: [Client 1073698420] client_send_chunk, size=1012, offset=5
14:02:42.857 -> >>> client_send: [Client 1073698420] send data size=1019, encrypted=true
14:02:42.857 -> >>> client_send: [Client 1073698420] Sending payload: 3f4\x0D\x0A{"accessories":[{"aid":1,"services":[{"iid":1,"type":"3E","hidden":false,"primary":false,"characteristics":[{"aid":1,"iid":2,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"ES"},{"aid":1,"iid":3,"type":"20","perms":["pr"],"description":"Manufacturer","format":"string","value":"Yurik72"},{"aid":1,"iid":4,"type":"30","perms":["pr"],"description":"Serial Number","format":"string","value":"0"},{"aid":1,"iid":5,"type":"21","perms":["pr"],"description":"Model","format":"string","value":"EspHapLed"},{"aid":1,"iid":6,"type":"52","perms":["pr"],"description":"Firmware Revision","format":"string","value":"1.0"},{"aid":1,"iid":7,"type":"14","perms":["pw"],"description":"Identify","format":"bool"}]},{"iid":8,"type":"43","hidden":false,"primary":true,"characteristics":[{"aid":1,"iid":9,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"Led"},{"aid":1,"iid":10,"type":"25","perms":["pr","pw","ev"],"ev":false,"description":"On","format":"bool","value":true}]}]}]}\x0D\x0A
14:02:42.964 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=1019
14:02:42.964 -> >>> client_send_chunk: [Client 1073698420] client_send_chunk, size=0, offset=3
14:02:43.001 -> >>> client_send: [Client 1073698420] send data size=5, encrypted=true
14:02:43.001 -> >>> client_send: [Client 1073698420] Sending payload: 0\x0D\x0A\x0D\x0A
14:02:43.001 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=5
14:02:43.038 -> >>> homekit_client_process: [Client 1073698420] Reading 90 bytes
14:02:43.038 -> >>> homekit_client_process: [Client 1073698420] Decrypted 72 bytes, available 0
14:02:43.038 -> Decrypted data (72 bytes): "GET /characteristics?id=1.10 HTTP/1.1\x0D\x0AHost: ES-B1E8.hap.tcp.local\x0D\x0A\x0D\x0A"
14:02:43.038 -> >>> HomeKit: [Client 1073698420] payload=<GET /characteristics?id=1.10 HTTP/1.1
14:02:43.079 -> Host: ES-B1E8.hap.tcp.local
14:02:43.079 ->
14:02:43.079 -> >
14:02:43.079 -> >>> homekit_server_on_message_complete: http_parser message_complete
14:02:43.079 -> >>> HomeKit: [Client 1073698420] Get Characteristics
14:02:43.079 -> >>> homekit_server_on_get_characteristics: Free heap: 26016
14:02:43.079 -> >>> homekit_server_on_get_characteristics: [Client 1073698420] Query paramter id = 1.10
14:02:43.079 -> >>> homekit_server_on_get_characteristics: [Client 1073698420] Requested characteristic info for 1.10
14:02:43.079 -> >>> client_send: [Client 1073698420] send data size=107, encrypted=true
14:02:43.138 -> >>> client_send: [Client 1073698420] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A
14:02:43.138 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=107
14:02:43.138 -> >>> homekit_server_on_get_characteristics: [Client 1073698420] Requested characteristic info for 1.10
14:02:43.138 -> >>> client_send_chunk: [Client 1073698420] client_send_chunk, size=53, offset=4
14:02:43.138 -> >>> client_send: [Client 1073698420] send data size=59, encrypted=true
14:02:43.193 -> >>> client_send: [Client 1073698420] Sending payload: 35\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"value":true}]}\x0D\x0A
14:02:43.193 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=59
14:02:43.193 -> >>> client_send_chunk: [Client 1073698420] client_send_chunk, size=0, offset=3
14:02:43.193 -> >>> client_send: [Client 1073698420] send data size=5, encrypted=true
14:02:43.193 -> >>> client_send: [Client 1073698420] Sending payload: 0\x0D\x0A\x0D\x0A
14:02:43.193 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=5
14:02:43.224 -> >>> homekit_client_process: [Client 1073698420] Reading 188 bytes
14:02:43.224 -> >>> homekit_client_process: [Client 1073698420] Decrypted 170 bytes, available 0
14:02:43.224 -> Decrypted data (170 bytes): "PUT /characteristics HTTP/1.1\x0D\x0AHost: ES-B1E8.hap.tcp.local\x0D\x0AContent-Length: 50\x0D\x0AContent-Type: application/hap+json\x0D\x0A\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"ev":true}]}"
14:02:43.256 -> >>> HomeKit: [Client 1073698420] payload=<PUT /characteristics HTTP/1.1
14:02:43.256 -> Host: ES-B1E8.hap.tcp.local
14:02:43.256 -> Content-Length: 50
14:02:43.256 -> Content-Type: application/hap+json
14:02:43.290 ->
14:02:43.290 -> {"characteristics":[{"aid":1,"iid":10,"ev":true}]}>
14:02:43.290 -> >>> homekit_server_on_message_complete: http_parser message_complete
14:02:43.290 -> >>> HomeKit: [Client 1073698420] Update Characteristics
14:02:43.290 -> >>> homekit_server_on_update_characteristics: Free heap: 26112
14:02:43.290 -> >>> HomeKit: Free heap: 26104
14:02:43.290 -> >>> homekit_server_on_update_characteristics: [Client 1073698420] There were no processing errors, sending No Content response
14:02:43.328 -> >>> client_send: [Client 1073698420] send data size=27, encrypted=true
14:02:43.328 -> >>> client_send: [Client 1073698420] Sending payload: HTTP/1.1 204 No Content\x0D\x0A\x0D\x0A
14:02:43.328 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=27
14:02:53.419 -> >>> homekit_client_process: [Client 1073698420] Reading 90 bytes
14:02:53.419 -> >>> homekit_client_process: [Client 1073698420] Decrypted 72 bytes, available 0
14:02:53.457 -> Decrypted data (72 bytes): "GET /characteristics?id=1.10 HTTP/1.1\x0D\x0AHost: ES-B1E8.hap.tcp.local\x0D\x0A\x0D\x0A"
14:02:53.457 -> >>> HomeKit: [Client 1073698420] payload=<GET /characteristics?id=1.10 HTTP/1.1
14:02:53.457 -> Host: ES-B1E8.hap.tcp.local
14:02:53.457 ->
14:02:53.457 -> >
14:02:53.457 -> >>> homekit_server_on_message_complete: http_parser message_complete
14:02:53.457 -> >>> HomeKit: [Client 1073698420] Get Characteristics
14:02:53.457 -> >>> homekit_server_on_get_characteristics: Free heap: 26112
14:02:53.526 -> >>> homekit_server_on_get_characteristics: [Client 1073698420] Query paramter id = 1.10
14:02:53.526 -> >>> homekit_server_on_get_characteristics: [Client 1073698420] Requested characteristic info for 1.10
14:02:53.526 -> >>> client_send: [Client 1073698420] send data size=107, encrypted=true
14:02:53.526 -> >>> client_send: [Client 1073698420] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A
14:02:53.526 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=107
14:02:53.526 -> >>> homekit_server_on_get_characteristics: [Client 1073698420] Requested characteristic info for 1.10
14:02:53.526 -> >>> client_send_chunk: [Client 1073698420] client_send_chunk, size=53, offset=4
14:02:53.582 -> >>> client_send: [Client 1073698420] send data size=59, encrypted=true
14:02:53.582 -> >>> client_send: [Client 1073698420] Sending payload: 35\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"value":true}]}\x0D\x0A
14:02:53.582 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=59
14:02:53.613 -> >>> client_send_chunk: [Client 1073698420] client_send_chunk, size=0, offset=3
14:02:53.613 -> >>> client_send: [Client 1073698420] send data size=5, encrypted=true
14:02:53.613 -> >>> client_send: [Client 1073698420] Sending payload: 0\x0D\x0A\x0D\x0A
14:02:53.613 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=5
14:02:53.772 -> >>> homekit_client_process: [Client 1073698420] Reading 90 bytes
14:02:53.772 -> >>> homekit_client_process: [Client 1073698420] Decrypted 72 bytes, available 0
14:02:53.772 -> Decrypted data (72 bytes): "GET /characteristics?id=1.10 HTTP/1.1\x0D\x0AHost: ES-B1E8.hap.tcp.local\x0D\x0A\x0D\x0A"
14:02:53.772 -> >>> HomeKit: [Client 1073698420] payload=<GET /characteristics?id=1.10 HTTP/1.1
14:02:53.828 -> Host: ES-B1E8.hap.tcp.local
14:02:53.828 ->
14:02:53.828 -> >
14:02:53.828 -> >>> homekit_server_on_message_complete: http_parser message_complete
14:02:53.828 -> >>> HomeKit: [Client 1073698420] Get Characteristics
14:02:53.828 -> >>> homekit_server_on_get_characteristics: Free heap: 26112
14:02:53.828 -> >>> homekit_server_on_get_characteristics: [Client 1073698420] Query paramter id = 1.10
14:02:53.828 -> >>> homekit_server_on_get_characteristics: [Client 1073698420] Requested characteristic info for 1.10
14:02:53.828 -> >>> client_send: [Client 1073698420] send data size=107, encrypted=true
14:02:53.828 -> >>> client_send: [Client 1073698420] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A
14:02:53.936 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=107
14:02:53.936 -> >>> homekit_server_on_get_characteristics: [Client 1073698420] Requested characteristic info for 1.10
14:02:53.936 -> >>> client_send_chunk: [Client 1073698420] client_send_chunk, size=53, offset=4
14:02:53.936 -> >>> client_send: [Client 1073698420] send data size=59, encrypted=true
14:02:53.936 -> >>> client_send: [Client 1073698420] Sending payload: 35\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"value":true}]}\x0D\x0A
14:02:53.973 -> >>> client_send_encrypted
: [Client 1073698420] client_send_encrypted
size=59
14:02:53.973 -> >>> client_send_chunk: [Client 1073698420] client_send_chunk, size=0, offset=3
14:02:53.973 -> >>> client_send: [Client 1073698420] send data size=5, encrypted=true
14:02:53.973 -> >>> client_send: [Client 1073698420] Sending payload: 0\x0D\x0A\x0D\x0A
14:02:53.973 -> >>> client_send_encrypted_: [Client 1073698420] client_send_encrypted_ size=5

Homebridge mdns

14:03:02.686 -> >>> HomeKit: WiFiServer receives a new client (current 1, max 8)
14:03:02.686 -> >>> HomeKit: Got new client connection: local 192.168.1.23:5556, remote 192.168.1.213:37498
14:03:02.686 -> >>> HomeKit: [Client 1073698804] Got client content from the cache 1
14:03:02.719 -> >>> HomeKit: [Client 1073698804] new client accepted
14:03:02.719 -> >>> homekit_client_process: [Client 1073698804] Reading 142 bytes
14:03:02.719 -> >>> HomeKit: [Client 1073698804] payload=<GET /accessories HTTP/1.1
14:03:02.719 -> Accept: application/json, text/plain, /
14:03:02.719 -> User-Agent: axios/0.21.1
14:03:02.719 -> Host: 192.168.1.23:5556
14:03:02.719 -> Connection: close
14:03:02.758 ->
14:03:02.758 -> >
14:03:02.758 -> >>> homekit_server_on_message_complete: http_parser message_complete
14:03:02.758 -> !!! HomeKit: Unknown endpoint
14:03:02.758 -> >>> client_send: [Client 1073698804] send data size=26, encrypted=false
14:03:02.758 -> >>> client_send: [Client 1073698804] Sending payload: HTTP/1.1 404 Not Found\x0D\x0A\x0D\x0A
14:03:07.773 -> >>> HomeKit: [Client 1073698804] Closing client connection
14:03:07.773 -> >>> homekit_server_close_client: [Client 1073698804] The sockect is stoped
14:03:07.809 -> >>> HomeKit: [Client 0] client content free

Also,

Note the log begins with:

14:02:29.567 -> >>> server_new: WiFiServer begin at port: 5556

Yurik72 added a commit that referenced this issue Mar 5, 2021
@Yurik72
Copy link
Owner

Yurik72 commented Mar 5, 2021 via email

@EIBHomeControl
Copy link
Contributor

If you have the Homebridge config ui installed, it show also the accessories. I think this is why it pulls the informations.

@Yurik72
Copy link
Owner

Yurik72 commented Mar 5, 2021 via email

@EIBHomeControl
Copy link
Contributor

EIBHomeControl commented Mar 5, 2021

just done a quick test. seems to work.

lets see what @eford321 says.

@eford321
Copy link
Contributor Author

eford321 commented Mar 5, 2021

GOOD NEWS ! Thanks for your patient and help Your logs 14:03:02.719 -> >>> HomeKit: [Client 1073698804] payload=<GET /accessories HTTP/1.1 14:03:02.719 -> Accept: application/json, text/plain, / 14:03:02.719 -> User-Agent: axios/0.21.1 14:03:02.719 -> Host: 192.168.1.23:5556 14:03:02.719 -> Connection: close 14:03:02.758 -> 14:03:02.758 -> > Exactly what I need, based on that I found root cause and FIXED issue

Great News! Nice work. new commit is working for me!

If you interesting, problem was related to Connection: close header. After that ESP is dead, It was my mistake due to the optimization, I didn’t reinitialize a parser Ok, you can get latest commit…. Additionally, As you see HomeBridge asking ESP about Accessories. I don’t know why and for what reason, because not very familiar with Homebridge.

I assume Homebridge is looking for other instances of Homebridge or other bridges.

Due to this question is not Encrypted, ESP doesn’t process this request. (For info Apple devices sent this request as encrypted, due to mDNS publish “sh” flag). Based on your previous logs(wireshark), I saw that your other device are not publish this flag, means communication is not encrypted Currently is not a problem at all to reply to this request. I can easily implement, just tell me. Maybe there are some functions on HomeBridge which we lost

I don't see any functionality lost in Homebridge. There might be plugins that use the responses, but my configuration does not.

@eford321
Copy link
Contributor Author

eford321 commented Mar 5, 2021

If you have the Homebridge config ui installed, it show also the accessories. I think this is why it pulls the informations.

Do you see non-Homebridge accessories in config ui? I only see devices listed in config.json. None of my HAP devices show up.

@chrwh
Copy link

chrwh commented Mar 5, 2021

I have the same issue, where can I get the latest commit? If I just use the button and download ZIP on the main page it still says V.1.0.7?

@EIBHomeControl
Copy link
Contributor

If you have the Homebridge config ui installed, it show also the accessories. I think this is why it pulls the informations.

Do you see non-Homebridge accessories in config ui? I only see devices listed in config.json. None of my HAP devices show up.

No. I also see only devices in the config.json.

@eford321
Copy link
Contributor Author

eford321 commented Mar 5, 2021

I have the same issue, where can I get the latest commit? If I just use the button and download ZIP on the main page it still says V.1.0.7?

Make sure the commit is the latest:
Screen Shot 2021-03-05 at 10 17 48 AM

@chrwh
Copy link

chrwh commented Mar 5, 2021

OK, read the readme file, is the fixed issue only related to ESP32 and NOT ESP8266 ??

@eford321
Copy link
Contributor Author

eford321 commented Mar 5, 2021

Tested with an ESP32 and it also works. Tested with EspHapLed example.

@eford321 eford321 closed this as completed Mar 5, 2021
@Yurik72
Copy link
Owner

Yurik72 commented Mar 6, 2021 via email

@eford321
Copy link
Contributor Author

eford321 commented Mar 6, 2021

FYI, I have 4 devices running ESPHap in my network with more than 24 hours uptime. Working well with more than 20000 free heap. Great job fixing the issues!

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

4 participants