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.

Sign up for GitHub

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

Jump to bottom

BLE stop advertising (ELx400) (IDFGH-6727) #8356

Closed
ffamar opened this issue Feb 6, 2022 · 21 comments
Closed

BLE stop advertising (ELx400) (IDFGH-6727) #8356

ffamar opened this issue Feb 6, 2022 · 21 comments
Labels
Resolution: Done Issue is done internally Status: Done Issue is done internally

Comments

@ffamar
Copy link

ffamar commented Feb 6, 2022

Hi,
I developed a project BLE + Wifi in station mode connected to mqtt server.
It works fine but after about 24 hours the ble stop advertising.
Below the last logs I see.

I (86738822) BT_GATT: GATT_GetConnIdIfConnected status=0
I (86738822) BT_APPL: BTA_DmSetBleAdvParamsAll: 32, 64
I (86738832) BT_APPL: adv_type = 0, addr_type_own = 0, chnl_map = 7, adv_fil_pol = 0
E (86738842) BLE: GAP_EVT, event 6
W (107904842) wifi:<ba-del>idx
W (107904852) wifi:<ba-add>idx:1 (ifx:0, 10:13:31:bc:b2:69), tid:0, ssn:741, winSize:64
W (107906782) wifi:<ba-del>idx
W (107947432) wifi:<ba-add>idx:1 (ifx:0, 10:13:31:bc:b2:69), tid:0, ssn:742, winSize:64
ELx400
I (111935212) *** MQTT ***: <-- Received message MQTT

The problem only affects BLE, Wifi and Mqtt continue to work.
When the problem occurs, I always see ELx400.

My configuration:
ESP32 WROVER-B with 16MB flash
ESP-IDF 4.4

Thanks for help.
@espressif-bot espressif-bot added the Status: Opened Issue is new label Feb 6, 2022
@github-actions github-actions bot changed the title BLE stop advertising (ELx400) BLE stop advertising (ELx400) (IDFGH-6727) Feb 6, 2022
@ffamar
Copy link
Author

ffamar commented Feb 11, 2022 •
edited
Loading

The issue happened again after a short time:

I (28) boot: ESP-IDF v4.4 2nd stage bootloader
I (28) boot: compile time 15:55:35
I (28) boot: chip revision: 1
I (31) boot.esp32: SPI Speed      : 40MHz
I (35) boot.esp32: SPI Mode       : DIO
I (40) boot.esp32: SPI Flash Size : 16MB
I (44) boot: Enabling RNG early entropy source...
I (50) boot: Partition Table:
I (53) boot: ## Label            Usage          Type ST Offset   Length
I (61) boot:  0 otadata          OTA data         01 00 00009000 00002000
I (68) boot:  1 nvs              WiFi data        01 02 0000b000 00060000
I (76) boot:  2 ota_0            OTA app          00 10 00070000 00160000
I (83) boot:  3 ota_1            OTA app          00 11 001d0000 00160000
I (91) boot: End of partition table
I (95) esp_image: segment 0: paddr=00070020 vaddr=3f400020 size=2d224h (184868) map
I (170) esp_image: segment 1: paddr=0009d24c vaddr=3ffbdb60 size=02dcch ( 11724) load
I (175) esp_image: segment 2: paddr=000a0020 vaddr=400d0020 size=cb20ch (832012) map
I (477) esp_image: segment 3: paddr=0016b234 vaddr=3ffc092c size=026b4h (  9908) load
I (481) esp_image: segment 4: paddr=0016d8f0 vaddr=40080000 size=1ab80h (109440) load
I (528) esp_image: segment 5: paddr=00188478 vaddr=50000000 size=00010h (    16) load
I (541) boot: Loaded app from partition at offset 0x70000
I (541) boot: Disabling RNG early entropy source...
I (553) psram: This chip is ESP32-D0WD
I (553) spiram: Found 64MBit SPI RAM device
I (554) spiram: SPI RAM mode: flash 40m sram 40m
I (558) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (566) cpu_start: Pro cpu up.
I (569) cpu_start: Starting app cpu, entry point is 0x4008153c
0x4008153c: call_start_cpu1 at /home/famar/Works/toolchain/esp/esp-idf-v4.4/components/esp_system/port/cpu_start.c:156

I (0) cpu_start: App cpu up.
I (1463) spiram: SPI SRAM memory test OK
I (1473) cpu_start: Pro cpu start user code
I (1473) cpu_start: cpu freq: 240000000
I (1473) cpu_start: Application information:
I (1476) cpu_start: Project name:     wash_max
I (1481) cpu_start: App version:      0.1-45-gf30cacc4-dirty
I (1487) cpu_start: ELF file SHA256:  636dee649669cb09...
I (1494) cpu_start: ESP-IDF:          v4.4
I (1499) heap_init: Initializing. RAM available for dynamic allocation:
I (1506) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (1512) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (1518) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (1524) heap_init: At 3FFC6B28 len 000194D8 (101 KiB): DRAM
I (1531) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1537) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1544) heap_init: At 4009AB80 len 00005480 (21 KiB): IRAM
I (1550) spiram: Adding pool of 4075K of external SPI memory to heap allocator
I (1559) spi_flash: detected chip: generic
I (1563) spi_flash: flash io: dio
I (1569) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (1577) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations
I (1627) stm_bootloader: GPIO Initialized
I (1627) BTDM_INIT: BT controller compile version [6a07b06]
I (1627) system_api: Base MAC address is not set
I (1637) system_api: read default base MAC address from EFUSE
I (1647) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (1917) BT_GATT: GATT_Register
I (1917) BT_GATT: allocated gatt_if=1

I (1917) BT_GATT: GATT_StartIf gatt_if=1
I (1917) BT_GATT: GATTS_CreateService

I (1917) BT_GATT: GATTS_StartService
I (1927) BT_GATT: GATT_Register
I (1927) BT_GATT: allocated gatt_if=2

I (1927) BT_GATT: GATT_StartIf gatt_if=2
I (1937) BT_GATT: GATTS_CreateService

I (1937) BT_GATT: GATTS_StartService
I (1967) BT_GATT: GATT_Register
I (1967) BT_GATT: allocated gatt_if=3

I (1967) BT_GATT: GATT_StartIf gatt_if=3
I (1967) BT_GATT: GATTS_CreateService

E (1977) BLE: GAP_EVT, event 4

I (1977) BT_GATT: GATTS_StartService
I (1977) BT_APPL: BTA_DmSetBleAdvParamsAll: 32, 64

I (1987) BT_APPL: adv_type = 0, addr_type_own = 0, chnl_map = 7, adv_fil_pol = 0

E (1997) BLE: GAP_EVT, event 6

I (2007) wifi:wifi driver task: 3ffce1e8, prio:23, stack:6656, core=0
I (2007) wifi:wifi firmware version: 7679c42
I (2007) wifi:wifi certification version: v7.0
I (2007) wifi:config NVS flash: disabled
I (2017) wifi:config nano formating: disabled
I (2017) wifi:Init data frame dynamic rx buffer num: 32
I (2027) wifi:Init management frame dynamic rx buffer num: 32
I (2027) wifi:Init management short buffer num: 32
I (2037) wifi:Init static tx buffer num: 16
I (2037) wifi:Init tx cache buffer num: 32
I (2037) wifi:Init static rx buffer size: 1600
I (2047) wifi:Init static rx buffer num: 10
I (2047) wifi:Init dynamic rx buffer num: 32
I (2057) wifi_init: rx ba win: 6
I (2057) wifi_init: tcpip mbox: 32
I (2057) wifi_init: udp mbox: 6
I (2067) wifi_init: tcp mbox: 6
I (2067) wifi_init: tcp tx win: 5744
I (2077) wifi_init: tcp rx win: 5744
I (2077) wifi_init: tcp mss: 1440
I (2077) wifi_init: WiFi/LWIP prefer SPIRAM
I (2087) wifi:mode : sta (a8:03:2a:75:d4:3c)
I (2097) wifi:enable tsf
I (2097) *** WI-FI ***: Connect to wifi....
I (2117) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
I (2687) wifi:state: init -> auth (b0)
I (2687) wifi:state: auth -> assoc (0)
I (2697) wifi:state: assoc -> run (10)
W (2727) wifi:<ba-add>idx:0 (ifx:0, 10:13:31:bc:b2:69), tid:5, ssn:0, winSize:64
W (2727) wifi:<ba-add>idx:1 (ifx:0, 10:13:31:bc:b2:69), tid:0, ssn:0, winSize:64
I (2747) wifi:connected with FamarWiFi, aid = 4, channel 1, BW20, bssid = 10:13:31:bc:b2:69
I (2747) wifi:security: WPA2-PSK, phy: bgn, rssi: -50
I (2747) wifi:pm start, type: 1

I (2757) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (3497) esp_netif_handlers: sta ip: 192.168.1.68, mask: 255.255.255.0, gw: 192.168.1.1
I (3497) *** WI-FI ***: got ip:192.168.1.68
I (3497) *** WI-FI ***: Device connected waiting for fail....
I (6347) *** MQTT ***: MQTT_EVENT_CONNECTED
I (6347) *** MQTT ***: Subscribe topic test/A8032A75D43E/RAW/DATA
I (6357) *** MQTT ***: sent subscribe topicServiceCommand successful, msg_id=17050
I (6357) *** MQTT ***: Default client connected task_id=1073466748
I (6447) *** MQTT ***: MQTT_EVENT_SUBSCRIBED, msg_id=2020
I (6487) *** MQTT ***: MQTT_EVENT_SUBSCRIBED, msg_id=17050
I (6687) *** MQTT ***: MQTT_EVENT_CONNECTED
I (6687) *** MQTT ***: Subscribe topic test/A8032A75D43E/RAW/DATA
I (6687) *** MQTT ***: sent subscribe topicServiceCommand successful, msg_id=4225
I (6697) CMD_MAN: --> Sending command message MQTT
I (6697) *** MQTT ***: Service client connected task_id=1073689652
I (6857) *** MQTT ***: MQTT_EVENT_SUBSCRIBED, msg_id=53698
I (6967) *** MQTT ***: MQTT_EVENT_SUBSCRIBED, msg_id=4225
ELx400

Who wrote ELx400?
Could this issue be related to the monitor serial port?
Any idea?

@ffamar
Copy link
Author

ffamar commented Feb 11, 2022

I found ELx400 in libbtdm_app.a.
What is the meaning?

@Weijian-Espressif
Copy link
Collaborator

@xiewenxiang please help to check ELx400 error

@AngelVersa
Copy link

I had the same issue, in a esp32 esp-wroom using esp-idf v4.3.2.

The devices was working fine for a week and after this message prompt in the console the advertising stopped.

Please help us with this issue with the ELx400.

@AngelVersa
Copy link

Can someone help with this issue?

@ffamar
Copy link
Author

ffamar commented Jul 20, 2022

Can someone help with this issue?

I disabled "Software controls WiFi/Bluetooth coexistence" in the sdkconfig and the issue has been fixed.

@AngelVersa
Copy link

AngelVersa commented Jul 20, 2022 •
edited
Loading

But then you do not have WiFi, do not?

@ffamar
Copy link
Author

ffamar commented Jul 20, 2022

I have WiFi in station mode and BLE at the same time.
Disabling this option means that the manage of coexistence BLE and WiFi is hardware.

@SatishSolankeEsp
Copy link
Contributor

SatishSolankeEsp commented Jul 21, 2022 •
edited
Loading

Hi @ffamar @AngelVersa ,
I have gone through the comment and ELx400 error code, looks like an issue is coming in the case of coex(wifi and BT combine ) scenario.

disabled "Software controls WiFi/Bluetooth coexistence" in the sdkconfig may not be the correct solution but if you are stuck and helps you to move on as of now go with it.

Software controls WiFi/Bluetooth coexistence = Handle coex by SW ways in case priority and all.

Could you please tell me the steps to reproduce the issue? if it is with a phone with the model or some details of the issue.
Do you guys have OTA or logs before/after the issue hit? Are you guys using ESP examples if yes could you point it out?
Share the sample code so that we can reproduce the issue locally?

Thanks,
Satish

@ffamar
Copy link
Author

ffamar commented Jul 21, 2022

Hi Satish,
thank for your help.
In the official documentation about CONFIG_ESP32_WIFI_SW_COEXIST_ENABLE espressif wrote:
If enabled, WiFi & Bluetooth coexistence is controlled by software rather than hardware.
Whitout this option my firmware manages wifi station connection and ble in the rigth way.

My scenario is:

  • Idf 4.4.1
  • BLE Slave ("peripheral").
  • WIFI Station
  • Smarphone Samsung S20+ or Huaway P9+

ELx400 is printed after an indefinite time, sometime immediately after boot, sometime after 2 days.
When ELx400 is printed the the app in the smartphone is off and esp32 is advertising.

I sarted fromt ble_spp_server example and I added wifi station connection.

Thanks.

@AngelVersa
Copy link

I will give a try, thanks

Hi @ffamar @AngelVersa , I have gone through the comment and ELx400 error code, looks like an issue is coming in the case of coex(wifi and BT combine ) scenario.

disabled "Software controls WiFi/Bluetooth coexistence" in the sdkconfig may not be the correct solution but if you are stuck and helps you to move on as of now go with it.

Software controls WiFi/Bluetooth coexistence = Handle coex by SW ways in case priority and all.

Could you please tell me the steps to reproduce the issue? if it is with a phone with the model or some details of the issue. Do you guys have OTA or logs before/after the issue hit? Are you guys using ESP examples if yes could you point it out? Share the sample code so that we can reproduce the issue locally?

Thanks, Satish

Hi Satish,

My setup is:
esp32 esp-wroom
esp-idf v4.3.2.
BLE Slave ("peripheral") with nimble
WIFI Station
Mqtt conection
UART (to use a rs485 driver)
i2c (to use an external rtc)
spi (to use an external flash)

The issue is the same than @ffamar. After an indefinite time (between a couple of hours to days) the ELx400 message appears. When the ELx400 message appears, the esp32 advertising disappears.

This can happens on devices that never got connected by the smartphone.

The only way I found to solve the problem when it appears is to reboot the esp32.

Thanks,

@SatishSolankeEsp
Copy link
Contributor

Hi @ffamar ,
We have a fix for the ELx400 in the controller lib on IDF4.4.1 , could you please rebase it?

In your log, I still see your point to the older BT controller compile version [6a07b06].
image

It is supposed to be BT controller compile version 5688ed5.

Could you please try your scenario on the latest BT controller compile version and let me know if you have an identical issue?

Thanks,
Satish

@SatishSolankeEsp
Copy link
Contributor

Hi @AngelVersa ,
The same IDF4.3.2 doesn't have a fix for error EL0x400.
Could you please try on IDF4.3.3 and let me know the result?

Thanks,
Satish

@AngelVersa
Copy link

Hi @SatishSolankeEsp ,

I am on it right now, I will give you feedback as soon as posible, thanks for your time.

@ffamar
Copy link
Author

ffamar commented Jul 21, 2022

Hi @ffamar , We have a fix for the ELx400 in the controller lib on IDF4.4.1 , could you please rebase it?

In your log, I still see your point to the older BT controller compile version [6a07b06]. image

It is supposed to be BT controller compile version 5688ed5.

Could you please try your scenario on the latest BT controller compile version and let me know if you have an identical issue?

Thanks, Satish

Hi Satish,
when I opened the issue I had the old compile version of the BT controller [6a07b06], now I confirm that I have [5688ed5].
I have just launched a new test whit CONFIG_ESP32_WIFI_SW_COEXIST_ENABLE, I'll let you know if the issue persists or if it is definitively fixed.

Last question for you, is it better to set CONFIG_ESP32_WIFI_SW_COEXIST_ENABLE or not?

Thank you for your time.

@SatishSolankeEsp
Copy link
Contributor

Hi @ffamar ,
Yes, We should enable CONFIG_ESP32_WIFI_SW_COEXIST_ENABLE.

Thanks,
Satish

@SatishSolankeEsp
Copy link
Contributor

Hi @ffamar @AngelVersa ,
Do you have any updates for me?
Thanks,
Satish

@AngelVersa
Copy link

I found some issues trying to update the SDK (MQTTs and wifi most of them), but now I think that now is fixed. I left one device running and logging all the weekend with the 4.3.3 SDK version and the coexistence enabled. The ELx400 message didn't appear, but I want to wait another week more before give the solution as valid.

@ffamar
Copy link
Author

ffamar commented Jul 26, 2022

Hi Satish,
after 3 days of testing the ELx400 message didn't appear.
The issue seems fixed.
Thanks

@Isl2017 Isl2017 closed this as completed Jul 26, 2022
@ffamar
Copy link
Author

ffamar commented Aug 4, 2022 •
edited
Loading

Hi @SatishSolankeEsp, during the firmware update regression tests I encountered a serious issue when CONFIG_ESP32_WIFI_SW_COEXIST_ENABLE = y.

esp_ota_begin called with large image size (1263952) causes a WDT reset.

This is a log with CONFIG_ESP32_WIFI_SW_COEXIST_ENABLE is not set, esp_ota_begin ends succesfully in 4.4 s

D (323754) CMD_MAN: Start erase partition firmwareLen: 1263952 <--This is printed before esp_ota_begin
D (328214) CMD_MAN: Partition ota_1 erased                                  <--This is printed after esp_ota_begin

This is a log with CONFIG_ESP32_WIFI_SW_COEXIST_ENABLE=y, WDT reset.

D (38517) CMD_MAN: Start erase partition firmwareLen: 1263952     <--This is printed before esp_ota_begin
ets Jun  8 2016 00:22:57

rst:0x8 (TG1WDT_SYS_RESET),boot:0x12 (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:0x3fff0030,len:6608
load:0x40078000,len:14788
ho 0 tail 12 room 4
load:0x40080400,len:3792
0x40080400: _init at ??:?

entry 0x40080694
I (171) boot: ESP-IDF v4.4.1 2nd stage bootloader
I (171) boot: compile time 16:42:46
I (172) boot: chip revision: 1
I (175) boot.esp32: SPI Speed      : 40MHz
I (180) boot.esp32: SPI Mode       : DIO
I (185) boot.esp32: SPI Flash Size : 16MB
W (189) boot.esp32: PRO CPU has been reset by WDT.
W (195) boot.esp32: WDT reset info: PRO CPU PC=0x400945e1
0x400945e1: _xt_context_save at /home/famar/Works/toolchain/esp/esp-idf-v4.4.1/components/freertos/port/xtensa/xtensa_context.S:209

W (201) boot.esp32: WDT reset info: APP CPU PC=0x40081f6d
0x40081f6d: panicHandler at /home/famar/Works/toolchain/esp/esp-idf-v4.4.1/components/esp_system/port/panic_handler.c:213

I (207) boot: Enabling RNG early entropy source...
I (212) boot: Partition Table:
I (216) boot: ## Label            Usage          Type ST Offset   Length
I (223) boot:  0 otadata          OTA data         01 00 00009000 00002000
I (231) boot:  1 nvs              WiFi data        01 02 0000b000 00505000
I (239) boot:  2 ota_0            OTA app          00 10 00510000 00500000
I (246) boot:  3 ota_1            OTA app          00 11 00a10000 00500000

In this case if I disable WD esp_ota_begin never end and nothing else is printed.

Thanks for your help.

@ffamar
Copy link
Author

ffamar commented Aug 29, 2022 •
edited
Loading

Hi @SatishSolankeEsp, I executed the same test using esp idf 4.4.2 and I got the same result.

I (171) boot: ESP-IDF v4.4.2 2nd stage bootloader
I (171) boot: compile time 08:38:19
I (172) boot: chip revision: 1
I (175) boot.esp32: SPI Speed      : 40MHz
I (180) boot.esp32: SPI Mode       : DIO
I (185) boot.esp32: SPI Flash Size : 16MB
W (189) boot.esp32: PRO CPU has been reset by WDT.
W (195) boot.esp32: WDT reset info: PRO CPU PC=0x40081f91
0x40081f91: panicHandler at /home/famar/Works/toolchain/esp/esp-idf-v4.4.2/components/esp_system/port/panic_handler.c:213

W (201) boot.esp32: WDT reset info: APP CPU PC=0x40081f91
0x40081f91: panicHandler at /home/famar/Works/toolchain/esp/esp-idf-v4.4.2/components/esp_system/port/panic_handler.c:213

I (207) boot: Enabling RNG early entropy source...

Thanks for your help.

@espressif-bot espressif-bot added Status: Done Issue is done internally Resolution: Done Issue is done internally and removed Status: Opened Issue is new labels May 23, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Resolution: Done Issue is done internally Status: Done Issue is done internally
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@Weijian-Espressif @ffamar @Isl2017 @espressif-bot @AngelVersa @SatishSolankeEsp