espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.37k stars 7.21k forks source link

[TW#18950] Error when trying to connect to Web server via Wifi while Bluetooth is on: bcn_timout, alloc fail #1670

Closed eagi223 closed 6 years ago

eagi223 commented 6 years ago

I'm getting the following errors when trying to connect to a server with HTTPS while Bluetooth is running. I'm using the latest IDF v3.0 commit I believe. I ran git pull on esp-idf right before testing this. Once the issue occurs, wifi disconnects and is unable to reconnect. I've combed through forums and issues trying to find a solution, but I'm stumped. Maybe I'm doing something wrong, but I've seen these error messages pop up in the issue tracker a few times for other bugs.

I've basically worked off of examples to this point so it's mainly using the Bluetooth GATT Server table example, in conjunction with the HTTPS Request example. If I set Bluetooth to disconnect when Wifi obtains an IP address, the Https code starts like expected and no crash occurs.

I (185) cpu_start: Pro cpu up.
I (185) cpu_start: Starting app cpu, entry point is 0x40081124
0x40081124: call_start_cpu1 at C:/esp-idf/components/esp32/cpu_start.c:225

I (0) cpu_start: App cpu up.
I (188) heap_init: Initializing. RAM available for dynamic allocation:
I (195) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (201) heap_init: At 3FFD2AF8 len 0000D508 (53 KiB): DRAM
I (207) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (214) heap_init: At 3FFE4350 len 00013CB0 (79 KiB): D/IRAM
I (220) heap_init: At 40093BE8 len 0000C418 (49 KiB): IRAM
I (226) cpu_start: Pro cpu start user code
I (19) esp_apptrace: Initialized TRAX on CPU0
I (20) pm_esp32: Frequency switching config: CPU_MAX: 240, APB_MAX: 240, APB_MIN: XTAL, Light sleep: DISABLED
I (25) cpu_start: Starting scheduler on PRO CPU.
I (68) esp_apptrace: Initialized TRAX on CPU1
I (5) cpu_start: Starting scheduler on APP CPU.
I (51) Main App (main): Start App
Device Name: Gunbox Pro
Firmware Version: R003541_00aa

I (118) Bluetooth Driver (dBluetooth): Initializing Bluetooth Driver
I (125) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (381) phy: phy_version: 383.0, 79a622c, Jan 30 2018, 15:38:06, 0, 0
I (422) Bluetooth Driver (dBluetooth): Bluetooth Driver Initialized
I (422) Bluetooth Interface (iBluetooth): Initializing Bluetooth Interface
I (426) Bluetooth Interface (iBluetooth): GATTS Profile Event Server reg event
I (439) Bluetooth Interface (iBluetooth): create attribute table successfully, the number handle = 16

I (447) Bluetooth Interface (iBluetooth): create attribute table successfully, the number handle = 28

I (454) Bluetooth Interface (iBluetooth): gap event handler: 0
I (460) Bluetooth Interface (iBluetooth): gap event handler: 1
I (469) Bluetooth Interface (iBluetooth): SERVICE_START_EVT, status 0, service_handle 40
I (475) Bluetooth Interface (iBluetooth): SERVICE_START_EVT, status 0, service_handle 56
I (484) Bluetooth Interface (iBluetooth): gap event handler: 6
I (490) Bluetooth Interface (iBluetooth): advertising start successfully
I (498) Bluetooth Interface (iBluetooth): Bluetooth Interface initialized successfully
I (506) WiFi Driver (dWifi): Start ESP32_Wifi_Driver_Init
I (514) wifi: wifi firmware version: ebd3e5d
I (516) wifi: config NVS flash: enabled
I (520) wifi: config nano formating: disabled
I (524) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (533) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (565) wifi: Init dynamic tx buffer num: 32
I (565) wifi: Init data frame dynamic rx buffer num: 32
I (565) wifi: Init management frame dynamic rx buffer num: 32
I (569) wifi: wifi driver task: 3ffe3c7c, prio:23, stack:4096
I (574) wifi: Init static rx buffer num: 10
I (578) wifi: Init dynamic rx buffer num: 32
I (582) wifi: wifi power manager task: 0x3ffe8c40 prio: 21 stack: 2560
I (600) wifi: mode : sta (24:0a:c4:83:13:64)
I (601) WiFi Driver (dWifi): Task started
I (601) WiFi Driver (dWifi): SYSTEM_EVENT_STA_START
I (601) ESP32 HTTPS Driver (dESP32_HTTPS): Seeding the random number generator
I (613) ESP32 HTTPS Driver (dESP32_HTTPS): Loading the CA root certificate...
I (622) ESP32 HTTPS Driver (dESP32_HTTPS): Setting hostname for TLS session...
I (628) ESP32 HTTPS Driver (dESP32_HTTPS): Setting up the SSL/TLS structure...
I (9317) Bluetooth Interface (iBluetooth): ESP_GATTS_CONNECT_EVT, conn_id = 0
I (9317) Bluetooth Interface (iBluetooth): 5a e7 22 d4 8d 6f
I (9734) Bluetooth Interface (iBluetooth): gap event handler: 20
I (9734) Bluetooth Interface (iBluetooth): update connetion params status = 0, min_int = 16, max_int = 32,conn_int = 24,latency = 0, timeout = 400
I (9825) Bluetooth Interface (iBluetooth): ESP_GATTS_MTU_EVT, MTU 500
I (10425) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (10425) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 1, handle 42

I (10427) Bluetooth Interface (iBluetooth): Base MAC: **:**:**:**:**:**
I (10545) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (10545) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 2, handle 45

I (10665) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (10665) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 3, handle 48

I (10875) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (10875) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 4, handle 51

I (11535) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (11535) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 5, handle 43

I (11595) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (11595) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 6, handle 46

I (11655) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (11655) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 7, handle 49

I (11715) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (11715) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 8, handle 52

I (11775) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (11775) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 9, handle 59

I (11835) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (11835) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 10, handle 62

I (11895) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (11895) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 11, handle 65

I (11955) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (11955) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 12, handle 68

I (12015) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (12015) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 13, handle 71

I (12075) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (12075) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 14, handle 74

I (12135) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (12135) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 15, handle 77

I (12195) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (12195) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 16, handle 80

I (12255) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (12255) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 17, handle 83

I (13724) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (13725) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 18, handle 58

I (17025) Bluetooth Interface (iBluetooth): Wifi Control Write
Wifi Control Write msg: cmdWifiConn=      NetworkName,NetworkPassword

I (17074) WiFi Driver (dWifi): Start ESP32_Wifi_Driver_Connect

I (17104) WiFi Driver (dWifi): Wifi Config Bit Detected

I (17145) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT
E (17145) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 21, handle 58

I (17230) wifi: n:1 0, o:1 0, ap:255 255, sta:1 0, prof:1
I (17896) wifi: state: init -> auth (b0)
I (17900) wifi: state: auth -> assoc (0)
I (17904) wifi: state: assoc -> run (10)
I (17921) wifi: connected with NetworkName, channel 1
I (19018) event: sta ip: 10.**.***.105, mask: 255.255.255.0, gw: 10.**.***.1
I (19018) WiFi Driver (dWifi): SYSTEM_EVENT_STA_GOT_IP
Wifi Serv char status read val changed to : 1
System got IP: wifiServVal: 1
I (19027) ESP32 HTTPS Driver (dESP32_HTTPS): Connected to AP
I (19027) WiFi Driver (dWifi): Wifi Config Good Bit Detected

I (19034) ESP32 HTTPS Driver (dESP32_HTTPS): Connecting to www.howsmyssl.com:443...
I (19168) ESP32 HTTPS Driver (dESP32_HTTPS): Connected.
I (19168) ESP32 HTTPS Driver (dESP32_HTTPS): Performing the SSL/TLS handshake...
I (20905) wifi: pm start, type:0

I (26491) wifi: bcn_timout,ap_probe_send_start
W (26491) wifi: alloc eb len=76 type=2 fail

W (26491) wifi: m f probe req l=0

W (26992) wifi: alloc eb len=76 type=2 fail

W (26992) wifi: m f probe req l=0

W (27492) wifi: alloc eb len=76 type=2 fail

W (27492) wifi: m f probe req l=0

W (27992) wifi: alloc eb len=76 type=2 fail

W (27993) wifi: m f probe req l=0

W (28493) wifi: alloc eb len=76 type=2 fail

W (28493) wifi: m f probe req l=0

I (28993) wifi: ap_probe_send over, resett wifi status to disassoc
I (28993) wifi: state: run -> init (1)
I (28994) wifi: pm stop, total sleep time: 0/8088689

I (28994) wifi: n:1 0, o:1 0, ap:255 255, sta:1 0, prof:1
I (29002) WiFi Driver (dWifi): SYSTEM_EVENT_STA_DISCONNECTED
Wifi Serv char status read val changed to : 0
I (31422) WiFi Driver (dWifi): SYSTEM_EVENT_STA_DISCONNECTED
Wifi Serv char status read val changed to : 0
I (33833) WiFi Driver (dWifi): SYSTEM_EVENT_STA_DISCONNECTED
Wifi Serv char status read val changed to : 0
I (36243) WiFi Driver (dWifi): SYSTEM_EVENT_STA_DISCONNECTED
Wifi Serv char status read val changed to : 0
...
This continues forever
eagi223 commented 6 years ago

So I doubled the amount of heap that I was allocating to both the Wifi and HTTPS tasks and I'm now getting this in the log: Has anyone got a fix or suggestion for this? I've given more info at esp32.com ` I (18516) WiFi Driver (dWifi): Wifi Config Bit Detected

I (18557) Bluetooth Interface (iBluetooth): ESP_GATTS_READ_EVT E (18558) BT: GATT_INFO_READ_EVT, conn_id 0, trans_id 21, handle 58

I (18643) wifi: n:1 0, o:1 0, ap:255 255, sta:1 0, prof:1 I (19309) wifi: state: init -> auth (b0) I (19314) wifi: state: auth -> assoc (0) I (19318) wifi: state: assoc -> run (10) I (19334) wifi: connected with RPHEngineering, channel 1 I (22318) wifi: pm start, type:0

I (23653) event: sta ip: 10.42.125.96, mask: 255.255.255.0, gw: 10.42.125.1 I (23653) WiFi Driver (dWifi): SYSTEM_EVENT_STA_GOT_IP Wifi Serv char status read val changed to : 1 System got IP: wifiServVal: 1 I (23663) WiFi Driver (dWifi): Wifi Config Good Bit Detected

I (23663) ESP32 HTTPS Driver (dESP32_HTTPS): Connected to AP I (23675) ESP32 HTTPS Driver (dESP32_HTTPS): Connecting to 54.218.40.65:443... I (23759) ESP32 HTTPS Driver (dESP32_HTTPS): Connected. I (23760) ESP32 HTTPS Driver (dESP32_HTTPS): Performing the SSL/TLS handshake... I (29844) wifi: bcn_timout,ap_probe_send_start I (32345) wifi: ap_probe_send over, resett wifi status to disassoc I (32345) wifi: state: run -> init (1) I (32346) wifi: pm stop, total sleep time: 0/10027329

I (32346) wifi: n:1 0, o:1 0, ap:255 255, sta:1 0, prof:1 I (32355) WiFi Driver (dWifi): SYSTEM_EVENT_STA_DISCONNECTED Wifi Serv char status read val changed to : 0 I (34774) WiFi Driver (dWifi): SYSTEM_EVENT_STA_DISCONNECTED Wifi Serv char status read val changed to : 0 I (37184) WiFi Driver (dWifi): SYSTEM_EVENT_STA_DISCONNECTED Wifi Serv char status read val changed to : 0 I (39594) WiFi Driver (dWifi): SYSTEM_EVENT_STA_DISCONNECTED Wifi Serv char status read val changed to : 0 I (42003) WiFi Driver (dWifi): SYSTEM_EVENT_STA_DISCONNECTED Wifi Serv char status read val changed to : 0 I (44413) WiFi Driver (dWifi): SYSTEM_EVENT_STA_DISCONNECTED `

TianHao-Yoursmake commented 6 years ago

@eagi223 , you can try the latest master branch that we have finish wifi/bluetooth coexistence function.

eagi223 commented 6 years ago

@TianHao-Espressif Perfect, I'll give it a try. Thanks!

FayeY commented 6 years ago

Hi @eagi223 , is there any update? Is this issue solved now?

eagi223 commented 6 years ago

Sorry, I've never been able to get it to work, so I just shutdown all non critical tasks and peripherals when communicating with the server. I'll be updating my code to 3.1 within a month or two, so hopefully I'll have more time to try to implement a real solution. I'll close the issue for now, because it's a definite possibility that I just need to optimize my code. Thanks!