maximkulkin / esp-homekit

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

Can’t pair with the flashed device #135

Closed benchuk closed 4 years ago

benchuk commented 4 years ago

Hi, I have build the firmeware using the latest esp idf docker env Everything seems to build Ok and I am able To flash and monitor the app But I cannot discover the homekit device on my ios device, seems to me like an mdns issue, but I am not sure Cloud it be becuase I am building over esp idf and not the rtos one?

My device is an esp32-cam And the example I have tried are led and also the camera project from the camera repo which is my end goal Thanks

maximkulkin commented 4 years ago

When trying LED example (I assume examples/esp32/led from esp-homekit-demo repository), did you set up wifi.h correctly? What do you see in logs on device?

benchuk commented 4 years ago

Thanks for the replay, I have updated the wifi file and I can verify that I am connected, I do have ping and the esp is listed on the router dhcp, so as for wifi connectivity everything seems to be ok

maximkulkin commented 4 years ago

Can you show logs?

benchuk commented 4 years ago

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT) configsip: 0, SPIWP:0xee clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00 mode:DIO, clock div:2 load:0x3fff0018,len:4 load:0x3fff001c,len:7060 load:0x40078000,len:14816 load:0x40080400,len:4456 entry 0x400806e8 I (72) boot: Chip Revision: 1 I (72) boot_comm: chip revision: 1, min. bootloader chip revision: 0 I (39) boot: ESP-IDF v4.1-dev-1572-g30372f5a4 2nd stage bootloader I (39) boot: compile time 00:59:59 I (39) boot: Enabling RNG early entropy source... I (45) boot: SPI Speed : 40MHz I (49) boot: SPI Mode : DIO I (53) boot: SPI Flash Size : 4MB I (57) boot: Partition Table: I (61) boot: ## Label Usage Type ST Offset Length I (68) boot: 0 nvs WiFi data 01 02 00009000 00006000 I (76) boot: 1 phy_init RF data 01 01 0000f000 00001000 I (83) boot: 2 factory factory app 00 00 00010000 00200000 I (91) boot: End of partition table I (95) boot_comm: chip revision: 1, min. application chip revision: 0 I (102) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x71034 (462900) map I (276) esp_image: segment 1: paddr=0x0008105c vaddr=0x3ffb0000 size=0x05038 ( 20536) load I (285) esp_image: segment 2: paddr=0x0008609c vaddr=0x40080000 size=0x00400 ( 1024) load 0x40080000: _WindowOverflow4 at /opt/esp/idf/components/freertos/xtensa_vectors.S:1778

I (286) esp_image: segment 3: paddr=0x000864a4 vaddr=0x40080400 size=0x09b74 ( 39796) load I (309) esp_image: segment 4: paddr=0x00090020 vaddr=0x400d0020 size=0x13bd2c (1293612) map 0x400d0020: _stext at ??:?

I (772) esp_image: segment 5: paddr=0x001cbd54 vaddr=0x40089f74 size=0x131b8 ( 78264) load 0x40089f74: reconfigureAllWdts at /opt/esp/idf/components/esp32/panic.c:405

I (823) boot: Loaded app from partition at offset 0x10000 I (823) boot: Disabling RNG early entropy source... I (823) psram: This chip is ESP32-D0WD I (829) spiram: Found 64MBit SPI RAM device I (832) spiram: SPI RAM mode: flash 40m sram 40m I (838) spiram: PSRAM initialized, cache is in low/high (2-core) mode. I (845) cpu_start: Pro cpu up. I (848) cpu_start: Application information: I (853) cpu_start: Project name: esp32-homekit-camera I (859) cpu_start: App version: 2a26d79-dirty I (865) cpu_start: Compile time: Apr 14 2020 01:00:11 I (871) cpu_start: ELF file SHA256: 3475f48eeddb6cf4... I (877) cpu_start: ESP-IDF: v4.1-dev-1572-g30372f5a4 I (883) cpu_start: Starting app cpu, entry point is 0x4008157c 0x4008157c: call_start_cpu1 at /opt/esp/idf/components/esp32/cpu_start.c:276

I (0) cpu_start: App cpu up. I (1775) spiram: SPI SRAM memory test OK D (1775) memory_layout: Checking 8 reserved memory ranges: D (1775) memory_layout: Reserved memory range 0x3f800000 - 0x3fc00000 D (1780) memory_layout: Reserved memory range 0x3ffae000 - 0x3ffae6e0 D (1787) memory_layout: Reserved memory range 0x3ffb0000 - 0x3ffbce48 D (1793) memory_layout: Reserved memory range 0x3ffe0000 - 0x3ffe0440 D (1800) memory_layout: Reserved memory range 0x3ffe3f20 - 0x3ffe4350 D (1806) memory_layout: Reserved memory range 0x40070000 - 0x40078000 D (1813) memory_layout: Reserved memory range 0x40078000 - 0x40080000 0x40080000: _WindowOverflow4 at /opt/esp/idf/components/freertos/xtensa_vectors.S:1778

D (1819) memory_layout: Reserved memory range 0x40080000 - 0x4009d12c 0x40080000: _WindowOverflow4 at /opt/esp/idf/components/freertos/xtensa_vectors.S:1778

D (1826) memory_layout: Building list of available memory regions: D (1832) memory_layout: Available memory region 0x3ffae6e0 - 0x3ffb0000 D (1839) memory_layout: Available memory region 0x3ffbce48 - 0x3ffc0000 D (1846) memory_layout: Available memory region 0x3ffc0000 - 0x3ffc2000 D (1852) memory_layout: Available memory region 0x3ffc2000 - 0x3ffc4000 D (1859) memory_layout: Available memory region 0x3ffc4000 - 0x3ffc6000 D (1866) memory_layout: Available memory region 0x3ffc6000 - 0x3ffc8000 D (1872) memory_layout: Available memory region 0x3ffc8000 - 0x3ffca000 D (1879) memory_layout: Available memory region 0x3ffca000 - 0x3ffcc000 D (1886) memory_layout: Available memory region 0x3ffcc000 - 0x3ffce000 D (1892) memory_layout: Available memory region 0x3ffce000 - 0x3ffd0000 D (1899) memory_layout: Available memory region 0x3ffd0000 - 0x3ffd2000 D (1906) memory_layout: Available memory region 0x3ffd2000 - 0x3ffd4000 D (1912) memory_layout: Available memory region 0x3ffd4000 - 0x3ffd6000 D (1919) memory_layout: Available memory region 0x3ffd6000 - 0x3ffd8000 D (1926) memory_layout: Available memory region 0x3ffd8000 - 0x3ffda000 D (1932) memory_layout: Available memory region 0x3ffda000 - 0x3ffdc000 D (1939) memory_layout: Available memory region 0x3ffdc000 - 0x3ffde000 D (1946) memory_layout: Available memory region 0x3ffde000 - 0x3ffe0000 D (1952) memory_layout: Available memory region 0x3ffe0440 - 0x3ffe3f20 D (1959) memory_layout: Available memory region 0x3ffe4350 - 0x3ffe8000 D (1966) memory_layout: Available memory region 0x3ffe8000 - 0x3fff0000 D (1973) memory_layout: Available memory region 0x3fff0000 - 0x3fff8000 D (1979) memory_layout: Available memory region 0x3fff8000 - 0x3fffc000 D (1986) memory_layout: Available memory region 0x3fffc000 - 0x40000000 D (1993) memory_layout: Available memory region 0x4009d12c - 0x4009e000 D (1999) memory_layout: Available memory region 0x4009e000 - 0x400a0000 I (2006) heap_init: Initializing. RAM available for dynamic allocation: D (2013) heap_init: New heap initialised at 0x3ffae6e0 I (2018) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM D (2025) heap_init: New heap initialised at 0x3ffbce48 I (2030) heap_init: At 3FFBCE48 len 000231B8 (140 KiB): DRAM I (2036) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM I (2043) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM D (2049) heap_init: New heap initialised at 0x4009d12c I (2054) heap_init: At 4009D12C len 00002ED4 (11 KiB): IRAM I (2061) cpu_start: Pro cpu start user code I (2065) spiram: Adding pool of 4096K of external SPI memory to heap allocator D (2081) clk: RTC_SLOW_CLK calibration value: 3318054 D (2090) intr_alloc: Connected src 46 to int 2 (cpu 0) D (2091) intr_alloc: Connected src 57 to int 3 (cpu 0) D (2092) intr_alloc: Connected src 24 to int 9 (cpu 0) D (2097) FLASH_HAL: extra_dummy: 1 D (2100) spi_flash: trying chip: issi D (2104) spi_flash: trying chip: gd D (2107) spi_flash: trying chip: generic I (2111) spi_flash: detected chip: generic I (2116) spi_flash: flash io: dio D (2120) chip_generic: set_io_mode: status before 0x0 I (2125) esp_core_dump_common: Init core dump to UART D (2131) partition: Loading the partition table E (2145) esp_core_dump_common: No core dump partition found! I (2146) cpu_start: Starting scheduler on PRO CPU. D (0) intr_alloc: Connected src 25 to int 2 (cpu 1) I (0) cpu_start: Starting scheduler on APP CPU. D (2157) heap_init: New heap initialised at 0x3ffe0440 D (2167) heap_init: New heap initialised at 0x3ffe4350 I (2177) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations D (2177) spiram: Allocating block of size 32768 bytes D (2187) intr_alloc: Connected src 16 to int 12 (cpu 0) D (2187) nvs: nvs_flash_init_custom partition=nvs start=9 count=6 D (2237) esp_netif_lwip: LwIP stack has been initialized D (2237) esp_netif_lwip: esp-netif has been successfully initialized D (2237) event: running task for loop 0x3ffca2a8 D (2247) event: created task for loop 0x3ffca2a8 D (2247) event: created event loop 0x3ffca2a8 D (2257) nvs: nvs_open_from_partition misc 1 D (2257) nvs: nvs_get_str_or_blob log I (2267) wifi: wifi driver task: 3ffcc950, prio:23, stack:3584, core=0 I (2267) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE D (2277) efuse: coding scheme 0 D (2277) efuse: In EFUSE_BLK0DATA2_REG is used 8 bits starting with 8 bit D (2287) efuse: coding scheme 0 D (2287) efuse: In EFUSE_BLK0DATA2_REG is used 8 bits starting with 0 bit D (2297) efuse: coding scheme 0 D (2297) efuse: In EFUSE_BLK0DATA1_REG is used 8 bits starting with 24 bit D (2307) efuse: coding scheme 0 D (2307) efuse: In EFUSE_BLK0DATA1_REG is used 8 bits starting with 16 bit D (2317) efuse: coding scheme 0 D (2317) efuse: In EFUSE_BLK0DATA1_REG is used 8 bits starting with 8 bit D (2327) efuse: coding scheme 0 D (2327) efuse: In EFUSE_BLK0DATA1_REG is used 8 bits starting with 0 bit D (2337) efuse: coding scheme 0 D (2337) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 16 bit I (2347) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE D (2357) efuse: coding scheme 0 D (2357) efuse: In EFUSE_BLK0DATA2_REG is used 8 bits starting with 8 bit D (2367) efuse: coding scheme 0 D (2367) efuse: In EFUSE_BLK0DATA2_REG is used 8 bits starting with 0 bit D (2377) efuse: coding scheme 0 D (2377) efuse: In EFUSE_BLK0DATA1_REG is used 8 bits starting with 24 bit D (2387) efuse: coding scheme 0 D (2387) efuse: In EFUSE_BLK0DATA1_REG is used 8 bits starting with 16 bit D (2397) efuse: coding scheme 0 D (2397) efuse: In EFUSE_BLK0DATA1_REG is used 8 bits starting with 8 bit D (2407) efuse: coding scheme 0 D (2407) efuse: In EFUSE_BLK0DATA1_REG is used 8 bits starting with 0 bit D (2417) efuse: coding scheme 0 D (2417) efuse: In EFUSE_BLK0DATA2_REG is used 8 bits starting with 16 bit D (2427) nvs: nvs_open_from_partition nvs.net80211 1 D (2437) nvs: nvs_get opmode 1 D (2437) nvs: nvs_get_str_or_blob sta.ssid D (2447) nvs: nvs_get_str_or_blob sta.mac D (2447) nvs: nvs_get sta.authmode 1 D (2447) nvs: nvs_get_str_or_blob sta.pswd D (2457) nvs: nvs_get_str_or_blob sta.pmk D (2457) nvs: nvs_get sta.chan 1 D (2457) nvs: nvs_get auto.conn 1 D (2467) nvs: nvs_get bssid.set 1 D (2467) nvs: nvs_get_str_or_blob sta.bssid D (2477) nvs: nvs_get sta.lis_intval 2 D (2477) nvs: nvs_get sta.phym 1 D (2477) nvs: nvs_get sta.phybw 1 D (2487) nvs: nvs_get_str_or_blob sta.apsw D (2487) nvs: nvs_get_str_or_blob sta.apinfo D (2497) nvs: nvs_get sta.scan_method 1 D (2497) nvs: nvs_get sta.sort_method 1 D (2497) nvs: nvs_get sta.minrssi 1 D (2507) nvs: nvs_get sta.minauth 1 D (2507) nvs: nvs_get sta.pmf_e 1 D (2507) nvs: nvs_get sta.pmf_r 1 D (2517) nvs: nvs_get_str_or_blob ap.ssid D (2517) nvs: nvs_get_str_or_blob ap.mac D (2517) nvs: nvs_get_str_or_blob ap.passwd D (2527) nvs: nvs_get_str_or_blob ap.pmk D (2527) nvs: nvs_get ap.chan 1 D (2537) nvs: nvs_get ap.authmode 1 D (2537) nvs: nvs_get ap.hidden 1 D (2537) nvs: nvs_get ap.max.conn 1 D (2547) nvs: nvs_get bcn.interval 2 D (2547) nvs: nvs_get ap.phym 1 D (2547) nvs: nvs_get ap.phybw 1 D (2557) nvs: nvs_get ap.sndchan 1 D (2557) nvs: nvs_get ap.pmf_e 1 D (2557) nvs: nvs_get ap.pmf_r 1 D (2567) nvs: nvs_get lorate 1 D (2567) nvs: nvs_set_blob sta.mac 6 D (2567) nvs: nvs_set_blob ap.mac 6 I (2577) wifi: wifi firmware version: e009c55 I (2577) wifi: config NVS flash: enabled I (2577) wifi: config nano formating: disabled I (2587) wifi: Init dynamic tx buffer num: 32 I (2587) wifi: Init data frame dynamic rx buffer num: 32 I (2597) wifi: Init management frame dynamic rx buffer num: 32 I (2597) wifi: Init management short buffer num: 32 I (2607) wifi: Init static tx buffer num: 16 I (2607) wifi: Init static rx buffer size: 1600 I (2617) wifi: Init static rx buffer num: 10 I (2617) wifi: Init dynamic rx buffer num: 32 D (2627) phy_init: loading PHY init data from application binary D (2627) nvs: nvs_open_from_partition phy 0 D (2627) nvs: nvs_get cal_version 4 D (2637) nvs: nvs_get_str_or_blob cal_mac D (2637) efuse: coding scheme 0 D (2637) efuse: In EFUSE_BLK0DATA2_REG is used 8 bits starting with 8 bit D (2647) efuse: coding scheme 0 D (2647) efuse: In EFUSE_BLK0DATA2_REG is used 8 bits starting with 0 bit D (2657) efuse: coding scheme 0 D (2667) efuse: In EFUSE_BLK0DATA1_REG is used 8 bits starting with 24 bit D (2667) efuse: coding scheme 0 D (2677) efuse: In EFUSE_BLK0DATA1_REG is used 8 bits starting with 16 bit D (2677) efuse: coding scheme 0 D (2687) efuse: In EFUSE_BLK0DATA1_REG is used 8 bits starting with 8 bit D (2687) efuse: coding scheme 0 D (2697) efuse: In EFUSE_BLK0DATA1_REG is used 8 bits starting with 0 bit D (2697) efuse: coding scheme 0 D (2707) efuse: In EFUSE_BLK0DATA2_REG is used 8 bits starting with 16 bit D (2707) nvs: nvs_get_str_or_blob cal_data D (2727) nvs: nvs_close 3 D (2727) efuse: coding scheme 0 D (2727) efuse: In EFUSE_BLK0DATA2_REG is used 8 bits starting with 8 bit D (2727) efuse: coding scheme 0 D (2727) efuse: In EFUSE_BLK0DATA2_REG is used 8 bits starting with 0 bit D (2737) efuse: coding scheme 0 D (2737) efuse: In EFUSE_BLK0DATA1_REG is used 8 bits starting with 24 bit D (2747) efuse: coding scheme 0 D (2747) efuse: In EFUSE_BLK0DATA1_REG is used 8 bits starting with 16 bit D (2757) efuse: coding scheme 0 D (2757) efuse: In EFUSE_BLK0DATA1_REG is used 8 bits starting with 8 bit D (2767) efuse: coding scheme 0 D (2767) efuse: In EFUSE_BLK0DATA1_REG is used 8 bits starting with 0 bit D (2777) efuse: coding scheme 0 D (2787) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 16 bit I (2877) phy: phy_version: 4180, cb3948e, Sep 12 2019, 16:39:13, 0, 0 I (2877) wifi: mode : sta (fc:f5:c4:0c:a8:74) D (2877) event: running post WIFI_EVENT:2 with handler 0x400efdf0 on loop 0x3ffca2a8 0x400efdf0: wifi_create_and_start_sta at /opt/esp/idf/components/tcpip_adapter/tcpip_adapter_compat.c:67

D (2887) esp_netif_objects: esp_netif_add_to_list 0x3ffbdc68 D (2887) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 1) D (2897) event: running post WIFI_EVENT:2 with handler 0x40166990 on loop 0x3ffca2a8 0x40166990: wifi_default_action_sta_start at /opt/esp/idf/components/esp_wifi/src/wifi_default.c:70

D (2907) wifi_init_default: wifi_start esp-netif:0x3ffbdc68 event-id2 D (2917) wifi_init_default: WIFI mac address: fc f5 c4 c a8 74 D (2917) esp_netif_handlers: esp_netif action has started with netif0x3ffbdc68 from event_id=2 D (2927) esp_netif_lwip: check: remote, if=0x3ffbdc68 fn=0x40166028 0x40166028: esp_netif_start_api at /opt/esp/idf/components/esp_netif/lwip/esp_netif_lwip.c:569

D (2937) esp_netif_lwip: esp_netif_start_api 0x3ffbdc68 D (2937) esp_netif_lwip: call api in lwip: ret=0x0, give sem D (2947) event: running post SYSTEM_EVENT:2 with handler 0x40164aac on loop 0x3ffca2a8 0x40164aac: esp_event_post_to_user at /opt/esp/idf/components/esp_event/event_loop_legacy.c:31

I (2957) esp32_camera: STA start I (4167) wifi: new:<11,0>, old:<1,0>, ap:<255,255>, sta:<11,0>, prof:1 I (5017) wifi: state: init -> auth (b0) I (5027) wifi: state: auth -> assoc (0) I (5027) wifi: state: assoc -> run (10) D (5037) wpa: IEEE 802.1X RX: version=2 type=3 length=95

D (5037) wpa: EAPOL-Key type=2

D (5037) wpa: key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)

D (5037) wpa: key_length=16 key_data_length=0

D (5047) wpa: WPA: RX EAPOL-Key - hexdump(len=99): D (5047) wpa: 02 03 00 5f 02 00 8a 00 10 00 00 00 00 00 00 00 D (5057) wpa: 01 67 24 8a c3 93 d7 05 c4 1b df 66 71 89 7d f7 D (5067) wpa: 84 67 68 b8 f5 5a 0c dc 8f 99 af 37 10 89 b4 8d D (5067) wpa: 8b 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (5077) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (5077) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (5087) wpa: 00 00 00 D (5087) wpa: WPA 1/4-Way Handshake

D (5097) wpa: RSN: msg 1/4 key data - hexdump(len=0): D (5097) wpa: WPA: PTK derivation - A1=fc:f5:c4:0c:a8:74 A2=8c:59:c3:aa:e8:ac

D (5107) wpa: WPA: PMK - hexdump(len=32): D (5107) wpa: 69 00 0f 1a 1f bf 5d 1a 05 b7 05 ce b6 db 40 1f D (5117) wpa: 4b 86 e3 73 7b 31 ef 1f 2b 57 d7 a0 2a 4b 46 0e D (5117) wpa: WPA: PTK - hexdump(len=48): D (5127) wpa: 7f c0 69 13 eb e0 57 42 bf c6 b2 75 e7 e4 c8 c3 D (5127) wpa: 14 2d a8 7a e1 65 17 9b 17 43 ac b3 00 b1 a0 90 D (5137) wpa: 29 b5 bd 7e ff fd 81 96 c1 c1 35 26 49 88 95 84 D (5147) wpa: WPA: WPA IE for msg 2/4

D (5157) wpa: WPA: TX EAPOL-Key - hexdump(len=121): D (5167) wpa: 01 03 00 75 02 01 0a 00 00 00 00 00 00 00 00 00 D (5167) wpa: 01 e0 b5 6a cb a0 a5 76 3e 34 f9 71 44 65 d6 9b D (5177) wpa: 7e e1 a1 eb b1 09 71 be 62 66 ec b0 60 4f 56 9a D (5187) wpa: 1c 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (5187) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (5197) wpa: 00 6d 8d f5 d7 c7 c7 da 39 43 9f 20 1d d3 38 59 D (5197) wpa: 58 00 16 30 14 01 00 00 0f ac 04 01 00 00 0f ac D (5207) wpa: 04 01 00 00 0f ac 02 00 00 D (5217) wpa: IEEE 802.1X RX: version=2 type=3 length=151

D (5217) wpa: EAPOL-Key type=2

D (5217) wpa: key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)

D (5227) wpa: key_length=16 key_data_length=56

D (5237) wpa: WPA: RX EAPOL-Key - hexdump(len=155): D (5237) wpa: 02 03 00 97 02 13 ca 00 10 00 00 00 00 00 00 00 D (5247) wpa: 02 67 24 8a c3 93 d7 05 c4 1b df 66 71 89 7d f7 D (5247) wpa: 84 67 68 b8 f5 5a 0c dc 8f 99 af 37 10 89 b4 8d D (5257) wpa: 8b 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (5267) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (5267) wpa: 00 e7 45 a1 da 8c 57 8a 66 ff 6d e4 e2 7b 37 1f D (5277) wpa: a5 00 38 80 f9 0b 99 8c 9c a2 e1 b1 08 5a 5b 63 D (5277) wpa: 44 83 02 40 3b 95 91 78 68 29 ef 63 4f 88 89 24 D (5287) wpa: 78 81 a0 5a 72 27 8e f8 9c 5d 3e 54 21 a2 48 3f D (5297) wpa: 52 24 95 cd ef 29 e1 51 f8 c7 95 D (5297) wpa: WPA 3/4-Way Handshake

D (5297) wpa: WPA: No WPA/RSN IE for this AP known. Trying to get from scan results

D (5307) wpa: WPA: Found the current AP from updated scan results

D (5317) wpa: tx 4/4 txcb_flags=8192

D (5317) wpa: WPA Send EAPOL-Key 4/4

D (5327) wpa: WPA: TX EAPOL-Key - hexdump(len=99): D (5327) wpa: 01 03 00 5f 02 03 0a 00 00 00 00 00 00 00 00 00 D (5337) wpa: 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (5337) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (5347) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (5347) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (5357) wpa: 00 c8 77 3d 1a de c0 9f 26 6f 9e 21 27 af b5 78 D (5367) wpa: ca 00 00 D (5367) wpa: WPA: Installing PTK to the driver.

D (5367) wpa: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=16).

D (5377) wpa: WPA: Key negotiation completed with 8c:59:c3:aa:e8:ac [PTK=CCMP GTK=CCMP]

I (5387) wifi: connected with Hilaguy, aid = 3, channel 11, BW20, bssid = 8c:59:c3:aa:e8:ac I (5397) wifi: security type: 3, phy: bgn, rssi: -73 I (5397) wifi: pm start, type: 1

D (5397) event: running post WIFI_EVENT:4 with handler 0x401669c0 on loop 0x3ffca2a8 0x401669c0: wifi_default_action_sta_connected at /opt/esp/idf/components/esp_wifi/src/wifi_default.c:84

I (5407) wifi: AP's beacon interval = 102400 us, DTIM period = 1 D (5417) esp_netif_handlers: esp_netif action connected with netif0x3ffbdc68 from event_id=4 D (5427) esp_netif_lwip: check: remote, if=0x3ffbdc68 fn=0x401662d4 0x401662d4: esp_netif_up_api at /opt/esp/idf/components/esp_netif/lwip/esp_netif_lwip.c:1047

D (5427) esp_netif_lwip: esp_netif_up_api esp_netif:0x3ffbdc68 D (5437) esp_netif_lwip: call api in lwip: ret=0x0, give sem D (5437) esp_netif_lwip: check: remote, if=0x3ffbdc68 fn=0x40165804 0x40165804: esp_netif_dhcpc_start_api at /opt/esp/idf/components/esp_netif/lwip/esp_netif_lwip.c:858

D (5447) esp_netif_lwip: esp_netif_dhcpc_start_api esp_netif:0x3ffbdc68 D (5457) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x3ffbdc68 D (5457) esp_netif_lwip: if0x3ffbdc68 start ip lost tmr: no need start because netif=0x3ffd7ffc interval=120 ip=0 D (5467) esp_netif_lwip: starting dhcp client D (5477) esp_netif_lwip: call api in lwip: ret=0x0, give sem D (5487) event: running post SYSTEM_EVENT:4 with handler 0x40164aac on loop 0x3ffca2a8 0x40164aac: esp_event_post_to_user at /opt/esp/idf/components/esp_event/event_loop_legacy.c:31

D (6237) esp_netif_lwip: esp_netif_dhcpc_cb lwip-netif:0x3ffd7ffc D (6237) esp_netif_lwip: if0x3ffbdc68 ip changed=1 D (6237) event: running post IP_EVENT:0 with handler 0x40166804 on loop 0x3ffca2a8 0x40166804: wifi_default_action_sta_got_ip at /opt/esp/idf/components/esp_wifi/src/wifi_default.c:124

D (6247) wifi_init_default: Got IP wifi default handler entered D (6247) esp_netif_handlers: esp_netif action got_ip with netif0x3ffbdc68 from event_id=0 I (6257) esp_netif_handlers: sta ip: 10.100.102.24, mask: 255.255.255.0, gw: 10.100.102.1 D (6267) event: running post SYSTEM_EVENT:7 with handler 0x40164aac on loop 0x3ffca2a8 0x40164aac: esp_event_post_to_user at /opt/esp/idf/components/esp_event/event_loop_legacy.c:31

I (6277) esp32_camera: WiFI ready I (6277) esp32_camera: Free heap: 4359140 I (6287) gpio: GPIO[13]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (6297) gpio: GPIO[14]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 D (6307) camera: Enabling XCLK output D (6307) camera: Initializing SSCB I (6307) sccb: pin_sda 26 pin_scl 27

D (6317) intr_alloc: Connected src 50 to int 13 (cpu 0) D (6317) camera: Resetting camera by power down line I (6327) gpio: GPIO[32]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 E (6357) sccb: SCCB_Write Failed addr:0x3c, reg:0xff, data:0x01, ret:-1 E (6357) sccb: SCCB_Write Failed addr:0x3c, reg:0x12, data:0x80, ret:-1 D (6367) camera: Searching for camera address D (6377) camera: Detected camera at address=0x30 D (6397) camera: Camera PID=0x26 VER=0x42 MIDL=0x7f MIDH=0xa2 D (6397) camera: Doing SW reset of sensor D (6457) camera: Detected OV2640 camera D (6457) camera: in_bpp: 2, fb_bpp: 2, fb_size: 38400, mode: 3, width: 640 height: 480 I (6457) gpio: GPIO[35]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (6467) gpio: GPIO[34]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (6477) gpio: GPIO[39]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (6487) gpio: GPIO[36]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (6497) gpio: GPIO[21]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (6507) gpio: GPIO[19]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (6517) gpio: GPIO[18]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (6527) gpio: GPIO[5]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (6537) gpio: GPIO[25]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (6537) gpio: GPIO[23]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (6547) gpio: GPIO[22]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 D (6557) intr_alloc: Connected src 32 to int 17 (cpu 0) D (6567) camera: Line width (for DMA): 5120 bytes D (6567) camera: DMA buffer size: 2560, DMA buffers per line: 2 D (6577) camera: DMA buffer count: 8 D (6577) camera: DMA buffer total: 20480 bytes D (6587) camera: Allocating DMA buffer #0, size=2560 D (6587) camera: Allocating DMA buffer #1, size=2560 D (6597) camera: Allocating DMA buffer #2, size=2560 D (6597) camera: Allocating DMA buffer #3, size=2560 D (6607) camera: Allocating DMA buffer #4, size=2560 D (6607) camera: Allocating DMA buffer #5, size=2560 D (6617) camera: Allocating DMA buffer #6, size=2560 D (6617) camera: Allocating DMA buffer #7, size=2560 I (6627) camera: Allocating 2 frame buffers (75 KB total) I (6637) camera: Allocating 37 KB frame buffer in OnBoard RAM I (6647) camera: Allocating 37 KB frame buffer in OnBoard RAM D (6647) intr_alloc: Connected src 22 to int 18 (cpu 0) D (6647) camera: Setting frame size to 640x480

HomeKit: Starting server I (6837) esp32_camera: Initializing streaming HomeKit: Using existing accessory ID: 04:DF:6E:D0:95:55 I (6857) esp32_camera: Streaming initialized >>> HomeKit: Configuring mDNS

benchuk commented 4 years ago

Ok after some investigations I have found the following:

  1. this problem was found after building and installing with docker (pre installed build env and esp idf version) using this docker image: lpodkalicki/esp32-toolchain
  2. after discovering this issue I have tried the latest version of docker by esp from docker hub latest all version can be found here: espressif/idf
  3. at the end the version of docker and idf that worked for me was version 3.3

not sure why but it works, but it is kind of slow and unstable - takes time to get the preview image on the ios app and also streaming sometimes fails, do not see any special errors and also it seems the IOS/Camera takes time to perform the handshake or any api call in general, maybe configuration issue? but I guess this issue is more. relevant to the camera project specifically esp32-homekit-camera

maximkulkin commented 4 years ago

When testing with esp-idf, I'm running latest master version and it works fine. Although I do not use Docker with esp-idf as it has pretty good scripts to install all dependencies on host machine.