How to fix a CORRUPT HEAP (IDFGH-9353)

f-hoepfinger-hr-agrartechnik commented 1 year ago

Answers checklist.

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

IDF version.

https://github.com/hr-agrartechnik/esp-idf/tree/HR_5.0_ram

Operating System used.

Windows

How did you build your project?

Eclipse IDE

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

PowerShell

Development Kit.

Custom Board

Power Supply used.

USB

What is the expected behavior?

we have 1 place where in 10/10 cases a crash happens. it happens always on the same place.

how to dig deeper in such a Problem?

What is the actual behavior?

see log:

CORRUPT HEAP: Bad head at 0x3ffdfeec. Expected 0xabba1234 got 0x3ffc5804

assert failed: multi_heap_free multi_heap_poisoning.c:272 (head != NULL)

Steps to reproduce.

Difficult to explain here. we must go to "Anhänger" and then switch from "analog sensor" to "BLE Sensor". and there it crash. always.

Debug Logs.

D (55589) [TiCoCi] TRAILER => insertPressure: pressures:
D (55590) [TiCoCi] TRAILER => insertPressure: actualMinPressure: 0
D (55590) [TiCoCi] TRAILER => insertPressure: actualMaxPressure: 0
D (55595) [TiCoCi] TRAILER => insertPressure: actualPressure: 65535
D (56102) [TiCoCi] TRAILER => insertPressure: pressures:
D (56103) [TiCoCi] TRAILER => insertPressure: actualMinPressure: 0
D (56103) [TiCoCi] TRAILER => insertPressure: actualMaxPressure: 0
D (56108) [TiCoCi] TRAILER => insertPressure: actualPressure: 65535
D (56615) [TiCoCi] TRAILER => insertPressure: pressures:
D (56615) [TiCoCi] TRAILER => insertPressure: actualMinPressure: 0
D (56616) [TiCoCi] TRAILER => insertPressure: actualMaxPressure: 0
D (56621) [TiCoCi] TRAILER => insertPressure: actualPressure: 65535

stopWork TRAILER
I (00:00:55.733) TPMS: SCANNED_ID: '4218D6'
I (00:00:55.734) TPMS -> FL_TR: PRESET_ID: '124944', SCANNED_ID: '4218D6'
I (00:00:55.735) TPMS -> FR_TR: PRESET_ID: '224C27', SCANNED_ID: '4218D6'
I (00:00:55.742) TPMS -> RL_TR: PRESET_ID: '321D46', SCANNED_ID: '4218D6'
I (00:00:55.750) TPMS -> RR_TR: PRESET_ID: '4218D6', SCANNED_ID: '4218D6'
I (00:00:55.757) TPMS: Matched with packet of '4218D6'!
D (56839) [TiCoCi] TRAC_R => insertPressure: pressures: 489, 446,
D (56844) [TiCoCi] TRAC_R => insertPressure: actualMinPressure: 446
D (56850) [TiCoCi] TRAC_R => insertPressure: actualMaxPressure: 489
D (56856) [TiCoCi] TRAC_R => insertPressure: actualPressure: 467
D (56862) [TiCoCi] TRAC_R => receiveBtTpmsPacketCb: insertPressure, checkPressure -> received BT packet
I (00:00:55.796) TPMS: Received packet of '4218D6'!
I (00:00:56.052) AN_TL:  **** any cleanup before terminating File: ./components/AppTask/src/AbstractTask.cpp Line: 116 Function: run Type: TireAnalogADC1
CORRUPT HEAP: Bad head at 0x3ffdfeec. Expected 0xabba1234 got 0x3ffc5804

assert failed: multi_heap_free multi_heap_poisoning.c:272 (head != NULL)

Backtrace: 0x400822f6:0x3f84f0d0 0x400920d9:0x3f84f0f0 0x40097cc1:0x3f84f110 0x40096f47:0x3f84f230 0x4008261e:0x3f84f250 0x40097cf1:0x3f84f270 0x400d2d92:0x3f84f290 0x400d312c:0x3f84f2b0 0x4016c5d1:0x3f84f2d0 0x400fac28:0x3f84f2f0 0x400f2e3e:0x3f84f310 0x400e80bd:0x3f84f340 0x400e5551:Backtrace: 0x400822f6:0x3f84f0d0 0x400920d9:0x3f84f0f0 0x40097cc1:0x3f84f110 0x40096f47:0x3f84f230 0x4008261e:0x3f84f250 0x40097cf1:0x3f84f270 0x400d2d92:0x3f84f290 0x400d312c:0x3f84f2b0 0x4016c5d1:0x3f84f2d0 0x400fac28:0x3f84f2f0 0x400f2e3e:0x3f84f310 0x400e80bd:0x3f84f340 0x400e5551:0x3f84f370 0x400e1d79:0x3f84f390 0x40197db9:0x3f84f3b0 0x4012a1ef:0x3f84f3e0 0x400db0ca:0x3f84f420 0x4019a53f:0x3f84f4a0 0x40136a72:0x3f84f4c0 0x40136c81:0x3f84f4e0 0x4013977d:0x3f84f610 0x401399f6:0x3f84f640 0x401
34fa1:0x3f84f660 0x4012d612:0x3f84f6b0 0x400da882:0x3f84f6f0 0x400da89b:0x3f84f710 0x40129356:0x3f84f730 0x400da32d:0x3f84f830 0x401979b7:0x3f84f850 0x4016c725:0x3f84f870 0x400d3280:0x3f84f8a0 0x400957e2:0x3f84f8c0
0x400822f6: panic_abort at C:/git/esp-idf/components/esp_system/panic.c:412

0x400920d9: esp_system_abort at C:/git/esp-idf/components/esp_system/esp_system.c:135

0x40097cc1: __assert_func at C:/git/esp-idf/components/newlib/assert.c:78

0x40096f47: multi_heap_free at C:/git/esp-idf/components/heap/multi_heap_poisoning.c:272 (discriminator 1)

0x4008261e: heap_caps_free at C:/git/esp-idf/components/heap/heap_caps.c:353

0x40097cf1: free at C:/git/esp-idf/components/newlib/heap.c:39

0x400d2d92: pthread_delete at C:/git/esp-idf/components/pthread/pthread.c:126 (discriminator 8)

0x400d312c: pthread_join at C:/git/esp-idf/components/pthread/pthread.c:392

0x4016c5d1: std::thread::join() at ??:?

0x400fac28: AppTask::AbstractTask::join() at C:/git/CTIS2/HR-Agrar-ISO-OS/components/AppTask/include/AbstractTask.h:46
 (inlined by) TireAnalog::stopWork() at C:/git/CTIS2/HR-Agrar-ISO-OS/components/TPMS/src/TPMS.cpp:643

0x400f2e3e: TireControlCircuit::stopWork() at C:/git/CTIS2/HR-Agrar-ISO-OS/components/CTIS/src/TireControlCircuit.cpp:1685

0x400e80bd: CTIS::setProfileTireMode(CTIS_Tire_Mode) at C:/git/CTIS2/HR-Agrar-ISO-OS/components/CTIS/src/CTIS.cpp:1163

0x400e5551: iCTIS::setProfileTireMode(CTIS_Tire_Mode) at C:/git/CTIS2/HR-Agrar-ISO-OS/components/CTIS/src/CTISi.cpp:141

0x400e1d79: Iso_CTIS::inputNumberCb(InputNumber_S const*) at C:/git/CTIS2/HR-Agrar-ISO-OS/components/VT-CTIS/src/Iso_CTIS.cpp:267

0x40197db9: void std::__invoke_impl<void, void (Iso_CTIS::*&)(InputNumber_S const*), Iso_CTIS*&, InputNumber_S const*>(std::__invoke_memfun_deref, void (Iso_CTIS::*&)(InputNumber_S const*), Iso_CTIS*&, InputNumber_S const*&&) at c:\espressif\tools\xtensa-esp32-elf\esp-2022r1-11.2.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\11.2.0\bits/invoke.h:74
 (inlined by) std::__invoke_result<void (Iso_CTIS::*&)(InputNumber_S const*), Iso_CTIS*&, InputNumber_S const*>::type std::__invoke<void (Iso_C (inlined by) std::__invoke_result<void (Iso_CTIS::*&)(InputNumber_S const*), Iso_CTIS*&, InputNumber_S const*>::type std::__invoke<void (Iso_CTIS::*&)(InputNumber_S const*), Iso_CTIS*&, InputNumber_S const*>(void (Iso_CTIS::*&)(InputNumber_S const*), Iso_CTIS*&, InputNumber_S const*&&) at c:\espressif\tools\xtensa-esp32-elf\esp-2022r1-11.2.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\11.2.0\bits/invoke.h:96
 (inlined by) void std::_Bind<void (Iso_CTIS::*(Iso_CTIS*, std::_Placeholder<1>))(InputNumber_S const*)>::__call<void, InputNumber_S const*&&,  (inlined by) void std::_Bind<void (Iso_CTIS::*(Iso_CTIS*, std::_Placeholder<1>))(InputNumber_S const*)>::__call<void, InputNumber_S const*&&, 0u, 1u>(std::tuple<InputNumber_S const*&&>&&, std::_Index_tuple<0u, 1u>) at c:\espressif\tools\xtensa-esp32-elf\esp-2022r1-11.2.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\11.2.0/functional:420
 (inlined by) void std::_Bind<void (Iso_CTIS::*(Iso_CTIS*, std::_Placeholder<1>))(InputNumber_S const*)>::operator()<InputNumber_S const*, void (inlined by) void std::_Bind<void (Iso_CTIS::*(Iso_CTIS*, std::_Placeholder<1>))(InputNumber_S const*)>::operator()<InputNumber_S const*, void>(InputNumber_S const*&&) at c:\espressif\tools\xtensa-esp32-elf\esp-2022r1-11.2.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\11.2.0/functional:503
 (inlined by) void std::__invoke_impl<void, std::_Bind<void (Iso_CTIS::*(Iso_CTIS*, std::_Placeholder<1>))(InputNumber_S const*)>&, InputNumber (inlined by) void std::__invoke_impl<void, std::_Bind<void (Iso_CTIS::*(Iso_CTIS*, std::_Placeholder<1>))(InputNumber_S const*)>&, InputNumber_S const*>(std::__invoke_other, std::_Bind<void (Iso_CTIS::*(Iso_CTIS*, std::_Placeholder<1>))(InputNumber_S const*)>&, InputNumber_S const*&&) at c:\espressif\tools\xtensa-esp32-elf\esp-2022r1-11.2.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\11.2.0\bits/invoke.h:61
 (inlined by) std::enable_if<is_invocable_r_v<void, std::_Bind<void (Iso_CTIS::*(Iso_CTIS*, std::_Placeholder<1>))(InputNumber_S const*)>&, InputNumber_S const*>, void>::type std::__invoke_r<void, std::_Bind<void (Iso_CTIS::*(Iso_CTIS*, std::_Placeholder<1>))(InputNumber_S const*)>&, InputNumber_S const*>(std::_Bind<void (Iso_CTIS::*(Iso_CTIS*, std::_Placeholder<1>))(InputNumber_S const*)>&, InputNumber_S const*&&) at c:\espressif\tools\xtensa-esp32-elf\esp-2022r1-11.2.0\xtensa-esp32-elf\xtensa-
esp32-elf\include\c++\11.2.0\bits/invoke.h:111
 (inlined by) std::_Function_handler<void (InputNumber_S const*), std::_Bind<void (Iso_CTIS::*(Iso_CTIS*, std::_Placeholder<1>))(InputNumber_S  (inlined by) std::_Function_handler<void (InputNumber_S const*), std::_Bind<void (Iso_CTIS::*(Iso_CTIS*, std::_Placeholder<1>))(InputNumber_S const*)> >::_M_invoke(std::_Any_data const&, InputNumber_S const*&&) at c:\espressif\tools\xtensa-esp32-elf\esp-2022r1-11.2.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\11.2.0\bits/std_function.h:291

0x4012a1ef: std::function<void (InputNumber_S const*)>::operator()(InputNumber_S const*) const at c:\espressif\tools\xtensa-esp32-elf\esp-2022r1-11.2.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\11.2.0\bits/std_function.h:560
 (inlined by) IsoVtActivationMessageHelper::InputNumberHandler::executeAll(InputNumber_S const*) at C:/git/CTIS2/HR-Agrar-ISO-OS/components/IsoVtActivationMessageHelper/src/IsoVtActivationMessageHelper.cpp:90

0x400db0ca: CbVtMessages(ISOVT_MSG_STA_T const*) at C:/git/CTIS2/HR-Agrar-ISO-OS/components/AppIsoVT/src/App_VTClient.cpp:909

0x4019a53f: IsoVtCallMsgRecCb at C:/git/CTIS2/HR-Agrar-ISO-OS/components/hr_cci_ecu_driver/ecu_driver/IsoLib/VTC/IsoVt.c:2353

0x40136a72: IsoRespToAppAndCtrl at C:/git/CTIS2/HR-Agrar-ISO-OS/components/hr_cci_ecu_driver/ecu_driver/IsoLib/VTC/IsoVTCmd.c:1912

0x40136c81: iso_ActivationMsgProcess at C:/git/CTIS2/HR-Agrar-ISO-OS/components/hr_cci_ecu_driver/ecu_driver/IsoLib/VTC/IsoVTCmd.c:1383

0x4013977d: VtcDoMsgReceive at C:/git/CTIS2/HR-Agrar-ISO-OS/components/hr_cci_ecu_driver/ecu_driver/IsoLib/VTC/IsoVt.c:966

0x401399f6: IsoVtc_MsgReceive at C:/git/CTIS2/HR-Agrar-ISO-OS/components/hr_cci_ecu_driver/ecu_driver/IsoLib/VTC/IsoVt.c:818

0x40134fa1: IsoCbDataOfBasicDistributor at C:/git/CTIS2/HR-Agrar-ISO-OS/components/hr_cci_ecu_driver/ecu_driver/IsoLib/CShared/IsoClShCtrl.c:368

0x4012d612: IsoCbClientDistributorCyclic at C:/git/CTIS2/HR-Agrar-ISO-OS/components/cci_wrapper/src/CoreBaseFiFo/ClientBaseThreading.cpp:61 (discriminator 2)

0x400da882: ECU_DRIVER::ClientTask::runCyclic() at C:/git/CTIS2/HR-Agrar-ISO-OS/components/AppThreading/src/ClientTask.cpp:54

0x400da89b: virtual thunk to ECU_DRIVER::ClientTask::runCyclic() at C:/git/CTIS2/HR-Agrar-ISO-OS/components/AppThreading/priv_include/ClientTask.h:19

0x40129356: AppTask::AbstractTask::run() at C:/git/CTIS2/HR-Agrar-ISO-OS/components/AppTask/src/AbstractTask.cpp:111

0x400da32d: AppTask::AbstractTask::exec(AppTask::AbstractTask*) at C:/git/CTIS2/HR-Agrar-ISO-OS/components/AppTask/include/AbstractTask.h:190

0x401979b7: void std::__invoke_impl<void, void (*)(AppTask::AbstractTask*), AppTask::AbstractTask*>(std::__invoke_other, void (*&&)(AppTask::Ab0x401979b7: void std::__invoke_impl<void, void (*)(AppTask::AbstractTask*), AppTask::AbstractTask*>(std::__invoke_other, void (*&&)(AppTask::AbstractTask*), AppTask::AbstractTask*&&) at c:\espressif\tools\xtensa-esp32-elf\esp-2022r1-11.2.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\11.2.0\bits/invoke.h:61
 (inlined by) std::__invoke_result<void (*)(AppTask::AbstractTask*), AppTask::AbstractTask*>::type std::__invoke<void (*)(AppTask::AbstractTask*), AppTask::AbstractTask*>(void (*&&)(AppTask::AbstractTask*), AppTask::AbstractTask*&&) at c:\espressif\tools\xtensa-esp32-elf\esp-2022r1-11.2.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\11.2.0\bits/invoke.h:96
 (inlined by) void std::thread::_Invoker<std::tuple<void (*)(AppTask::AbstractTask*), AppTask::AbstractTask*> >::_M_invoke<0u, 1u>(std::_Index_ (inlined by) void std::thread::_Invoker<std::tuple<void (*)(AppTask::AbstractTask*), AppTask::AbstractTask*> >::_M_invoke<0u, 1u>(std::_Index_tuple<0u, 1u>) at c:\espressif\tools\xtensa-esp32-elf\esp-2022r1-11.2.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\11.2.0\bits/std_thread.h:253
 (inlined by) std::thread::_Invoker<std::tuple<void (*)(AppTask::AbstractTask*), AppTask::AbstractTask*> >::operator()() at c:\espressif\tools\ (inlined by) std::thread::_Invoker<std::tuple<void (*)(AppTask::AbstractTask*), AppTask::AbstractTask*> >::operator()() at c:\espressif\tools\xtensa-esp32-elf\esp-2022r1-11.2.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\11.2.0\bits/std_thread.h:260
 (inlined by) std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (*)(AppTask::AbstractTask*), AppTask::AbstractTask*> > >::_M_run() at c:\espressif\tools\xtensa-esp32-elf\esp-2022r1-11.2.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\11.2.0\bits/std_thread.h:211

0x4016c725: execute_native_thread_routine at thread.cc:?

0x400d3280: pthread_task_func at C:/git/esp-idf/components/pthread/pthread.c:201 (discriminator 15)

0x400957e2: vPortTaskWrapper at C:/git/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:151

More Information.

No response

f-hoepfinger-hr-agrartechnik commented 1 year ago

https://github.com/hr-agrartechnik/esp-idf-examples-cxx-pthread

Crash on join()

It is reproducible. So need to debug on this minimal example.

0xjakob commented 1 year ago

@f-hoepfinger-hr-agrartechnik Have you checked the Heap Memory Debugging section in our documentation already?

What do you mean by "It is reproducible"? I tried the example (https://github.com/hr-agrartechnik/esp-idf-examples-cxx-pthread/tree/main/pthread) on IDF commit 7f5ecbe533b2666df6b10658a023b5f637320696 but there was no error. I enabled comprehensive heap poisoning.

Would you mind sending us your sdkconfig file? Sometimes there are some other configurations that we usually don't try and that contribute to the error.

f-hoepfinger-hr-agrartechnik commented 1 year ago

Hi,

the Error happens with this IDF:

https://github.com/hr-agrartechnik/esp-idf/tree/HR_5.0_ram

it is about using PSRAM as Stack on Pthread.

SoucheSouche commented 1 year ago

@f-hoepfinger-hr-agrartechnik, from your description (CORRUPT HEAP: Bad head at 0x3ffdfeec. Expected 0xabba1234 got 0x3ffc5804) you have light poisoning active (0xabba1234 is the head or tail canary), meaning that your application most likely writes over those bytes.

In esp_heap_caps.h the function heap_caps_get_allocated_size() returns the allocated size of a block, but in case of light / comprehensive poisoning, the size also include the canary bytes, so if your application uses this function to manipulate the allocated memory, it can easily lead to this behavior. This issue is in the process of being fixed.

Just to be sure that it is the issue, could you please try to run your application with poisoning disabled and report back to whether the problem persists or not ?

SoucheSouche commented 1 year ago

I will close this issue since the bug with heap_caps_get_allocated_size() when poisoning is enabled was fixed. If your problem still persist even with poisoning disabled, feel free to reopen the issue.

espressif / esp-idf