gatt client - heap corruption

[dhs2017]

I use the latest version IDF, with the module from brand A, when I use the function esp_ble_gattc_get_all char, it will trigger the heap corruption.

However, when I use the module from another brand B, this problem doesn't appear, anyone can help?

Code: Select all

CORRUPT HEAP: multi_heap.c:173 detected at 0x3ffcf03c
abort() was called at PC 0x400882fa on core 0

[ESP_Angus]

Hi dhs2017,

Are there any other differences between the two modules (ESP32 silicon revision, SPI flash type or size, etc?) Can you post the full log from both, please?

There may be some hardware-specific differences which change the timing of the code, and cause the heap corruption bug to trigger.

Some documentation for debugging heap corruption bugs can be found here:
https://esp-idf.readthedocs.io/en/lates ... -detection

Angus

[dhs2017]

Brand A:

Code: Select all

ets Jun  8 2016 00:22:57

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:0x3fff0010,len:4
load:0x3fff0014,len:5544
load:0x40078000,len:0
ho 12 tail 0 room 4
load:0x40078000,len:12476
entry 0x40078f74
W (72) rtc_clk: Possibly invalid CONFIG_ESP32_XTAL_FREQ setting (40MHz). Detected 40 MHz.
I (38) boot: ESP-IDF v3.0-dev-806-gde750e99 2nd stage bootloader
I (38) boot: compile time 14:38:03
I (38) boot: Enabling RNG early entropy source...
I (44) boot: SPI Speed      : 40MHz
I (48) boot: SPI Mode       : DIO
I (52) boot: SPI Flash Size : 4MB
I (56) boot: Partition Table:
I (60) boot: ## Label            Usage          Type ST Offset   Length
I (67) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (75) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (82) boot:  2 factory          factory app      00 00 00010000 00100000
I (90) boot: End of partition table
I (94) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x2b2cc (176844) map
I (164) esp_image: segment 1: paddr=0x0003b2f4 vaddr=0x3ffc0000 size=0x0274c ( 10060) load
I (168) esp_image: segment 2: paddr=0x0003da48 vaddr=0x40080000 size=0x00400 (  1024) load
I (171) esp_image: segment 3: paddr=0x0003de50 vaddr=0x40080400 size=0x021c0 (  8640) load
I (183) esp_image: segment 4: paddr=0x00040018 vaddr=0x400d0018 size=0x67510 (423184) map
I (335) esp_image: segment 5: paddr=0x000a7530 vaddr=0x400825c0 size=0x0f17c ( 61820) load
I (361) esp_image: segment 6: paddr=0x000b66b4 vaddr=0x400c0000 size=0x00000 (     0) load
I (371) boot: Loaded app from partition at offset 0x10000
I (371) boot: Disabling RNG early entropy source...
I (373) cpu_start: Pro cpu up.
I (376) cpu_start: Starting app cpu, entry point is 0x40081098
I (0) cpu_start: App cpu up.
I (387) heap_init: Initializing. RAM available for dynamic allocation:
I (393) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (399) heap_init: At 3FFC9F80 len 00016080 (88 KiB): DRAM
I (406) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (412) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (418) heap_init: At 4009173C len 0000E8C4 (58 KiB): IRAM
I (425) cpu_start: Pro cpu start user code
I (107) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (157) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (447) phy: phy_version: 359.0, e79c19d, Aug 31 2017, 17:06:07, 0, 0
E (477) BT: btc_gattc_call_handler()
I (487) GATTC_DEMO: REG_EVT
I (487) GATTC_DEMO: scan start success
I (597) GATTC_DEMO: 00 03 5b 00 15 10 
I (597) GATTC_DEMO: searched Adv Data Len 21, Scan Response Len 0
I (597) GATTC_DEMO: searched Device Name Len 3
I (607) GATTC_DEMO: ESS
I (607) GATTC_DEMO: 

I (607) GATTC_DEMO: searched device ESS

I (617) GATTC_DEMO: connect to the remote device.
I (617) GATTC_DEMO: 53 6a 63 f3 d6 aa 
I (627) GATTC_DEMO: searched Adv Data Len 14, Scan Response Len 0
I (637) GATTC_DEMO: searched Device Name Len 0
I (637) GATTC_DEMO: 

I (647) GATTC_DEMO: stop scan successfully
I (747) GATTC_DEMO: ESP_GATTC_CONNECT_EVT conn_id 0, if 3, status 0
I (747) GATTC_DEMO: REMOTE BDA:
I (747) GATTC_DEMO: 00 03 5b 00 15 10 
I (757) GATTC_DEMO: open success
I (1537) GATTC_DEMO: ESP_GATTC_CFG_MTU_EVT, Status 0, MTU 23, conn_id 0
I (1537) GATTC_DEMO: ESP_GATTC_SEARCH_RES_EVT
I (1547) GATTC_DEMO: service found
I (1547) GATTC_DEMO: UUID16: 181a
I (1547) GATTC_DEMO: ESP_GATTC_SEARCH_CMPL_EVT
I (1557) GATTC_DEMO: 6 attributes found
CORRUPT HEAP: multi_heap.c:173 detected at 0x3ffd63b8
abort() was called at PC 0x400882f6 on core 0

Backtrace: 0x40088d28:0x3ffd1250 0x40088e27:0x3ffd1270 0x400882f6:0x3ffd1290 0x400887d5:0x3ffd12b0 0x40082292:0x3ffd12d0 0x400825f1:0x3ffd12f0 0x4000bec7:0x3ffd1310 0x400ec8c1:0x3ffd1330 0x400e75e5:0x3ffd1360 0x400d4340:0x3ffd1390 0x400d40a3:0x3ffd13e0 0x400ecba5:0x3ffd1410 0x400e7a1a:0x3ffd1450

Rebooting...
ets Jun  8 2016 00:22:57

[dhs2017]

Brand B:

Code: Select all

ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
ets Jun  8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_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:0x3fff0010,len:4
load:0x3fff0014,len:5544
load:0x40078000,len:0
ho 12 tail 0 room 4
load:0x40078000,len:12476
entry 0x40078f74
W (73) rtc_clk: Possibly invalid CONFIG_ESP32_XTAL_FREQ setting (40MHz). Detected 40 MHz.
I (39) boot: ESP-IDF v3.0-dev-806-gde750e99 2nd stage bootloader
I (39) boot: compile time 14:38:03
I (49) boot: Enabling RNG early entropy source...
I (49) 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 (75) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (83) boot:  2 factory          factory app      00 00 00010000 00100000
I (90) boot: End of partition table
I (95) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x2b2cc (176844) map
I (165) esp_image: segment 1: paddr=0x0003b2f4 vaddr=0x3ffc0000 size=0x0274c ( 10060) load
I (169) esp_image: segment 2: paddr=0x0003da48 vaddr=0x40080000 size=0x00400 (  1024) load
I (172) esp_image: segment 3: paddr=0x0003de50 vaddr=0x40080400 size=0x021c0 (  8640) load
I (184) esp_image: segment 4: paddr=0x00040018 vaddr=0x400d0018 size=0x67510 (423184) map
I (336) esp_image: segment 5: paddr=0x000a7530 vaddr=0x400825c0 size=0x0f17c ( 61820) load
I (362) esp_image: segment 6: paddr=0x000b66b4 vaddr=0x400c0000 size=0x00000 (     0) load
I (372) boot: Loaded app from partition at offset 0x10000
I (372) boot: Disabling RNG early entropy source...
I (373) cpu_start: Pro cpu up.
I (377) cpu_start: Starting app cpu, entry point is 0x40081098
I (0) cpu_start: App cpu up.
I (387) heap_init: Initializing. RAM available for dynamic allocation:
I (394) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (400) heap_init: At 3FFC9F80 len 00016080 (88 KiB): DRAM
I (406) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (413) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (419) heap_init: At 4009173C len 0000E8C4 (58 KiB): IRAM
I (425) cpu_start: Pro cpu start user code
I (107) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (158) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (418) phy: phy_version: 359.0, e79c19d, Aug 31 2017, 17:06:07, 0, 0
E (468) BT: btc_gattc_call_handler()
I (468) GATTC_DEMO: REG_EVT
I (478) GATTC_DEMO: scan start success
I (588) GATTC_DEMO: 00 03 5b 00 15 10 
I (588) GATTC_DEMO: searched Adv Data Len 21, Scan Response Len 0
I (588) GATTC_DEMO: searched Device Name Len 3
I (588) GATTC_DEMO: ESS
I (598) GATTC_DEMO: 

I (598) GATTC_DEMO: searched device ESS

I (598) GATTC_DEMO: connect to the remote device.
I (608) GATTC_DEMO: stop scan successfully
I (988) GATTC_DEMO: ESP_GATTC_CONNECT_EVT conn_id 0, if 3, status 0
I (988) GATTC_DEMO: REMOTE BDA:
I (988) GATTC_DEMO: 00 03 5b 00 15 10 
I (988) GATTC_DEMO: open success
I (2168) GATTC_DEMO: ESP_GATTC_CFG_MTU_EVT, Status 0, MTU 23, conn_id 0
I (2168) GATTC_DEMO: ESP_GATTC_SEARCH_RES_EVT
I (2168) GATTC_DEMO: service found
I (2178) GATTC_DEMO: UUID16: 181a
I (2178) GATTC_DEMO: ESP_GATTC_SEARCH_CMPL_EVT
I (2188) GATTC_DEMO: 6 attributes found
I (2188) GATTC_DEMO: Temperature char 2a6e found handle 20 props 2
I (2198) GATTC_DEMO: Cleared char_elem_result memory

[ESP_Angus]

OK. It looks like there are some hardware differences, for example one module has revision 0 silicon and the other has revision 1. This is almost certainly not the cause of the bug, but it may change timing around a tiny bit - making it enough to trigger on one module.

Suggest following the steps at the link above to try and get more detail about the corruption.

You can also use "make monitor" or xtensa-esp32-elf-addr2line to decode the backtrace which may give some clues. You can find more about these tools here:
esp-idf.readthedocs.io/en/latest/get-started/idf-monitor.html
(addr2line is mentioned in a comment about half way down the page.)

Are you able to post your code anywhere? Check carefully for anything which may be overflowing a buffer.

[dhs2017]

Actually, from my observation, I found that brand B will also restart occasionally, but the chance is small.

I just do little modification in the gattc example code from the latest idf,

I added 5 char and just replace the find char by uuid function to this one.........

If I run find char by uuid function 6 times one by one, it's ok to find all the char without any problem on both modules.

[dhs2017]

OK. It looks like there are some hardware differences, for example one module has revision 0 silicon and the other has revision 1. This is almost certainly not the cause of the bug, but it may change timing around a tiny bit - making it enough to trigger on one module.

Suggest following the steps at the link above to try and get more detail about the corruption.

You can also use "make monitor" or xtensa-esp32-elf-addr2line to decode the backtrace which may give some clues. You can find more about these tools here:
esp-idf.readthedocs.io/en/latest/get-started/idf-monitor.html
(addr2line is mentioned in a comment about half way down the page.)

Are you able to post your code anywhere? Check carefully for anything which may be overflowing a buffer.

Someone reply me in github that the code should be written as this

Code: Select all

char_elem_result = (esp_gattc_char_elem_t *) malloc (sizeof (esp_gattc_char_elem_t) * count);

instead of

Code: Select all

char_elem_result = (esp_gattc_char_elem_t *)malloc(sizeof(char_elem_result) * count);

in the IDF example code, pls clarify....

[WiFive]

Yes looks like example is wrong.