esp-idf: Status: Requesting Composition Data gets an error when using ble-mesh/on-off-server example out of the box (IDFGH-8482)

Answers checklist.

  • I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
  • I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
  • I have searched the issue tracker for a similar issue and not found a similar issue.

IDF version.

v4.4

Operating System used.

Windows

How did you build your project?

Command line with idf.py

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

CMD

Development Kit.

ESP32-C3-DevKitM1-v1.0

Power Supply used.

USB

What is the expected behavior?

When using ESP-BLE-MESH/on-off-server example, with two or more devices, the app should be able to get the Composition Data successfully for the 2nd device

What is the actual behavior?

The Status: Requesting Composition Data for the 2nd device finishes into Error: request timed out

Steps to reproduce.

  1. Build ESP-BLE-MESH/on-off-server example
  2. Flash two or more devices
  3. Use the iOS nRF Mesh app to provision the devices
  4. when provisioning the second device, the error appears …

Debug Logs.

1st device provisioned (this one works)
I (30) boot: ESP-IDF v4.4-dirty 2nd stage bootloader
I (30) boot: compile time 14:07:49
I (30) boot: chip revision: 3
I (32) boot.esp32c3: SPI Speed      : 80MHz
I (37) boot.esp32c3: SPI Mode       : DIO
I (42) boot.esp32c3: SPI Flash Size : 2MB
I (46) boot: Enabling RNG early entropy source...
I (52) boot: Partition Table:
I (55) boot: ## Label            Usage          Type ST Offset   Length
I (63) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (70) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (78) boot:  2 factory          factory app      00 00 00010000 00100000
I (85) boot: End of partition table
I (89) esp_image: segment 0: paddr=00010020 vaddr=3c0c0020 size=2a840h (174144) map
I (125) esp_image: segment 1: paddr=0003a868 vaddr=3fc8e400 size=0305ch ( 12380) load
I (127) esp_image: segment 2: paddr=0003d8cc vaddr=40380000 size=0274ch ( 10060) load
I (133) esp_image: segment 3: paddr=00040020 vaddr=42000020 size=b218ch (729484) map
I (253) esp_image: segment 4: paddr=000f21b4 vaddr=4038274c size=0bc84h ( 48260) load
I (262) esp_image: segment 5: paddr=000fde40 vaddr=50000010 size=00010h (    16) load
I (267) boot: Loaded app from partition at offset 0x10000
I (267) boot: Disabling RNG early entropy source...
I (283) cpu_start: Pro cpu up.
I (290) cpu_start: Pro cpu start user code
I (291) cpu_start: cpu freq: 160000000
I (291) cpu_start: Application information:
I (293) cpu_start: Project name:     onoff_server
I (299) cpu_start: App version:      v4.4-dirty
I (304) cpu_start: Compile time:     Oct  7 2022 14:31:29
I (310) cpu_start: ELF file SHA256:  f3d971a4a0d9d8df...
I (316) cpu_start: ESP-IDF:          v4.4-dirty
I (321) heap_init: Initializing. RAM available for dynamic allocation:
I (328) heap_init: At 3FC98490 len 00027B70 (158 KiB): DRAM
I (335) heap_init: At 3FCC0000 len 0001F060 (124 KiB): STACK/DRAM
I (341) heap_init: At 50000020 len 00001FE0 (7 KiB): RTCRAM
I (348) spi_flash: detected chip: generic
I (353) spi_flash: flash io: dio
W (356) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (370) sleep: Configure to isolate all GPIO pins in sleep state
I (376) sleep: Enable automatic switching of GPIO sleep configuration
I (384) coexist: coexist rom version 9387209
I (388) cpu_start: Starting scheduler.
I (393) EXAMPLE: Initializing...
I (393) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (403) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (413) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
W (423) BTDM_INIT: esp_bt_controller_mem_release not implemented, return OK
I (423) BTDM_INIT: BT controller compile version [6881869]
I (433) phy_init: phy_version 907,3369105-dirty,Dec  3 2021,14:55:12
I (473) system_api: Base MAC address is not set
I (473) system_api: read default base MAC address from EFUSE
I (473) BTDM_INIT: Bluetooth MAC: 84:f7:03:67:da:b2

I (563) EXAMPLE: ESP_BLE_MESH_PROV_REGISTER_COMP_EVT, err_code 0
I (563) EXAMPLE: ESP_BLE_MESH_NODE_PROV_ENABLE_COMP_EVT, err_code 0
I (563) EXAMPLE: BLE Mesh Node initialized
I (17383) EXAMPLE: ESP_BLE_MESH_NODE_PROV_LINK_OPEN_EVT, bearer PB-GATT
W (17733) BLE_MESH: No Health Server context provided
W (19693) BLE_MESH: No Health Server context provided
I (19703) EXAMPLE: ESP_BLE_MESH_NODE_PROV_LINK_CLOSE_EVT, bearer PB-GATT
I (19703) EXAMPLE: ESP_BLE_MESH_NODE_PROV_COMPLETE_EVT
I (19703) EXAMPLE: net_idx: 0x0000, addr: 0x01de
I (19713) EXAMPLE: flags: 0x00, iv_index: 0x00000000

2nd device provisioned(this one doesn't work)
I (30) boot: ESP-IDF v4.4-dirty 2nd stage bootloader
I (30) boot: compile time 14:07:49
I (30) boot: chip revision: 3
I (32) boot.esp32c3: SPI Speed      : 80MHz
I (37) boot.esp32c3: SPI Mode       : DIO
I (42) boot.esp32c3: SPI Flash Size : 2MB
I (46) boot: Enabling RNG early entropy source...
I (52) boot: Partition Table:
I (55) boot: ## Label            Usage          Type ST Offset   Length
I (63) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (70) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (78) boot:  2 factory          factory app      00 00 00010000 00100000
I (85) boot: End of partition table
I (89) esp_image: segment 0: paddr=00010020 vaddr=3c0c0020 size=2a840h (174144) map
I (125) esp_image: segment 1: paddr=0003a868 vaddr=3fc8e400 size=0305ch ( 12380) load
I (127) esp_image: segment 2: paddr=0003d8cc vaddr=40380000 size=0274ch ( 10060) load
I (133) esp_image: segment 3: paddr=00040020 vaddr=42000020 size=b218ch (729484) map
I (253) esp_image: segment 4: paddr=000f21b4 vaddr=4038274c size=0bc84h ( 48260) load
I (262) esp_image: segment 5: paddr=000fde40 vaddr=50000010 size=00010h (    16) load
I (267) boot: Loaded app from partition at offset 0x10000
I (267) boot: Disabling RNG early entropy source...
I (283) cpu_start: Pro cpu up.
I (290) cpu_start: Pro cpu start user code
I (290) cpu_start: cpu freq: 160000000
I (290) cpu_start: Application information:
I (293) cpu_start: Project name:     onoff_server
I (299) cpu_start: App version:      v4.4-dirty
I (304) cpu_start: Compile time:     Oct  7 2022 14:31:29
I (310) cpu_start: ELF file SHA256:  f3d971a4a0d9d8df...
I (316) cpu_start: ESP-IDF:          v4.4-dirty
I (321) heap_init: Initializing. RAM available for dynamic allocation:
I (328) heap_init: At 3FC98490 len 00027B70 (158 KiB): DRAM
I (334) heap_init: At 3FCC0000 len 0001F060 (124 KiB): STACK/DRAM
I (341) heap_init: At 50000020 len 00001FE0 (7 KiB): RTCRAM
I (348) spi_flash: detected chip: generic
I (352) spi_flash: flash io: dio
W (356) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (370) sleep: Configure to isolate all GPIO pins in sleep state
I (376) sleep: Enable automatic switching of GPIO sleep configuration
I (383) coexist: coexist rom version 9387209
I (388) cpu_start: Starting scheduler.
I (393) EXAMPLE: Initializing...
I (393) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (403) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (413) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
W (423) BTDM_INIT: esp_bt_controller_mem_release not implemented, return OK
I (423) BTDM_INIT: BT controller compile version [6881869]
I (433) phy_init: phy_version 907,3369105-dirty,Dec  3 2021,14:55:12
W (443) phy_init: failed to load RF calibration data (0x1102), falling back to full calibration
I (493) system_api: Base MAC address is not set
I (493) system_api: read default base MAC address from EFUSE
I (493) BTDM_INIT: Bluetooth MAC: 84:f7:03:66:a4:76

I (593) EXAMPLE: ESP_BLE_MESH_PROV_REGISTER_COMP_EVT, err_code 0
I (593) EXAMPLE: ESP_BLE_MESH_NODE_PROV_ENABLE_COMP_EVT, err_code 0
I (593) EXAMPLE: BLE Mesh Node initialized
I (18863) EXAMPLE: ESP_BLE_MESH_NODE_PROV_LINK_OPEN_EVT, bearer PB-GATT
W (19193) BLE_MESH: No Health Server context provided
W (21083) BLE_MESH: No Health Server context provided
I (21093) EXAMPLE: ESP_BLE_MESH_NODE_PROV_LINK_CLOSE_EVT, bearer PB-GATT
I (21103) EXAMPLE: ESP_BLE_MESH_NODE_PROV_COMPLETE_EVT
I (21103) EXAMPLE: net_idx: 0x0000, addr: 0x01e1
I (21103) EXAMPLE: flags: 0x00, iv_index: 0x00000000

More Information.

I want to be able to provision several devices with the same app. As far as I know, this should be possible using the example out of the box.

https://www.youtube.com/watch?v=cgqMMck3OSU You can see in 0:35 that the 2nd device is provisioned successfully, so I expect this to happen as well on my setup.

Thanks a lot in advance 😃

About this issue

  • Original URL
  • State: closed
  • Created 2 years ago
  • Comments: 25

Most upvoted comments

hi, @gomez9656 I have tested with your project, but it still works well. Combined with @AntoineSX ‘s experience and the last log information(that log shows the first node forwarded the composition data get msg to the second node successfully but the second node didn’t receive), I guess if that nodes on your side are also far apart or there are some obstacles that hinder the propagation of the signal, And how much nodes in your test net? could you provide me with your test video, so that I can replicate your test environment.

By the way, esp_ble_tx_power_set in the file components\bt\controller\esp32c3\bt.c : 1367. This function could change your transmitting power.

Thanks a lot.

+1
forx157 on Oct 27, 2022
Read more comments on GitHub
← esp-idf: statement 'cout<<endl<<"App Running"<<endl;' causes wdt & cpu-reset in endless loop, with several different backtraces. Also happens with standard esp-idf lcd/lvgl example (IDFGH-7728)
esp-idf: Support for 32MB version of ESP32S3 Module is missing (IDFGH-6736) →