Page 1 of 1

Native C: ESP32 core panic with µPython callback in task

Posted: Wed Jun 30, 2021 9:15 am
by johannes.rost
Dear community,

I have an issue that might also be related to ESP32 specific memory handling, but maybe also the way Python functions are handled within C-context.

Used hardware: WiPy v3.0 (containing an ESP32D0WDQ6 (revision 1))
Used framework: Pycom MicroPython 1.20.2.r4 [v1.20.1.r2-363-ga37510c0-dirty] on 2021-06-30;
Used ESP-IDF: v3.3.x

What I want to do: the firmware is currently running in µPython. For performance reasons, I want to subsequently convert parts of Python code into C. Current part ist the webserver. The webserver shall send the content of a rather large Python dictionary in JSON format on request. Because the dictionary is used in a lot of places, my idea was to have a callback that returns the JSON from the dict as a string, and not have the dict converted to a JSON string within C. And to be able to trigger an update of the dict within Python, if the webserver gets POSTed a new version of it. To test the implementation of callbacks, I went with some really simple callback functions that should not consume a lot of memory, see code snippets below.

When I call the callback the following way, it works: register the callback as a mp_obj_t in C. Then execute a function from the µPython REPL, that calls an underlying C-function, which executes the callback with mp_call_function_n_kw().
When I call the callback from the webserver task (ESP IDF server, running on core 0) or from a simple task (running on core 1, the same on which µPython runs), I get core panics (LoadProhibied) on the core that was executing the callback.

So to me it seems, that when executing a Python function from outside the Python context, there is something going wrong. Do I need to synchronize the µPython execution loop/task with my execution of a Python function? Or is this maybe just a memory related issue, because the task that executes µPython code needs a substantially larger amount of stack? Is it even possible to independently call µPython code from outside the µPython context and asynchronously in a C-task?

Tanks in advance for every help and suggestion!

C part:

Code: Select all

static mp_obj_t TestCallback;

typedef struct C_CallBackExecutionTaskData {
    mp_obj_t* callBackFunction;
    mp_obj_t* fctArgs;
    size_t nArgs;
    mp_obj_t cbReturn;
    SemaphoreHandle_t request;
    SemaphoreHandle_t processed;
} C_CallBackExecutionTaskData;

C_CallBackExecutionTaskData callBackExecutionTaskData;

void CallBackExecutionTask(void* PvParameters)
{
    C_CallBackExecutionTaskData* data = (C_CallBackExecutionTaskData*) PvParameters;

    // init semaphores
    printf("CallBackExecutionTask: creating semaphores\n");
    data->processed = xSemaphoreCreateBinary(); //semphore is locked in initial state
    data->request = xSemaphoreCreateBinary();   //semphore is locked in initial state

    printf("CallBackExecutionTask: starting loop\n");
    while (true)
    {
        // 1. Wait for new processing request (semaphore released)
        printf("CallBackExecutionTask: waiting for work\n");
        xSemaphoreTake(data->request, portMAX_DELAY);
        uint32_t coreId = xPortGetCoreID();
        printf("CallBackExecutionTask: processing callback on core %"PRIu32"\n",coreId);
        
        // 2. process callback and store return
        data->cbReturn = mp_call_function_n_kw(*data->callBackFunction, data->nArgs, 0, data->fctArgs);
        printf("CallBackExecutionTask: returning from callback, passing returned object to data struct\n");
        
        // 3. release process ready lock
        printf("CallBackExecutionTask: signalling processing finished\n");
        xSemaphoreGive(data->processed);
    }
}

void CallbackExecution(mp_obj_t Function, mp_obj_t* FunctionArgs, size_t NumberArgs)
{
    printf("CallbackExecution: preparing data\n");
    callBackExecutionTaskData.callBackFunction = &Function;
    callBackExecutionTaskData.fctArgs = FunctionArgs;
    callBackExecutionTaskData.nArgs = NumberArgs;

    // release task that processes the callback
    printf("CallbackExecution: releasing cb task\n");
    xSemaphoreGive(callBackExecutionTaskData.request);

    // wait for the process to be finished
    printf("CallbackExecution: waiting for cb task to finish\n");
    BaseType_t semRet = xSemaphoreTake(callBackExecutionTaskData.processed, 10000 / portTICK_PERIOD_MS);    //wait for the response 10s at max
    
    if (semRet == pdFALSE)
    {
        printf("CallbackExecution: cb task timed out\n");
    }
    else
    {
        printf("CallbackExecution: cb task has returned\n");
    }
}


STATIC mp_obj_t WebserverStart(void)
{
    UBaseType_t uxHighWaterMark = 0;
    uxHighWaterMark = uxTaskGetStackHighWaterMark(NULL);
    printf("Webserver: high water mark stack: %"PRIu16"\n", uxHighWaterMark);

    printf("Webserver: event loop init...\n");
    esp_event_loop_init(event_handler, &server);
    
    uxHighWaterMark = uxTaskGetStackHighWaterMark(NULL);
    printf("Webserver: high water mark stack after event loop init: %"PRIu16"\n", uxHighWaterMark);    
    
    printf("Webserver: starting webserver...\n");
    server = start_webserver();

    uxHighWaterMark = uxTaskGetStackHighWaterMark(NULL);
    printf("Webserver: high water mark stack after starting webserver loop: %"PRIu16"\n", uxHighWaterMark);

    // pin task to run on core 1, the same as µPython
    printf("Webserver: creating call back execution task\n");
    xTaskCreatePinnedToCore(CallBackExecutionTask, "CbExecTask", 1024 * 17, &callBackExecutionTaskData, tskIDLE_PRIORITY + 2, NULL, 1);

    printf("Webserver: give call back execution time to initialize\n");
    vTaskDelay(1000 / portTICK_PERIOD_MS);

    printf("Webserver: all work done\n");
    return mp_const_none;
}
STATIC MP_DEFINE_CONST_FUN_OBJ_0(WebserverStart_obj, WebserverStart);

STATIC mp_obj_t RegisterTestCallback(mp_obj_t NewTestCallbackFunction)
{
    TestCallback = NewTestCallbackFunction;
    printf("successfully registered function as callback in C\n");
    return mp_const_none;
}
STATIC MP_DEFINE_CONST_FUN_OBJ_1(RegisterTestCallback_obj, RegisterTestCallback);

STATIC mp_obj_t CallbackTest(void)
{
    printf("executing test callback\n");
    //mp_obj_t response = mp_call_function_0(TestCallback);
    mp_obj_t response = mp_call_function_n_kw(TestCallback, 0, 0, NULL);
    printf("processing return...\n");
    printf("retrieving tuple from callback (int, int, int, string)\n");
    mp_obj_t* respTuple;
    size_t tupleLen = 0;
    mp_obj_tuple_get(response, &tupleLen, &respTuple);
    printf("tuple len: %"PRIu16"\n", tupleLen);
    
    if (tupleLen >=4)
    {
        printf("int values: %d, %d, %d | string value: %s\n", mp_obj_get_int(respTuple[0]), mp_obj_get_int(respTuple[1]), mp_obj_get_int(respTuple[2]), mp_obj_str_get_str(respTuple[3]));
    }
    else
    {
        printf("return tuple of callback provided less elements than expected\n");
    }

    return mp_const_none;
}
STATIC MP_DEFINE_CONST_FUN_OBJ_0(CallbackTest_obj, CallbackTest);

STATIC mp_obj_t CallbackTestFromThread(void)
{
    printf("CallbackTestFromThread: requesting TestCallBack to be processed\n");
    CallbackExecution(TestCallback, NULL, 0);

    printf("processing return...\n");
    printf("retrieving tuple from callback (int, int, int, string)\n");
    mp_obj_t* respTuple;
    size_t tupleLen = 0;
    mp_obj_tuple_get(callBackExecutionTaskData.cbReturn, &tupleLen, &respTuple);
    printf("tuple len: %"PRIu16"\n", tupleLen);
    
    if (tupleLen >=4)
    {
        printf("int values: %d, %d, %d | string value: %s\n", mp_obj_get_int(respTuple[0]), mp_obj_get_int(respTuple[1]), mp_obj_get_int(respTuple[2]), mp_obj_str_get_str(respTuple[3]));
    }
    else
    {
        printf("return tuple of callback provided less elements than expected\n");
    }

    printf("CallbackTestFromThread: finished\n");
    return mp_const_none;
}
STATIC MP_DEFINE_CONST_FUN_OBJ_0(CallbackTestFromThread_obj, CallbackTestFromThread);

µPython part

Code: Select all

# start server in ESP IDF C webserver
websrv.WebserverStart()

print("registering test call back from uPython")
websrv.RegisterTestCallback(TestCallback)

print("performing call back test called from uPython")
websrv.CallbackTest()

print("performing call back test called from uPython, processed in thread")
websrv.CallbackTestThread()

def TestCallback():
    print("hello from within test callback")
    hallo = "hallo"
    a = 1
    b = 2
    c = a + b
    print("calculation in callback: {}  + {} = {}".format(a,b,c))
    return (a,b,c,hallo)

Re: Native C: ESP32 core panic with µPython callback in task

Posted: Tue Jul 06, 2021 7:14 am
by jimmo
johannes.rost wrote:
Wed Jun 30, 2021 9:15 am
Used hardware: WiPy v3.0 (containing an ESP32D0WDQ6 (revision 1))
Used framework: Pycom MicroPython 1.20.2.r4 [v1.20.1.r2-363-ga37510c0-dirty] on 2021-06-30;
Used ESP-IDF: v3.3.x
See my other reply... I will try and help but PyCom is a long way behind upstream MicroPython and I'm less familiar with it.
johannes.rost wrote:
Wed Jun 30, 2021 9:15 am
and not have the dict converted to a JSON string within C
dict to json should already be implemented in C -- using the `json` module.

Code: Select all

import json
x = { ... }
print(json.dumps(x))
johannes.rost wrote:
Wed Jun 30, 2021 9:15 am
When I call the callback the following way, it works: register the callback as a mp_obj_t in C. Then execute a function from the µPython REPL, that calls an underlying C-function, which executes the callback with mp_call_function_n_kw().
When I call the callback from the webserver task (ESP IDF server, running on core 0) or from a simple task (running on core 1, the same on which µPython runs), I get core panics (LoadProhibied) on the core that was executing the callback.
I'm not sure how the pycom fork handles this but in general synchronising across both cores takes a lot of work, and in general you will need to ensure that the MicroPython code entirely runs on one core (i.e. you can't execute a callback on core 0, if the VM is running on core 1).

Re: Native C: ESP32 core panic with µPython callback in task

Posted: Tue Jul 06, 2021 11:42 am
by johannes.rost
Hi jimmo,

thank you very much for your reply!

Yes, MicroPython is the one from the PyCom fork. I supposed that PyComs µPython version might not be very up to date...but it seemed to me that the issues I am facing rather come from a wrong approach on my side.
dict to json should already be implemented in C -- using the `json` module.
I cannot believe why I haven't already tried that...that would have been the most obvious thing to try at first. Thanks for pointing that possibility out.
I tried that immediately after reading your post, unfortunately there is also something amiss: as soon as

Code: Select all

mp_obj_print_helper(&print, obj, PRINT_JSON);
from mod_ujson_dumps is called, the core panic happens again. The line before that (vstr_init_print(&vstr, 8, &print);) returns correctly.
I'm not sure how the pycom fork handles this but in general synchronising across both cores takes a lot of work, and in general you will need to ensure that the MicroPython code entirely runs on one core (i.e. you can't execute a callback on core 0, if the VM is running on core 1).
Yeah I thought this might be an issue too. That's why I tested executing a callback on both cores (core 0 is supposed to be the "protocol core", core 1 is supposed to be the "app core". All PyCom and the MicroPython tasks are pinned to core 1). In both cases executing the callback doesn't work, as soon as I try to call it from a freeRTOS task, and not from within the MicroPython VM.
There is also a possible memory bug present on ESP32 Dual Core MCUs in hardware revision 1 (which is used on current PyCom modules), that can lead to device freezes and errors when both cores try to access the external RAM. There is a compiler workaround, but some users still report problems. But that shouldn't happen when I execute everything on the same core.