espressif / esp-idf

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

Nimble SPP Server example doesn't work (IDFGH-12002) #13070

Open riegaz opened 7 months ago

riegaz commented 7 months ago

Answers checklist.

IDF version.

v5.1.2

Espressif SoC revision.

ESP32 v1.0

Operating System used.

macOS

How did you build your project?

VS Code IDE

If you are using Windows, please specify command line type.

None

Development Kit.

ESP32-WROOM-32D

Power Supply used.

External 5V

What is the expected behavior?

The SPP server example should advertise as a bluetooth device.

What is the actual behavior?

It doesn't advertise, at least I can't find it.

Steps to reproduce.

  1. Create a fresh SPP server project, program it, run it.

Debug Logs.

I (31) boot: ESP-IDF v5.1.2-dirty 2nd stage bootloader
I (31) boot: compile time Jan 25 2024 11:34:45
I (31) boot: Multicore bootloader
I (35) boot: chip revision: v1.0
I (39) boot.esp32: SPI Speed : 40MHz
I (44) boot.esp32: SPI Mode : DIO
I (48) boot.esp32: SPI Flash Size : 2MB
I (53) boot: Enabling RNG early entropy source...
I (58) boot: Partition Table:
I (62) boot: ## Label Usage Type ST Offset Length
I (69) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (77) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (84) boot: 2 factory factory app 00 00 00010000 00100000
I (92) boot: End of partition table
I (96) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=190a0h (102560) map
I (141) esp_image: segment 1: paddr=000290c8 vaddr=3ffbdb60 size=049b8h ( 18872) load
I (149) esp_image: segment 2: paddr=0002da88 vaddr=40080000 size=02590h ( 9616) load
I (153) esp_image: segment 3: paddr=00030020 vaddr=400d0020 size=61f38h (401208) map
I (300) esp_image: segment 4: paddr=00091f60 vaddr=40082590 size=17ec0h ( 97984) load
I (355) boot: Loaded app from partition at offset 0x10000
I (355) boot: Disabling RNG early entropy source...
I (366) cpu_start: Multicore app
I (367) cpu_start: Pro cpu up.
I (367) cpu_start: Starting app cpu, entry point is 0x40081568
0x40081568: call_start_cpu1 at /Users/taarimi7/Downloads/proj/esp-idf/components/esp_system/port/cpu_start.c:157

I (0) cpu_start: App cpu up.
I (384) cpu_start: Pro cpu start user code
I (385) cpu_start: cpu freq: 160000000 Hz
I (385) cpu_start: Application information:
I (389) cpu_start: Project name: bleuart5
I (394) cpu_start: App version: 1
I (399) cpu_start: Compile time: Jan 25 2024 11:34:33
I (405) cpu_start: ELF file SHA256: 1a3d2ec7b5fcad54...
I (411) cpu_start: ESP-IDF: v5.1.2-dirty
I (416) cpu_start: Min chip rev: v0.0
I (421) cpu_start: Max chip rev: v3.99
I (426) cpu_start: Chip rev: v1.0
I (431) heap_init: Initializing. RAM available for dynamic allocation:
I (438) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (444) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (450) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (456) heap_init: At 3FFC5508 len 0001AAF8 (106 KiB): DRAM
I (462) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (469) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (475) heap_init: At 4009A450 len 00005BB0 (22 KiB): IRAM
I (483) spi_flash: detected chip: generic
I (486) spi_flash: flash io: dio
W (490) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (504) coexist: coex firmware version: https://github.com/project-chip/connectedhomeip/commit/b6d5e8c8b02ada06a12febcb3b47feeb0ae5452f
I (509) app_start: Starting scheduler on CPU0
I (513) app_start: Starting scheduler on CPU1
mI (513) main_task: Started on CPU0
I (523) main_task: Calling app_main()
I (543) BTDM_INIT: BT controller compile version [ec4ac65]
I (543) BTDM_INIT: Bluetooth MAC: e8:9f:6d:a6:c9:52
I (543) phy_init: phy_version 4780,16b31a7,Sep 22 2023,20:42:16
I (87I (873) NimBLE: BLE server UART_task started

I (873) NimBLE: BLE Host Task Started
I (873) main_task: Returned from app_main()
I (913) NimBLE: Device Address:
I (913) NimBLE: e8:9f:6d:a6:c9:52
I (913) NimBLE:

I (913) NimBLE: GAP procedure initiated: advertise;
I (913) NimBLE: disc_mode=2
I (923) NimBLE: adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
I (933) NimBLE:

More Information.

I tried with ESP-IDF v5.1 and v5.2 and neither worked.

rahult-github commented 7 months ago

Hi @riegaz ,

I checked the application against nrf connect and do i see it works as expected. Attached is console log for esp32 side and nrf snapshots for finding the device and able to connect it.

spp_server_success.txt

nrfconnect can find the device :

image

And is also able to connect .

image

So, functionality for examples is working ok.

In your log :

image

As seen here, advertising has been initiated.

at least I can't find it.

So, may i know

  1. what central device is being used for scanning ?
  2. Are there any other modifications done in the code ?
  3. Can the central device find other BLE devices in the vicinity ?
  4. Can you try spp_client example to check if it works against the spp_server example ?
italocjs commented 7 months ago

I have the exact same issue, using example from esp idf v5.1.2 for nimble nothing shows up on my phone NRF connect, verbose log.txt

The radio was working under arduino examples before.

Edit: also added images. the source code was NOT modified in any way, just got the example and built it with no success.

device information nrf scanning

italocjs commented 7 months ago

Tried with my two of my custom boards and two devkits to the same result! code says its started broadcasting but i do not see anything to connect to. I'm not sure but this may have messed up something in flash, as after flashing this code, im no longer able to correcly erase flash (it erases in 1.5s which is too low, usually takes 10+ seconds for 4mb chips and even more for 16mb chips),

This example works on my device and adversiting starts https://github.com/masuidrive/esp-nimble-nordic-uart/tree/main/components/nimble-nordic-uart

rahult-github commented 7 months ago

Hi @italocjs

I have the exact same issue, using example from esp idf v5.1.2 for nimble nothing shows up on my phone NRF connect, verbose log.txt

The radio was working under arduino examples before.

Edit: also added images. the source code was NOT modified in any way, just got the example and built it with no success.

device information nrf scanning

The version i tested with was Android 13. The one mentioend here is Android 11.

I tested with Android 11 too at my end, and observing similar behaviour. So, android versions doesn't seem to be a problem either.

This example works on my device and adversiting starts https://github.com/masuidrive/esp-nimble-nordic-uart/tree/main/components/nimble-nordic-uart

So i checked the example and the only differences i could see is that the particular example uses 128 bit UUID ( instead of 16 bit ) and a name shortened to length 5. Rest , everything is logically same during advertising.

So a query here, does any other IDF example, (say bleprph ) work at your end ? Since all examples use the same parameter, if other examples work but ble_spp doesn't , then that can help us narrow down the issue further.

italocjs commented 7 months ago

bleprph indeed works! here are info and verbose logs

i will study the difference in more detail later.

bleprph verbose log.txt bleprph info log.txt blephpr working

rahult-github commented 7 months ago

Hi @italocjs ,

bleprph and spp_server use the same advertising parameters ( apart from the 16 bit UUID information that is passed as data in the advertising report) .

I have one query though :

In the first log ( issue )

I (873) NimBLE: BLE Host Task Started I (873) main_task: Returned from app_main() I (913) NimBLE: Device Address: I (913) NimBLE: e8:9f:6d:a6:c9:52 I (913) NimBLE:

in second bleprph log ( success )

I (884) main_task: Returned from app_main() I (904) NimBLE: Device Address: I (904) NimBLE: 08:d1:f9:c4:a5:2a I (904) NimBLE:

Since bluetooth MAC address is different , are these 2 different chips ? If yes, can you confirm if running the spp server application on the second chip works ?

italocjs commented 7 months ago

Hi @italocjs ,

bleprph and spp_server use the same advertising parameters ( apart from the 16 bit UUID information that is passed as data in the advertising report) .

I have one query though :

In the first log ( issue )

I (873) NimBLE: BLE Host Task Started I (873) main_task: Returned from app_main() I (913) NimBLE: Device Address: I (913) NimBLE: e8:9f:6d:a6:c9:52 I (913) NimBLE:

in second bleprph log ( success )

I (884) main_task: Returned from app_main() I (904) NimBLE: Device Address: I (904) NimBLE: 08:d1:f9:c4:a5:2a I (904) NimBLE:

Since bluetooth MAC address is different , are these 2 different chips ? If yes, can you confirm if running the spp server application on the second chip works ?

Hello!, is likely another chip, i have two devkits and 3 proprietary boards laying here (flashed all to no success, the devkits are ESP_WROOM-32E 4MB Flash and the proprietary are ESP-WROOM-32D 16mb flash). I did not investigate this further because i found another working example which already integrated NuS so i developed based on it. Not sure if its helpful but here is my current code: https://github.com/italocjs/ESP32Arduino_NimbleNUS_processor

I noticed that the verbose log for blephpr is not complete, i will flash it again and post the complete verbose later so we can compare in more detail.

As i mentioned previosly, another strange thing was happening, for some reason when using the esp-idf spp example i was not able to erase the flash correctly, i think something was being messed up in the nvs sector reserved for the RF data. When erasing flash with an standard code (ble_phpr or "hello world" for example) it would take ~14s to erase the 4MB flash, when using the ble spp example, it was only taking 1.5s. The issue may be related to this.

rahult-github commented 3 months ago

Closing this. Feel free to reopen if issue still observed.

italocjs commented 3 months ago

Sorry @rahult-github , but was this fixed? someone tested it again? i dont agree on closing since there is no clear solution here. The espidf docs MUST work for everyone, not at random, without it no one can reliable develop based on it.

rahult-github commented 3 months ago

Reopening it.

bleprph indeed works! here are info and verbose logs

So, it was confirmed that IDF examples work ok.

i will flash it again and post the complete verbose later so we can compare in more detail.

Can you please share this .

for some reason when using the esp-idf spp example i was not able to erase the flash correctly,

Did you get a chance to check this ? Is issue seen on all chipsets or one particular chip ?

The espidf docs MUST work for everyone, not at random,

yes indeed, we do have a exhaustive internal QA cycle where this gets validated. But yes, we can debug more on what is happening at your end to narrow down this further.

italocjs commented 3 months ago

Thank you for testing, i will test on a few board that i have here too after work, can you please share which version of idf you used?

So far, the only main difference i found was that my chips have 16mb flash, and for some very weird reason, after flashing the sample code, it seems that the erase_flash stopped working properly (it concluded in 1.5s instead of the usual 10s+). I also have some devkits that i will try.

rahult-github commented 3 months ago

can you please share which version of idf you used?

The same as reported in this issue . ESP32 chipset on v5.1.2