search

maximkulkin / esp-homekit

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

accessory not discoverable right after wifi configuration and connection to AP #34

Closed ageorgios closed 6 years ago

ageorgios commented 6 years ago

Tried using wifi_config.h but when it connects to the AP the homekit device is not discoverable and it needs a reset.

void on_wifi_ready() {
    homekit_server_init(&config);
}

void user_init(void) {
    uart_set_baud(0, 115200);
    create_accessory_name();
    gpio_init();
    wifi_config_init("ESP-Homekit-Motor", NULL, on_wifi_ready);
}
maximkulkin commented 6 years ago

logs please

ageorgios commented 6 years ago

This is a case where ERASE->FLASH->CONNECT AP->PAIR(fails)

Booting rom 0.
pp_task_hdl : 3ffefdd0, prio:14, stack:512
pm_task_hdl : 3ffef830, prio:1, stack:176
frc2_timer_task_hdl:0x3fff3de0, prio:12, stack:200

ESP-Open-SDK ver: 0.0.1 compiled @ Feb 28 2018 21:43:08
phy ver: 273, pp ver: 8.3

>>> wifi_config: wifi_config_station_connect: No configuration found
>>> wifi_config: Starting AP mode
>>> wifi_config: wifi_config_softap_start: Starting AP SSID=ESP-Homekit-Motor-121C4C
>>> wifi_config: Starting DHCP server
mode : sta(a0:20:a6:12:1c:4c) + softAP(a2:20:a6:12:1c:4c)
add if0
add if1
bcn 100
>>> wifi_config: Starting WiFi scan
>>> wifi_config: Starting DNS server
>>> wifi_config: Staring HTTP server
scandone
scandone
add 1
aid 1
station: 04:54:53:07:3d:db join, AID = 1
>>> wifi_config: http_task: Got 64 incomming data
!!! wifi_config: Unknown endpoint: GET /hotspot-detect.html
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 3 incomming data
>>> wifi_config: wifi_config_server_on_message_complete: Unknown endpoint
>>> wifi_config: client_send_redirect: Redirecting to http://192.168.4.1/settings
scandone
>>> wifi_config: Client disconnected
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 50 incomming data
>>> wifi_config: Client disconnected
>>> wifi_config: http_task: Got 64 incomming data
!!! wifi_config: Unknown endpoint: GET /hotspot-detect.html
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 26 incomming data
>>> wifi_config: wifi_config_server_on_message_complete: Unknown endpoint
>>> wifi_config: client_send_redirect: Redirecting to http://192.168.4.1/settings
>>> wifi_config: Client disconnected
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 9 incomming data
>>> wifi_config: Client disconnected
>>> wifi_config: http_task: Got 64 incomming data
!!! wifi_config: Unknown endpoint: GET /hotspot-detect.html
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 3 incomming data
>>> wifi_config: wifi_config_server_on_message_complete: Unknown endpoint
>>> wifi_config: client_send_redirect: Redirecting to http://192.168.4.1/settings
>>> wifi_config: Client disconnected
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 50 incomming data
>>> wifi_config: Client disconnected
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 44 incomming data
>>> wifi_config: wifi_config_server_on_settings_update: Update settings, body = ssid=MG&password=1234567%21
scandone
>>> wifi_config: Found configuration, connecting to MG
>>> wifi_config: Client disconnected
>>> wifi_config: http_task: Got 64 incomming data
!!! wifi_config: Unknown endpoint: GET /hotspot-detect.html
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 3 incomming data
>>> wifi_config: wifi_config_server_on_message_complete: Unknown endpoint
>>> wifi_config: client_send_redirect: Redirecting to http://192.168.4.1/settings
>>> wifi_config: Client disconnected
>>> wifi_config: http_task: Got 64 incomming data
>>> wifi_config: http_task: Got 50 incomming data
>>> wifi_config: Client disconnected
scandone
add 0
aid 21
cnt

connected with MG, channel 11
dhcp client start...
ip:192.168.178.68,mask:255.255.255.0,gw:192.168.178.1
>>> wifi_config: wifi_config_sta_connect_timeout_callback: Successfully connected
station: 04:54:53:07:3d:db leave, AID = 1
rm match
bcn 0
del if1
mode : sta(a0:20:a6:12:1c:4c)
Function called without core lock
Window Task Commands initialized
Window Task State initialized with Delay: 10 ticks
>>> HomeKit: Starting server
>>> HomeKit: Formatting flash at 0x7a000
>>> HomeKit: Generated new accessory ID: 19:A6:28:A4:DE:3A
>>> HomeKit: Generated new accessory key
Function called without core lock
Function called without core lock
Function called without core lock
Function called without core lock
Function called without core lock
Function called without core lock
Function called without core lock
Function called without core lock
Function called without core lock
>>> HomeKit: Configuring mDNS
Function called without core lock
Function called without core lock
Function called without core lock
Function called without core lock
Function called without core lock
>>> homekit_run_server: Staring HTTP server
>>> HomeKit: Got new client connection: 6
>>> homekit_client_process: [Client 6] Got 159 incomming data
>>> homekit_server_on_pair_setup: Pair Setup
>>> homekit_server_on_pair_setup: Free heap: 17656
>>> tlv_debug: Got following TLV values:
>>> tlv_debug: Type 6 value (1 bytes): \x01
>>> tlv_debug: Type 0 value (1 bytes): \x00
>>> HomeKit: [Client 6] Pair Setup Step 1/3
>>> homekit_server_on_pair_setup: Free heap: 17568
>>> crypto_srp_new: Initializing SRP
>>> homekit_server_on_pair_setup: [Client 6] Initializing crypto
>>> homekit_server_on_pair_setup: Free heap: 16904
>>> homekit_server_on_pair_setup: [Client 6] Using user-specified password: 111-11-111
>>> crypto_srp_init: Generating salt
>>> crypto_srp_init: Setting SRP username
>>> crypto_srp_init: Setting SRP params
>>> crypto_srp_init: Setting SRP password
>>> crypto_srp_init: Getting SRP verifier
>>> crypto_srp_init: Failed to get SRP verifier (code -2)
>>> crypto_srp_get_public_key: Calculating public key
!!! HomeKit: [Client 6] Failed to dump SPR public key (code -2)
>>> send_tlv_response: [Client 6] Sending TLV response
>>> tlv_debug: Got following TLV values:
>>> tlv_debug: Type 7 value (1 bytes): \x01
>>> tlv_debug: Type 6 value (1 bytes): \x02
>>> client_send: [Client 6] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/pairing+tlv8\x0D\x0AContent-Length: 6\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A\x07\x01\x01\x06\x01\x02
>>> homekit_client_process: [Client 6] Finished processing
>>> HomeKit: [Client 6] Closing client connection
>>> HomeKit: Got new client connection: 6
>>> homekit_client_process: [Client 6] Got 159 incomming data
>>> homekit_server_on_pair_setup: Pair Setup
>>> homekit_server_on_pair_setup: Free heap: 17664
>>> tlv_debug: Got following TLV values:
>>> tlv_debug: Type 6 value (1 bytes): \x01
>>> tlv_debug: Type 0 value (1 bytes): \x00
>>> HomeKit: [Client 6] Pair Setup Step 1/3
>>> homekit_server_on_pair_setup: Free heap: 17576
>>> crypto_srp_new: Initializing SRP
>>> homekit_server_on_pair_setup: [Client 6] Initializing crypto
>>> homekit_server_on_pair_setup: Free heap: 16912
>>> homekit_server_on_pair_setup: [Client 6] Using user-specified password: 111-11-111
>>> crypto_srp_init: Generating salt
>>> crypto_srp_init: Setting SRP username
>>> crypto_srp_init: Setting SRP params
>>> crypto_srp_init: Setting SRP password
>>> crypto_srp_init: Getting SRP verifier
>>> crypto_srp_init: Failed to get SRP verifier (code -2)
>>> crypto_srp_get_public_key: Calculating public key
!!! HomeKit: [Client 6] Failed to dump SPR public key (code -2)
>>> send_tlv_response: [Client 6] Sending TLV response
>>> tlv_debug: Got following TLV values:
>>> tlv_debug: Type 7 value (1 bytes): \x01
>>> tlv_debug: Type 6 value (1 bytes): \x02
>>> client_send: [Client 6] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/pairing+tlv8\x0D\x0AContent-Length: 6\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A\x07\x01\x01\x06\x01\x02
>>> homekit_client_process: [Client 6] Finished processing
>>> HomeKit: [Client 6] Closing client connection
maximkulkin commented 6 years ago

!!! HomeKit: [Client 6] Failed to dump SPR public key (code -2)

Code "-2" means "out of memory".

>>> HomeKit: [Client 6] Pair Setup Step 1/3 >>> homekit_server_on_pair_setup: Free heap: 17576

At this point you should have at least ~23K of RAM, otherwise crypto will fail.

This could be related to memory leak in wifi_config which I'm working on now, but also it could be related to stuff that YOU allocate (e.g. your own tasks). Usually wifi_config consumes ~15K which leaves RAM down to ~27K which should be sufficient for pairing.

ageorgios commented 6 years ago

Thanks for your clarifications,

the init proc is above, nothing memory intensive

maximkulkin commented 6 years ago

Then I suggest you to reset (power cycle) accessory after configuring WiFi before pairing until I fix memory usage in wifi_config.

ageorgios commented 6 years ago

Thanks for the great work!