search

aws / amazon-freertos

DEPRECATED - See README.md
https://aws.amazon.com/freertos/
MIT License
2.54k stars 1.1k forks source link

multi_heap_assert called when calling SecureSocketsTransport_Connect() #3081

Closed samuelbles07 closed 3 years ago

samuelbles07 commented 3 years ago

Hi,

My case is i am using amazon-freertos as submodule, and currently i want to integrate coreMQTT mqtt_demo_mutual_auth from demo directory to my main project. Everything in the main code is basically from the demo code, from wifi and mqtt. But when the code start execute SecureSocketsTransport_Connect(), multi_heap is called. Below is the log.

D (540) memory_layout: Checking 10 reserved memory ranges:
D (546) memory_layout: Reserved memory range 0x3ff80000 - 0x3ff80000
D (552) memory_layout: Reserved memory range 0x3ffae000 - 0x3ffae6e0
D (559) memory_layout: Reserved memory range 0x3ffae6e0 - 0x3ffaff10
D (565) memory_layout: Reserved memory range 0x3ffb0000 - 0x3ffb6388
D (571) memory_layout: Reserved memory range 0x3ffb8000 - 0x3ffb9a20
D (578) memory_layout: Reserved memory range 0x3ffbdb28 - 0x3ffbdb5c
D (584) memory_layout: Reserved memory range 0x3ffbdb60 - 0x3ffc7440
D (591) memory_layout: Reserved memory range 0x3ffe0000 - 0x3ffe0440
D (597) memory_layout: Reserved memory range 0x40070000 - 0x40078000
D (603) memory_layout: Reserved memory range 0x40080000 - 0x40095bac
0x40080000: _WindowOverflow4 at /Users/inventory-1/Project/build/../freertos/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1851

D (610) memory_layout: Building list of available memory regions:
D (616) memory_layout: Available memory region 0x3ff80000 - 0x3ff82000
D (623) memory_layout: Available memory region 0x3ffaff10 - 0x3ffb0000
D (629) memory_layout: Available memory region 0x3ffb6388 - 0x3ffb8000
D (636) memory_layout: Available memory region 0x3ffb9a20 - 0x3ffbdb28
D (642) memory_layout: Available memory region 0x3ffc7440 - 0x3ffc8000
D (649) memory_layout: Available memory region 0x3ffc8000 - 0x3ffca000
D (656) memory_layout: Available memory region 0x3ffca000 - 0x3ffcc000
D (662) memory_layout: Available memory region 0x3ffcc000 - 0x3ffce000
D (669) memory_layout: Available memory region 0x3ffce000 - 0x3ffd0000
D (675) memory_layout: Available memory region 0x3ffd0000 - 0x3ffd2000
D (682) memory_layout: Available memory region 0x3ffd2000 - 0x3ffd4000
D (689) memory_layout: Available memory region 0x3ffd4000 - 0x3ffd6000
D (695) memory_layout: Available memory region 0x3ffd6000 - 0x3ffd8000
D (702) memory_layout: Available memory region 0x3ffd8000 - 0x3ffda000
D (708) memory_layout: Available memory region 0x3ffda000 - 0x3ffdc000
D (715) memory_layout: Available memory region 0x3ffdc000 - 0x3ffde000
D (722) memory_layout: Available memory region 0x3ffde000 - 0x3ffe0000
D (728) memory_layout: Available memory region 0x3ffe0440 - 0x3ffe4000
D (735) memory_layout: Available memory region 0x3ffe4000 - 0x3ffe8000
D (741) memory_layout: Available memory region 0x3ffe8000 - 0x3fff0000
D (748) memory_layout: Available memory region 0x3fff0000 - 0x3fff8000
D (755) memory_layout: Available memory region 0x3fff8000 - 0x3fffc000
D (761) memory_layout: Available memory region 0x3fffc000 - 0x40000000
D (768) memory_layout: Available memory region 0x40078000 - 0x40080000
0x40080000: _WindowOverflow4 at /Users/inventory-1/Project/build/../freertos/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1851

D (774) memory_layout: Available memory region 0x40095bac - 0x40096000
D (781) memory_layout: Available memory region 0x40096000 - 0x40098000
D (788) memory_layout: Available memory region 0x40098000 - 0x4009a000
D (794) memory_layout: Available memory region 0x4009a000 - 0x4009c000
D (801) memory_layout: Available memory region 0x4009c000 - 0x4009e000
D (807) memory_layout: Available memory region 0x4009e000 - 0x400a0000
I (814) heap_init: Initializing. RAM available for dynamic allocation:
D (821) heap_init: New heap initialised at 0x3ff80000
I (826) heap_init: At 3FF80000 len 00002000 (8 KiB): RTCRAM
D (833) heap_init: New heap initialised at 0x3ffaff10
I (838) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
D (844) heap_init: New heap initialised at 0x3ffb6388
I (849) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
D (855) heap_init: New heap initialised at 0x3ffb9a20
I (860) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
D (866) heap_init: New heap initialised at 0x3ffc7440
I (871) heap_init: At 3FFC7440 len 00018BC0 (98 KiB): DRAM
I (878) heap_init: At 3FFE0440 len 0001FBC0 (126 KiB): D/IRAM
D (884) heap_init: New heap initialised at 0x40078000
I (889) heap_init: At 40078000 len 00008000 (32 KiB): IRAM
D (895) heap_init: New heap initialised at 0x40095bac
I (900) heap_init: At 40095BAC len 0000A454 (41 KiB): IRAM
I (907) cpu_start: Pro cpu start user code
D (919) clk: RTC_SLOW_CLK calibration value: 3560230
D (928) intr_alloc: Connected src 46 to int 2 (cpu 0)
D (929) intr_alloc: Connected src 17 to int 3 (cpu 0)
D (929) intr_alloc: Connected src 24 to int 9 (cpu 0)
D (934) FLASH_HAL: extra_dummy: 1
D (937) spi_flash: trying chip: issi
D (941) spi_flash: trying chip: gd
D (944) spi_flash: trying chip: mxic
D (948) spi_flash: trying chip: generic
I (952) spi_flash: detected chip: generic
I (957) spi_flash: flash io: dio
I (961) cpu_start: Starting scheduler on PRO CPU.
D (966) heap_init: New heap initialised at 0x3ffe0440
D (966) intr_alloc: Connected src 16 to int 12 (cpu 0)
D (976) partition: Loading the partition table
0 2 [main] Initializing lwIP TCP stack
D (986) esp_netif_lwip: LwIP stack has been initialized
D (986) esp_netif_lwip: esp-netif has been successfully initialized
I (996) PKCS11: Initializing NVS partition: "storage"
D (1006) PKCS11: Finding file P11_Cert
D (1006) nvs: nvs_open_from_partition creds 0
D (1006) PKCS11: failed nvs open 4354
D (1006) PKCS11: Finding file P11_CSK
D (1016) nvs: nvs_open_from_partition creds 0
D (1016) PKCS11: failed nvs open 4354
D (1026) PKCS11: Finding file P11_Key
D (1026) nvs: nvs_open_from_partition creds 0
D (1026) PKCS11: failed nvs open 4354
D (1036) PKCS11: Finding file P11_Key
D (1036) nvs: nvs_open_from_partition creds 0
D (1046) PKCS11: failed nvs open 4354
D (1046) PKCS11: Finding file P11_Cert
D (1046) nvs: nvs_open_from_partition creds 0
D (1056) PKCS11: failed nvs open 4354
1 9 [main] Write certificate...
D (1066) PKCS11: Writing file P11_Cert, 862 bytes
D (1066) nvs: nvs_open_from_partition creds 1
D (1076) nvs: nvs_set_blob P11_Cert 862
D (1076) nvs: nvs_close 1
D (1086) PKCS11: Writing file P11_Key, 1191 bytes
D (1086) nvs: nvs_open_from_partition creds 1
D (1086) nvs: nvs_set_blob P11_Key 1191
D (1096) nvs: nvs_close 2
D (1096) BTDM_INIT: Release DRAM [0x3ffb2730] - [0x3ffb6388]
D (1096) BTDM_INIT: Release DRAM [0x3ffae6e0] - [0x3ffaff10]
D (1106) BTDM_INIT: Release DRAM [0x3ffb0000] - [0x3ffb2730]
D (1106) BTDM_INIT: Release DRAM [0x3ffb8000] - [0x3ffb9a20]
D (1116) BTDM_INIT: Release DRAM [0x3ffbdb28] - [0x3ffbdb5c]
D (1126) event: running task for loop 0x3ffb8044
D (1126) event: created task for loop 0x3ffb8044
D (1136) event: created event loop 0x3ffb8044
D (1136) esp_netif_objects: esp_netif_add_to_list 0x3ffb92b0
D (1146) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 1)
D (1146) nvs: nvs_open_from_partition misc 1
D (1156) nvs: nvs_get_str_or_blob log
D (1156) nvs: nvs_set_blob log 4
I (1176) wifi:wifi driver task: 3ffb98a4, prio:23, stack:6656, core=0
I (1176) system_api: Base MAC address is not set
I (1176) system_api: read default base MAC address from EFUSE
D (1176) efuse: coding scheme 0
D (1186) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 8 bit
D (1186) efuse: coding scheme 0
D (1196) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 0 bit
D (1196) efuse: coding scheme 0
D (1206) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 24 bit
D (1206) efuse: coding scheme 0
D (1216) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 16 bit
D (1216) efuse: coding scheme 0
D (1226) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 8 bit
D (1226) efuse: coding scheme 0
D (1236) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 0 bit
D (1236) efuse: coding scheme 0
D (1246) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 16 bit
D (1256) nvs: nvs_open_from_partition nvs.net80211 1
D (1256) nvs: nvs_get opmode 1
D (1256) nvs: nvs_set opmode 1 2
D (1266) nvs: nvs_get_str_or_blob sta.ssid
D (1266) nvs: nvs_set_blob sta.ssid 36
D (1276) nvs: nvs_get_str_or_blob sta.mac
D (1276) nvs: nvs_set_blob sta.mac 6
D (1276) nvs: nvs_get sta.authmode 1
D (1286) nvs: nvs_set sta.authmode 1 1
D (1286) nvs: nvs_get_str_or_blob sta.pswd
D (1286) nvs: nvs_set_blob sta.pswd 65
D (1296) nvs: nvs_get_str_or_blob sta.pmk
D (1296) nvs: nvs_set_blob sta.pmk 32
D (1306) nvs: nvs_get sta.chan 1
D (1306) nvs: nvs_set sta.chan 1 0
D (1306) nvs: nvs_get auto.conn 1
D (1316) nvs: nvs_set auto.conn 1 1
D (1316) nvs: nvs_get bssid.set 1
D (1316) nvs: nvs_set bssid.set 1 0
D (1326) nvs: nvs_get_str_or_blob sta.bssid
D (1326) nvs: nvs_set_blob sta.bssid 6
D (1326) nvs: nvs_get sta.lis_intval 2
D (1336) nvs: nvs_set sta.lis_intval 2 3
D (1336) nvs: nvs_get sta.phym 1
D (1346) nvs: nvs_set sta.phym 1 3
D (1346) nvs: nvs_get sta.phybw 1
D (1346) nvs: nvs_set sta.phybw 1 2
D (1356) nvs: nvs_get_str_or_blob sta.apsw
D (1356) nvs: nvs_set_blob sta.apsw 2
D (1356) nvs: nvs_get_str_or_blob sta.apinfo
D (1366) nvs: nvs_set_blob sta.apinfo 700
D (1366) nvs: nvs_get sta.scan_method 1
D (1376) nvs: nvs_set sta.scan_method 1 0
D (1376) nvs: nvs_get sta.sort_method 1
D (1376) nvs: nvs_set sta.sort_method 1 0
D (1386) nvs: nvs_get sta.minrssi 1
D (1386) nvs: nvs_set sta.minrssi 1 -127
D (1396) nvs: nvs_get sta.minauth 1
D (1396) nvs: nvs_set sta.minauth 1 0
D (1396) nvs: nvs_get sta.pmf_e 1
D (1406) nvs: nvs_set sta.pmf_e 1 0
D (1406) nvs: nvs_get sta.pmf_r 1
D (1406) nvs: nvs_set sta.pmf_r 1 0
D (1416) nvs: nvs_get_str_or_blob ap.ssid
D (1416) nvs: nvs_set_blob ap.ssid 36
D (1426) nvs: nvs_get_str_or_blob ap.mac
D (1426) nvs: nvs_set_blob ap.mac 6
D (1426) nvs: nvs_get_str_or_blob ap.passwd
D (1436) nvs: nvs_set_blob ap.passwd 65
D (1436) nvs: nvs_get_str_or_blob ap.pmk
D (1436) nvs: nvs_set_blob ap.pmk 32
D (1446) nvs: nvs_get ap.chan 1
D (1446) nvs: nvs_set ap.chan 1 1
D (1446) nvs: nvs_get ap.authmode 1
D (1456) nvs: nvs_set ap.authmode 1 0
D (1456) nvs: nvs_get ap.hidden 1
D (1466) nvs: nvs_set ap.hidden 1 0
D (1466) nvs: nvs_get ap.max.conn 1
D (1466) nvs: nvs_set ap.max.conn 1 4
D (1476) nvs: nvs_get bcn.interval 2
D (1476) nvs: nvs_set bcn.interval 2 100
D (1476) nvs: nvs_get ap.phym 1
D (1486) nvs: nvs_set ap.phym 1 3
D (1486) nvs: nvs_get ap.phybw 1
D (1486) nvs: nvs_set ap.phybw 1 2
D (1496) nvs: nvs_get ap.sndchan 1
D (1496) nvs: nvs_set ap.sndchan 1 1
D (1496) nvs: nvs_get ap.pmf_e 1
D (1506) nvs: nvs_set ap.pmf_e 1 0
D (1506) nvs: nvs_get ap.pmf_r 1
D (1506) nvs: nvs_set ap.pmf_r 1 0
D (1516) nvs: nvs_get lorate 1
D (1516) nvs: nvs_set lorate 1 0
D (1516) nvs: nvs_get_str_or_blob country
D (1526) nvs: nvs_set_blob country 12
D (1526) nvs: nvs_set ap.sndchan 1 1
D (1536) nvs: nvs_set_blob sta.mac 6
D (1536) nvs: nvs_set_blob ap.mac 6
I (1536) wifi:wifi firmware version: 1865b55
I (1546) wifi:wifi certification version: v7.0
I (1546) wifi:config NVS flash: enabled
I (1546) wifi:config nano formating: disabled
I (1556) wifi:Init data frame dynamic rx buffer num: 32
I (1556) wifi:Init management frame dynamic rx buffer num: 32
I (1566) wifi:Init management short buffer num: 32
I (1566) wifi:Init dynamic tx buffer num: 32
I (1576) wifi:Init static rx buffer size: 1600
I (1576) wifi:Init static rx buffer num: 10
I (1586) wifi:Init dynamic rx buffer num: 32
I (1586) wifi_init: rx ba win: 6
I (1586) wifi_init: tcpip mbox: 32
I (1596) wifi_init: udp mbox: 6
I (1596) wifi_init: tcp mbox: 6
I (1606) wifi_init: tcp tx win: 5744
I (1606) wifi_init: tcp rx win: 5744
I (1606) wifi_init: tcp mss: 1440
I (1616) wifi_init: WiFi IRAM OP enabled
I (1616) wifi_init: WiFi RX IRAM OP enabled
2 66 [main] Success enable wifi, connecting wifi...
3 66 [main] [INFO ][DEMO][660] Credential OK, connecting...
D (1636) phy_init: loading PHY init data from application binary
D (1636) nvs: nvs_open_from_partition phy 0
D (1646) phy_init: esp_phy_load_cal_data_from_nvs: failed to open NVS namespace (0x1102)
W (1656) phy_init: failed to load RF calibration data (0x1102), falling back to full calibration
D (1666) efuse: coding scheme 0
D (1666) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 8 bit
D (1676) efuse: coding scheme 0
D (1676) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 0 bit
D (1686) efuse: coding scheme 0
D (1686) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 24 bit
D (1696) efuse: coding scheme 0
D (1696) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 16 bit
D (1706) efuse: coding scheme 0
D (1706) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 8 bit
D (1716) efuse: coding scheme 0
D (1716) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 0 bit
D (1726) efuse: coding scheme 0
D (1726) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 16 bit
I (1866) phy: phy_version: 4500, 0cd6843, Sep 17 2020, 15:37:07, 0, 2
D (1866) nvs: nvs_open_from_partition phy 1
D (1866) nvs: nvs_set_blob cal_data 1904
D (1876) efuse: coding scheme 0
D (1876) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 8 bit
D (1886) efuse: coding scheme 0
D (1886) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 0 bit
D (1896) efuse: coding scheme 0
D (1896) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 24 bit
D (1906) efuse: coding scheme 0
D (1906) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 16 bit
D (1916) efuse: coding scheme 0
D (1916) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 8 bit
D (1926) efuse: coding scheme 0
D (1926) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 0 bit
D (1936) efuse: coding scheme 0
D (1936) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 16 bit
D (1946) nvs: nvs_set_blob cal_mac 6
D (1946) nvs: nvs_set cal_version 4 4500
D (1956) nvs: nvs_close 5
I (1956) wifi:mode : sta (3c:61:05:3d:de:7c)
D (1956) event: running post WIFI_EVENT:2 with handler 0x400f6bcc and context 0x3ffb9510 on loop 0x3ffb8044
0x400f6bcc: wifi_default_action_sta_start at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/esp_wifi/src/wifi_default.c:74

D (1966) wifi_init_default: wifi_start esp-netif:0x3ffb92b0 event-id2
D (1976) wifi_init_default: WIFI mac address: 3c 61 5 3d de 7c
D (1976) esp_netif_handlers: esp_netif action has started with netif0x3ffb92b0 from event_id=2
D (1986) esp_netif_lwip: check: remote, if=0x3ffb92b0 fn=0x400f7eb4
0x400f7eb4: esp_netif_start_api at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:608

D (1996) esp_netif_lwip: esp_netif_start_api 0x3ffb92b0
D (2006) esp_netif_lwip: esp_netif_get_hostname esp_netif:0x3ffb92b0
D (2006) esp_netif_lwip: check: local, if=0x3ffb92b0 fn=0x400f8878
0x400f8878: esp_netif_update_default_netif_lwip at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:163

D (2016) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3ffb92b0
D (2016) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (2026) event: running post WIFI_EVENT:2 with handler 0x400d3894 and context 0x3ffb9640 on loop 0x3ffb8044
0x400d3894: event_handler at /Users/inventory-1/Project/build/../freertos/vendors/espressif/boards/ports/wifi/iot_wifi.c:126

I (2036) WIFI: SYSTEM_EVENT_STA_START
I (3126) wifi:new:<9,0>, old:<1,0>, ap:<255,255>, sta:<9,0>, prof:1
I (3666) wifi:state: init -> auth (b0)
I (3666) wifi:state: auth -> assoc (0)
I (3676) wifi:state: assoc -> run (10)
I (3696) wifi:connected with samuelbles.com, aid = 1, channel 9, BW20, bssid = 3c:84:6a:3a:9a:7a
I (3706) wifi:security: WPA2-PSK, phy: bgn, rssi: -71
I (3706) wifi:pm start, type: 1

D (3706) event: running post WIFI_EVENT:4 with handler 0x400f6bfc and context 0x3ffb9560 on loop 0x3ffb8044
0x400f6bfc: wifi_default_action_sta_connected at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/esp_wifi/src/wifi_default.c:88

D (3716) esp_netif_handlers: esp_netif action connected with netif0x3ffb92b0 from event_id=4
D (3726) esp_netif_lwip: check: remote, if=0x3ffb92b0 fn=0x400f80b8
0x400f80b8: esp_netif_up_api at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:1131

D (3736) esp_netif_lwip: esp_netif_up_api esp_netif:0x3ffb92b0
I (3736) wifi:AP's beacon interval = 102400 us, DTIM period = 1
D (3746) esp_netif_lwip: check: local, if=0x3ffb92b0 fn=0x400f8878
0x400f8878: esp_netif_update_default_netif_lwip at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:163

D (3746) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3ffb92b0
D (3756) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (3766) esp_netif_lwip: check: remote, if=0x3ffb92b0 fn=0x400f7cd4
0x400f7cd4: esp_netif_dhcpc_start_api at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:929

D (3766) esp_netif_lwip: esp_netif_dhcpc_start_api esp_netif:0x3ffb92b0
D (3776) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x3ffb92b0
D (3786) esp_netif_lwip: if0x3ffb92b0 start ip lost tmr: no need start because netif=0x3ffb9324 interval=120 ip=0
D (3796) esp_netif_lwip: starting dhcp client
D (3796) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (3806) event: running post WIFI_EVENT:4 with handler 0x400d3894 and context 0x3ffb9640 on loop 0x3ffb8044
0x400d3894: event_handler at /Users/inventory-1/Project/build/../freertos/vendors/espressif/boards/ports/wifi/iot_wifi.c:126

I (3816) WIFI: SYSTEM_EVENT_STA_CONNECTED
D (4486) esp_netif_lwip: esp_netif_dhcpc_cb lwip-netif:0x3ffb9324
D (4486) esp_netif_lwip: if0x3ffb92b0 ip changed=1
D (4486) event: running post IP_EVENT:0 with handler 0x400f6a28 and context 0x3ffb9614 on loop 0x3ffb8044
0x400f6a28: wifi_default_action_sta_got_ip at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/esp_wifi/src/wifi_default.c:128

D (4496) wifi_init_default: Got IP wifi default handler entered
D (4496) esp_netif_handlers: esp_netif action got_ip with netif0x3ffb92b0 from event_id=0
I (4506) esp_netif_handlers: sta ip: 192.168.0.200, mask: 255.255.255.0, gw: 192.168.0.1
D (4516) event: running post IP_EVENT:0 with handler 0x400d3894 and context 0x3ffb9658 on loop 0x3ffb8044
0x400d3894: event_handler at /Users/inventory-1/Project/build/../freertos/vendors/espressif/boards/ports/wifi/iot_wifi.c:126

I (4526) WIFI: SYSTEM_EVENT_STA_GOT_IP
4 356 [sys_evt] [INFO ][DEMO][3560] _wifiEventHandler called!
5 356 [sys_evt] [INFO ][DEMO][3560] Connected to WiFi access point, ip address: 255.255.255.0.
6 358 [main] Wifi connected, start MQTT
D (5056) PKCS11: Reading file P11_Key
D (5056) nvs: nvs_open_from_partition creds 0
D (5056) nvs: nvs_get_str_or_blob P11_Key
D (5056) nvs: nvs_get_str_or_blob P11_Key
D (5056) nvs: nvs_close 6
D (5056) PKCS11: Reading file P11_Key
D (5066) nvs: nvs_open_from_partition creds 0
D (5066) nvs: nvs_get_str_or_blob P11_Key
D (5076) nvs: nvs_get_str_or_blob P11_Key
D (5076) nvs: nvs_close 7
D (5076) PKCS11: Reading file P11_Cert
D (5086) nvs: nvs_open_from_partition creds 0
D (5086) nvs: nvs_get_str_or_blob P11_Cert
D (5096) nvs: nvs_get_str_or_blob P11_Cert
D (5096) nvs: nvs_close 8
D (5096) PKCS11: Reading file P11_Cert
D (5106) nvs: nvs_open_from_partition creds 0
D (5106) nvs: nvs_get_str_or_blob P11_Cert
D (5116) nvs: nvs_get_str_or_blob P11_Cert
D (5116) nvs: nvs_close 9
D (5116) PKCS11: Reading file P11_Cert
D (5126) nvs: nvs_open_from_partition creds 0
D (5126) nvs: nvs_get_str_or_blob P11_Cert
D (5126) nvs: nvs_get_str_or_blob P11_Cert
D (5136) nvs: nvs_close 10
D (5136) PKCS11: Finding file P11_JITP
D (5146) nvs: nvs_open_from_partition creds 0
D (5146) nvs: nvs_get_str_or_blob P11_JITP
E (5146) PKCS11: failed nvs get file size 4354 0
D (5156) nvs: nvs_close 11
CORRUPT HEAP: multi_heap.c:438 detected at 0x3ffb6544

abort() was called at PC 0x4008b019 on core 0
0x4008b019: multi_heap_assert at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/heap/multi_heap_platform.h:67
 (inlined by) multi_heap_malloc_impl at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/heap/multi_heap.c:438

Backtrace:0x400877b3:0x3ffb6370 0x40087dc5:0x3ffb6390 0x4008e4fa:0x3ffb63b0 0x4008b019:0x3ffb6420 0x4008171d:0x3ffb6440 0x40081963:0x3ffb6460 0x40080efc:0x3ffb6480 0x4013ece9:0x3ffb64a0 0x401353e6:0x3ffb64c0 0x401354d3:0x3ffb64e0 0x40135d72:0x3ffb6500 0x40135e2d:0x3ffb6540 0x40136164:0x3ffb6570 0x4013632f:0x3ffb65f0 0x40136573:0x3ffb6610 0x4013f78c:0x3ffb6c80 0x401406b1:0x3ffb6cb0 0x40140741:0x3ffb6ce0 0x4013d3c9:0x3ffb6d10 0x4013d0b7:0x3ffb6d50 0x4013d0de:0x3ffb6d90 0x4013d26b:0x3ffb6dc0 0x4014612b:0x3ffb6e00 0x40146211:0x3ffb6e50 0x401462eb:0x3ffb6e80 0x401465b5:0x3ffb6ec0 0x40146c76:0x3ffb6f10 0x4014538a:0x3ffb6f90 0x4014c25c:0x3ffb6fd0 0x40143c19:0x3ffb6ff0 0x40143c49:0x3ffb7010 0x400dc666:0x3ffb7030 0x400d8201:0x3ffb7050 0x400d8912:0x3ffb70b0 0x400d7998:0x3ffb70d0 0x400d7abf:0x3ffb7100 0x400d7d4d:0x3ffb7120 0x400d2d01:0x3ffb7140 0x400d2fbd:0x3ffb71a0 0x400f3b93:0x3ffb72f0 0x40087df9:0x3ffb7320
0x400877b3: panic_abort at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/esp_system/panic.c:330

0x40087dc5: esp_system_abort at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/esp_system/system_api.c:106

0x4008e4fa: abort at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/newlib/abort.c:46

0x4008b019: multi_heap_assert at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/heap/multi_heap_platform.h:67
 (inlined by) multi_heap_malloc_impl at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/heap/multi_heap.c:438

0x4008171d: heap_caps_malloc at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/heap/heap_caps.c:145

0x40081963: heap_caps_calloc at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/heap/heap_caps.c:395

0x40080efc: esp_mbedtls_mem_calloc at /Users/inventory-1/Project/build/../freertos/vendors/espressif/esp-idf/components/mbedtls/port/esp_mem.c:25

0x4013ece9: mbedtls_calloc at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/platform.c:91

0x401353e6: mbedtls_mpi_grow at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/bignum.c:155

0x401354d3: mbedtls_mpi_copy at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/bignum.c:242

0x40135d72: mbedtls_mpi_mul_mpi at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/bignum.c:1570 (discriminator 1)

0x40135e2d: mbedtls_mpi_mul_int at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/bignum.c:1611

0x40136164: mbedtls_mpi_div_mpi at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/bignum.c:1782 (discriminator 4)

0x4013632f: mbedtls_mpi_mod_mpi at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/bignum.c:1860

0x40136573: mbedtls_mpi_exp_mod at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/bignum.c:2102 (discriminator 2)

0x4013f78c: mbedtls_rsa_public at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/rsa.c:782

0x401406b1: mbedtls_rsa_rsassa_pkcs1_v15_verify at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/rsa.c:2424

0x40140741: mbedtls_rsa_pkcs1_verify at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/rsa.c:2482

0x4013d3c9: rsa_verify_wrap at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/pk_wrap.c:113

0x4013d0b7: mbedtls_pk_verify_restartable at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/pk.c:306

0x4013d0de: mbedtls_pk_verify at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/pk.c:317

0x4013d26b: mbedtls_pk_verify_ext at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/pk.c:381

0x4014612b: x509_crt_check_signature at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/x509_crt.c:1949

0x40146211: x509_crt_find_parent_in at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/x509_crt.c:2087

0x401462eb: x509_crt_find_parent at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/x509_crt.c:2184 (discriminator 4)

0x401465b5: x509_crt_verify_chain at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/x509_crt.c:2367

0x40146c76: mbedtls_x509_crt_verify_restartable at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/x509_crt.c:2600

0x4014538a: mbedtls_ssl_parse_certificate at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/ssl_tls.c:5855

0x4014c25c: mbedtls_ssl_handshake_client_step at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/ssl_cli.c:3834

0x40143c19: mbedtls_ssl_handshake_step at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/ssl_tls.c:8174

0x40143c49: mbedtls_ssl_handshake at /Users/inventory-1/Project/build/../freertos/libraries/3rdparty/mbedtls/library/ssl_tls.c:8198

0x400dc666: TLS_Connect at /Users/inventory-1/Project/build/../freertos/libraries/freertos_plus/standard/tls/src/iot_tls.c:937

0x400d8201: SOCKETS_Connect at /Users/inventory-1/Project/build/../freertos/libraries/abstractions/secure_sockets/lwip/iot_secure_sockets.c:526

0x400d8912: Sockets_MetricsConnect at /Users/inventory-1/Project/build/../freertos/libraries/abstractions/platform/freertos/iot_metrics.c:205

0x400d7998: connectToServer at /Users/inventory-1/Project/build/../freertos/libraries/abstractions/transport/secure_sockets/transport_secure_sockets.c:336

0x400d7abf: establishConnect at /Users/inventory-1/Project/build/../freertos/libraries/abstractions/transport/secure_sockets/transport_secure_sockets.c:465

0x400d7d4d: SecureSocketsTransport_Connect at /Users/inventory-1/Project/build/../freertos/libraries/abstractions/transport/secure_sockets/transport_secure_sockets.c:540

0x400d2d01: prvConnectToServerWithBackoffRetries at /Users/inventory-1/Project/build/../src/main.c:386

0x400d2fbd: app_main at /Users/inventory-1/Project/build/../src/main.c:624

0x400f3b93: main_task at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/esp32/cpu_start.c:614

0x40087df9: vPortTaskWrapper at /Users/inventory-1/Project/build/../freertos/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/port.c:154

I don't know what happen, please help.

Thank you!

samuelbles07 commented 3 years ago

I check free heap size before calling SecureSocketsTransport_Connect using esp_get_free_heap_size is 239564 bytes.

And sometimes the debug showing:

Guru Meditation Error: Core  0 panic'ed (LoadStoreAlignment). Exception was unhandled.

Core  0 register dump:
PC      : 0x4008b018  PS      : 0x00060533  A0      : 0x80081710  A1      : 0x3ffb6420
0x4008b018: is_free at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/heap/multi_heap.c:138
 (inlined by) multi_heap_malloc_impl at /Users/inventory-1/tools/amazon-freertos/vendors/espressif/esp-idf/components/heap/multi_heap.c:439

I wonder if it's something?

mahavirj commented 3 years ago

@samuelbles07

Did you reconfigure stack size of main task? Default value is 3584 bytes, configured using CONFIG_ESP_MAIN_TASK_STACK_SIZE which may not be sufficient for TLS operation. I recommend increasing this to at-least 6-7KB and then fine tune it based on high water mark (usage).

samuelbles07 commented 3 years ago

Hi @mahavirj ,

No, i don't configure anything of that scope. Where do i change it, from menuconfig?

mahavirj commented 3 years ago

No, i don't configure anything of that scope. Where do i change it, from menuconfig?

idf.py menuconfig → Component config → Common ESP-related → Main task stack size

Alternatively, you may create new task to start your demo application code.

samuelbles07 commented 3 years ago

Yes that is the problem, thank you!