heap_caps_get_largest_free_block or heap_caps_check_integrity_all cause panic (LoadProhibited) (IDFGH-7044)

moefear85 commented 2 years ago

Environment

Development Kit: AiThinker ESP-CAM
Module or chip used: ESP32-WROVER
IDF version : v4.4
Build System: idf.py
Operating System: Linux
Using an IDE?: VSCode with ESP-IDF Extension
Power Supply: external 3.3V

Problem Description

I'm trying to capture frames on an esp32-cam module. Everytime I call

heap_caps_check_integrity_all(true) or heap_caps_get_largest_free_block(MALLOC_CAP_8BIT) or heap_caps_get_largest_free_block(MALLOC_CAP_DEFAULT)

it causes a panic.

Expected Behavior

I expect the functions to succeed, just like the other heap functions do. I can call these successfully:

xPortGetFreeHeapSize() xPortGetMinimumEverFreeHeapSize()

Actual Behavior

once I uncomment the top mentioned functions, they fail, even if I use critical senctions or suspend everything else.

Code to reproduce this issue

// the code should be wrapped in the ```cpp tag so that it will be displayed better.
#include "esp_log.h"

void app_main()
{
    esp_event_loop_create_default();

    setup_fixed_paths();
    //esp_log_level_set("*",ESP_LOG_WARN);
    esp_log_level_set("BFS",ESP_LOG_ERROR);
    esp_log_level_set(TAG_CAM,ESP_LOG_DEBUG);
    esp_log_level_set(TAG_CB_HN,ESP_LOG_DEBUG);
    //esp_log_level_set(TAG_CB,ESP_LOG_INFO);
    //esp_log_level_set(tag_reset,ESP_LOG_VERBOSE);
    //esp_log_level_set(ack_in,ESP_LOG_VERBOSE);
    //esp_log_level_set(data_out,ESP_LOG_VERBOSE);

    wifi_setup();
    camera_setup();
}

void camera_setup()
{
    camera_config_t camera_config =
    {
        .pin_pwdn  = PWDN_GPIO_NUM,
        .pin_reset = RESET_GPIO_NUM,
        .pin_xclk = XCLK_GPIO_NUM,
        .pin_sscb_sda = SIOD_GPIO_NUM,
        .pin_sscb_scl = SIOC_GPIO_NUM,

        .pin_d7 = Y9_GPIO_NUM,
        .pin_d6 = Y8_GPIO_NUM,
        .pin_d5 = Y7_GPIO_NUM,
        .pin_d4 = Y6_GPIO_NUM,
        .pin_d3 = Y5_GPIO_NUM,
        .pin_d2 = Y4_GPIO_NUM,
        .pin_d1 = Y3_GPIO_NUM,
        .pin_d0 = Y2_GPIO_NUM,
        .pin_vsync = VSYNC_GPIO_NUM,
        .pin_href = HREF_GPIO_NUM,
        .pin_pclk = PCLK_GPIO_NUM,

        .xclk_freq_hz = 10000000,//EXPERIMENTAL: Set to 16MHz on ESP32-S2 or ESP32-S3 to enable EDMA mode
        .ledc_timer = LEDC_TIMER_0,
        .ledc_channel = LEDC_CHANNEL_0,

        .pixel_format = PIXFORMAT_JPEG, //YUV422,GRAYSCALE,RGB565,JPEG
        .frame_size = FRAMESIZE_QVGA,//QQVGA-QXGA Do not use sizes above QVGA when not JPEG

        .jpeg_quality = 30, //0-63 lower number means higher quality
        .fb_count = 2, //if more than one, i2s runs in continuous mode. Use only with JPEG
        .fb_location=CAMERA_FB_IN_DRAM,
        .grab_mode = CAMERA_GRAB_LATEST,//CAMERA_GRAB_LATEST | CAMERA_GRAB_WHEN_EMPTY. Sets when buffers should be filled        
    };

    vTaskDelay(100);
    int i=0;
    while (esp_camera_init(&camera_config))
    {
        printf("Camera Init failed. Retrying in 1s...\n");
        esp_camera_deinit();
        gpio_uninstall_isr_service();
        vTaskDelay(100);
        if(i++==3) esp_restart();
    }
    frame_msg_buf=xMessageBufferCreate(MAX_FRAME_SIZE);
    xTaskCreate(capture_task,"capture_task",1024*4,NULL,tskIDLE_PRIORITY,&capture_task_handle);
    vTaskDelay(100);
    camera_timer_handle=xTimerCreate("camera",100,true,NULL,capture_timer_callback);
    xTimerStart(camera_timer_handle,0);
    capture_timer_callback(NULL);
}

void capture_timer_callback(TimerHandle_t timer)
{
    camera_fb_t * fb = esp_camera_fb_get();
    xMessageBufferSend(frame_msg_buf,fb->buf,fb->len,portMAX_DELAY);
    esp_camera_fb_return(fb);
}

void capture_task(void* arg)
{
    char* frame=new char[MAX_FRAME_SIZE];
    while (true)
    {
        if (!(capture_count%250))
        {
            //vTaskSuspendAll ();
            //taskENTER_CRITICAL (&my_mutex);
            //printf("FREE HEAP: now: %u, contiguous: %u, lowest: %u\n",xPortGetFreeHeapSize(),heap_caps_get_largest_free_block(MALLOC_CAP_DEFAULT),xPortGetMinimumEverFreeHeapSize());
            heap_caps_check_integrity_all(true);
            size_t free=xPortGetFreeHeapSize();
            size_t largest=heap_caps_get_largest_free_block(MALLOC_CAP_8BIT);
            size_t minimum=xPortGetMinimumEverFreeHeapSize();
            //xTaskResumeAll ();
            //taskEXIT_CRITICAL (&my_mutex);
            printf("FREE HEAP: now: %u, lowest: %u\n",xPortGetFreeHeapSize(),xPortGetMinimumEverFreeHeapSize());
            print_sizes();
        }
        uint16_t frame_size=xMessageBufferReceive(frame_msg_buf,frame,MAX_FRAME_SIZE,portMAX_DELAY);
        printf("%u - frame size: %u\n",capture_count++,frame_size);
        esp_err_t result=ESP_OK;
        send_stream(addr_display,frame,0,frame_size,true);
        send_stream(addr_display,(void*)magic,0,strlen(magic),true);
        if (result) ESP_LOGE(TAG_CAM," -- %s",esp_err_to_name(result));        
    }
}

Debug Logs

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

Core  0 register dump:
PC      : 0x4008f9f9  PS      : 0x00060533  A0      : 0x8008fa28  A1      : 0x3ffdf1d0  
0x4008f9f9: block_size at /home/moefear85/Source/esp-idf-v4.4/components/heap/heap_tlsf_block_functions.h:75
 (inlined by) block_is_last at /home/moefear85/Source/esp-idf-v4.4/components/heap/heap_tlsf_block_functions.h:86
 (inlined by) tlsf_walk_pool at /home/moefear85/Source/esp-idf-v4.4/components/heap/heap_tlsf.c:581

A2      : 0x889a4388  A3      : 0x4008f780  A4      : 0x3ffdf1f4  A5      : 0x3ffd40ec  
0x4008f780: integrity_walker at /home/moefear85/Source/esp-idf-v4.4/components/heap/heap_tlsf.c:499

A6      : 0x00000000  A7      : 0x3ffba7ec  A8      : 0xfffffffc  A9      : 0x3ffdf1b0  
A10     : 0x00000000  A11     : 0x489d02a0  A12     : 0x00000001  A13     : 0x3ffdf1f4  
A14     : 0x400f6920  A15     : 0x00000004  SAR     : 0x00000001  EXCCAUSE: 0x0000001c  
0x400f6920: queue_send_wrapper at /home/moefear85/Source/esp-idf-v4.4/components/esp_wifi/esp32/esp_adapter.c:347

EXCVADDR: 0x889a438c  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0xffffffff  

Backtrace:0x4008f9f6:0x3ffdf1d00x4008fa25:0x3ffdf1f0 0x40090426:0x3ffdf220 0x400d5238:0x3ffdf240 0x400d525d:0x3ffdf260 0x400e307f:0x3ffdf280 0x4008df15:0x3ffdf2a0 
0x4008f9f6: offset_to_block at /home/moefear85/Source/esp-idf-v4.4/components/heap/heap_tlsf_block_functions.h:134
 (inlined by) block_next at /home/moefear85/Source/esp-idf-v4.4/components/heap/heap_tlsf_block_functions.h:146
 (inlined by) tlsf_walk_pool at /home/moefear85/Source/esp-idf-v4.4/components/heap/heap_tlsf.c:588

0x4008fa25: tlsf_check_pool at /home/moefear85/Source/esp-idf-v4.4/components/heap/heap_tlsf.c:607

0x40090426: multi_heap_check at /home/moefear85/Source/esp-idf-v4.4/components/heap/multi_heap.c:299

0x400d5238: heap_caps_check_integrity at /home/moefear85/Source/esp-idf-v4.4/components/heap/heap_caps.c:544

0x400d525d: heap_caps_check_integrity_all at /home/moefear85/Source/esp-idf-v4.4/components/heap/heap_caps.c:553

0x400e307f: capture_task(void*) at /home/moefear85/Desktop/ESP32/Doorbell/Camera/build/../main/camera.cpp:82

0x4008df15: vPortTaskWrapper at /home/moefear85/Source/esp-idf-v4.4/components/freertos/port/xtensa/port.c:131

ELF file SHA256: ab1ba2fdcda9f6bb

CPU halted.

Other items if possible

sdkconfig.txt

Additional Info:

This seems related to 8658 as both involve the esp32s & heap issues. Btw I only see max about 90KB free memory at any moment. Is this usual/normal?

Also, could this commit be relevant?

o-marshmallow commented 2 years ago

Hi @moefear85 ,

Which IDF commit version are you using exactly? Do you have commit 09db8845c692ee5002810744fd1ce889d4d69c9d in your working tree?

moefear85 commented 2 years ago

@o-marshmallow

I THINK I'm using the march 11 commit of release/v4.4:

c29343eb94d2f2ca17b3a5b38c82452e556147f2

I can't try latest master. the version difference breaks so many things in my system so isn't working. But, I cloned using the following statement. I did it 2-3 days ago:

git clone --depth=1 --recursive --shallow-submodules -b releases/v4.4 https://github.com/espressif/esp-idf.git

If that doesn't automatically amount to the latest commit to that branch, then please inform me, as I would be using the wrong commit.

UPDATE: I just checked "git log", it clearly says I'm definately on the correct commit I thought I was.

At this point I have to ask... is there any sure way to know if any undetected heap corruption on the coder's side could still manage might systematically trigger the above exception at exactly the same function? It doesn't crash directly on the first run. Sometimes it runs on or two iterations (of being called). But I have heap corruption detection set to comprehensive, and stack smashing detection using canary bytes. I double & triple checked every malloc/new keyword to ensure it is matched with a delete statement through every possible branch of execution, and have everything structured so that it is simple to comprehend and follow. Other than that I make extensive use of nested C++ STL maps,vectors, and arrays whose top level maps are statically/globally defined. Moreover, the app runs indefinately over night and I've run it again and again over long periods of time. It doesn't crash at all. Only once I uncomment the above mentioned lines, it does, very very quickly.

moefear85 commented 2 years ago

I was writing past a heap buffer. I corrected it, now I'm not getting the error anymore. The irony though is, the whole point of calling heap_caps_check_integrity_all(true) is to catch such corruptions. I also have all memory/heap protections/debugging options set, but nothing caught it.

espressif / esp-idf