Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

xTaskCreate ignore the priority. #3093

Closed
nopnop2002 opened this issue Feb 24, 2019 · 25 comments
Closed

xTaskCreate ignore the priority. #3093

nopnop2002 opened this issue Feb 24, 2019 · 25 comments
Assignees

Comments

@nopnop2002
Copy link

I tested this code.

/* The example of esp-idf
 *
 * This sample code is in the public domain.
 */
#include <stdio.h>
#include "freertos/FreeRTOS.h"
#include "freertos/task.h"
#include "esp_log.h"

static const char *TAG = "task-test";

void ConsumptionTick(int delay) {
    TickType_t startTick;
    TickType_t endTick;
    TickType_t nowTick;
    startTick = xTaskGetTickCount();
    endTick = startTick + delay;
    //printf("startTick=%d endTick=%d\n",startTick,endTick);
    while(1) {
      nowTick = xTaskGetTickCount();
      if (nowTick > endTick) break;
    }
}

void task(void *pvParameter)
{
    char * my_name = pcTaskGetTaskName( NULL );
    int cpu_id = xPortGetCoreID();
    UBaseType_t my_prio = uxTaskPriorityGet( NULL );

    ESP_LOGI(TAG, "[%s] start CoreID=%d Priority=%d",my_name, cpu_id, my_prio);
    ConsumptionTick(200);
    ESP_LOGI(TAG, "[%s] end CoreID=%d Priority=%d",my_name, cpu_id, my_prio);
    vTaskDelete( NULL );
}

void app_main()
{
    char * my_name = pcTaskGetTaskName(NULL);
    int cpu_id = xPortGetCoreID();
    UBaseType_t my_prio = uxTaskPriorityGet( NULL );

    ESP_LOGI(TAG, "[%s] start CoreID=%d Priority=%d",my_name, cpu_id, my_prio);
    ESP_LOGI(TAG, "[%s] portTICK_PERIOD_MS=%d[ms]",my_name, portTICK_PERIOD_MS);
    ESP_LOGI(TAG, "[%s] configMAX_PRIORITIES=%d",my_name, configMAX_PRIORITIES);
    ESP_LOGI(TAG, "[%s] configMINIMAL_STACK_SIZE=%d",my_name, configMINIMAL_STACK_SIZE);

#if 1
    xTaskCreate(&task, "Task1", 2048, NULL, 1, NULL);
    xTaskCreate(&task, "Task2", 2048, NULL, 2, NULL);
#endif

#if 0
    xTaskCreatePinnedToCore(&task, "Task1", 2048, NULL, 1, NULL, 1);
    xTaskCreatePinnedToCore(&task, "Task2", 2048, NULL, 2, NULL, 1);
#endif
}

When i use xTaskCreate, It work round-robin.
The priority is ignored.

I (239) task-test: [main] start CoreID=0 Priority=1
I (239) task-test: [main] portTICK_PERIOD_MS=10[ms]
I (249) task-test: [main] configMAX_PRIORITIES=25
I (249) task-test: [main] configMINIMAL_STACK_SIZE=768
I (259) task-test: [Task1] start CoreID=1 Priority=1
I (259) task-test: [Task2] start CoreID=1 Priority=2
I (2279) task-test: [Task1] end CoreID=1 Priority=1
I (2279) task-test: [Task2] end CoreID=1 Priority=2

When i use xTaskCreatePinnedToCore, It work follow the priority.

I (240) task-test: [main] start CoreID=0 Priority=1
I (240) task-test: [main] portTICK_PERIOD_MS=10[ms]
I (250) task-test: [main] configMAX_PRIORITIES=25
I (250) task-test: [main] configMINIMAL_STACK_SIZE=768
I (260) task-test: [Task2] start CoreID=1 Priority=2
I (2270) task-test: [Task2] end CoreID=1 Priority=2
I (260) task-test: [Task1] start CoreID=1 Priority=1
I (4280) task-test: [Task1] end CoreID=1 Priority=1
@chegewara
Copy link
Contributor

I would rather say its problem with codeID identification rather than ignoring task priority. You can easy test it by increasing number of tasks:

#if 1
    xTaskCreate(&task, "Task1", 2048, NULL, 1, NULL);
    xTaskCreate(&task, "Task2", 2048, NULL, 2, NULL);
    xTaskCreate(&task, "Task3", 2048, NULL, 3, NULL);
    xTaskCreate(&task, "Task4", 2048, NULL, 4, NULL);
#endif

@negativekelvin
Copy link
Contributor

Task1 switches to core 0 but you only call xPortGetCoreID once

@nopnop2002
Copy link
Author

nopnop2002 commented Feb 24, 2019

I changed my code.

void task(void *pvParameter)
{
    int cpu_id;
    char * my_name = pcTaskGetTaskName( NULL );
    UBaseType_t my_prio = uxTaskPriorityGet( NULL );

    cpu_id = xPortGetCoreID();
    ESP_LOGI(my_name, "start CoreID=%d Priority=%d",cpu_id, my_prio);
    ConsumptionTick(200);
    cpu_id = xPortGetCoreID();
    ESP_LOGI(my_name, "end CoreID=%d Priority=%d",cpu_id, my_prio);
    vTaskDelete( NULL );
}

Task1 start with core1 and end with core1.

I (240) main: start CoreID=0 Priority=1
I (240) main: portTICK_PERIOD_MS=10[ms]
I (240) main: configMAX_PRIORITIES=25
I (250) main: configMINIMAL_STACK_SIZE=768
I (250) Task1: start CoreID=1 Priority=1
I (250) Task2: start CoreID=1 Priority=2
I (2270) Task2: end CoreID=1 Priority=2
I (2280) Task1: end CoreID=1 Priority=1

Task1 switches to core 0 ??

@nopnop2002
Copy link
Author

nopnop2002 commented Feb 24, 2019

@chegewara

What is problem with codeID identification ??

@chegewara
Copy link
Contributor

chegewara commented Feb 24, 2019

This is what i mean:

I (67) task-test: [Task2] start CoreID=0 Priority=2
I (67) task-test: [Task1] start CoreID=1 Priority=1
I (273) task-test: [Task2] end CoreID=0 Priority=2
I (279) task-test: [Task1] end CoreID=1 Priority=1

By default when you create 2 tasks with xTaskCreate then most likely both tasks will start on both cores, but your tasks are on the same core (core1). In the other hand, logs suggest that both tasks are running on different cores, because both start and end on the same time, are running simultaneously (compare with my logs).

When you have 2 tasks running on the same core, with code you provisioned in OP, and you modify code the way i asked you then you will be sure that at least 2 tasks will be running on the same core. Here are logs:

I (67) task-test: [Task2] start CoreID=0 Priority=12
I (67) task-test: [Task1] start CoreID=1 Priority=11
I (273) task-test: [Task2] end CoreID=0 Priority=12
I (273) task-test: [Task3] start CoreID=0 Priority=13
I (279) task-test: [Task1] end CoreID=1 Priority=11
I (474) task-test: [Task3] end CoreID=0 Priority=13

Those logs suggest that you are right about ignoring priority, but not exactly. The problem is specific of ConsumptionTick function. This function consumes all time on core until it exits, there is no delay or any other function that is blocking task. Here you can see test code and logs to confirm it:

void app_main()
{
    char * my_name = pcTaskGetTaskName(NULL);
    int cpu_id = xPortGetCoreID();
    UBaseType_t my_prio = uxTaskPriorityGet( NULL );

    ESP_LOGI(TAG, "[%s] start CoreID=%d Priority=%d",my_name, cpu_id, my_prio);
    ESP_LOGI(TAG, "[%s] portTICK_PERIOD_MS=%d[ms]",my_name, portTICK_PERIOD_MS);
    ESP_LOGI(TAG, "[%s] configMAX_PRIORITIES=%d",my_name, configMAX_PRIORITIES);
    ESP_LOGI(TAG, "[%s] configMINIMAL_STACK_SIZE=%d",my_name, configMINIMAL_STACK_SIZE);

#if 1
    ESP_LOGI(__func__, "before task 1 start");
    xTaskCreate(&task, "Task1", 2048, NULL, 1, NULL);
    ESP_LOGI(__func__, "before task 2 start");
    xTaskCreate(&task, "Task2", 2048, NULL, 2, NULL);
    ESP_LOGI(__func__, "before task 3 start");
    xTaskCreate(&task, "Task3", 2048, NULL, 3, NULL);
#endif

#if 0
    xTaskCreatePinnedToCore(&task, "Task1", 2048, NULL, 1, NULL, 1);
    xTaskCreatePinnedToCore(&task, "Task2", 2048, NULL, 2, NULL, 1);
#endif
}
I (46) task-test: [main] start CoreID=0 Priority=1
I (50) task-test: [main] portTICK_PERIOD_MS=1[ms]
I (56) task-test: [main] configMAX_PRIORITIES=25
I (61) task-test: [main] configMINIMAL_STACK_SIZE=768
I (67) app_main: before task 1 start
I (71) app_main: before task 2 start
I (71) task-test: [Task1] start CoreID=1 Priority=1
I (76) task-test: [Task2] start CoreID=1 Priority=2
I (282) task-test: [Task1] end CoreID=1 Priority=1
I (287) task-test: [Task2] end CoreID=1 Priority=2
I (76) app_main: before task 3 start
I (287) task-test: [Task3] start CoreID=1 Priority=3
I (493) task-test: [Task3] end CoreID=1 Priority=3

Conclusion:
when task1 is running, task2 will start on second core, no matter what priority it has and task3 will start only when any core have free time to run another task, in this case when task1 or task2 will finish.

PS as you can see all 3 tasks in my last logs also are running on CoreID = 1 which is not correct

@chegewara
Copy link
Contributor

chegewara commented Feb 25, 2019

My observations:

  1. you have set portTICK_PERIOD_MS=10, i have portTICK_PERIOD_MS=1; thats why xPortGetCoreID is working different for you and me
  2. when i add ESP_LOGI(__func__, "before task 1 start"); in app_main then in my logs xPortGetCoreID also is not working properly, but if i comment out those logs then all is back to normal
  3. the real issue is xPortGetCoreID

Compare logs:

I (67) task-test: [Task3] start CoreID=0 Priority=3
I (67) task-test: [Task2] start CoreID=1 Priority=2
I (273) task-test: [Task3] end CoreID=0 Priority=3
I (67) task-test: [Task1] start CoreID=1 Priority=1
I (279) task-test: [Task2] end CoreID=1 Priority=2
I (474) task-test: [Task1] end CoreID=1 Priority=1
I (67) app_main: before task 1 start
I (71) app_main: before task 2 start
I (71) task-test: [Task1] start CoreID=1 Priority=1
I (76) task-test: [Task2] start CoreID=1 Priority=2
I (282) task-test: [Task1] end CoreID=1 Priority=1
I (287) task-test: [Task2] end CoreID=1 Priority=2
I (76) app_main: before task 3 start
I (287) task-test: [Task3] start CoreID=1 Priority=3
I (493) task-test: [Task3] end CoreID=1 Priority=3

@negativekelvin
Copy link
Contributor

Yeah something is sketchy...

void task(void *pvParameter)
{
    char * my_name = pcTaskGetTaskName( NULL );
    int cpu_id = xPortGetCoreID();
    UBaseType_t my_prio = uxTaskPriorityGet( NULL );
    int id;
    __asm__  volatile (
        "rsr.prid %0\n"
        :"=r"(id));
    ESP_LOGI(TAG, "[%s] start CoreID=%d cpu_id=%d Priority=%d",my_name, id,cpu_id, my_prio);
    ConsumptionTick(200);
    cpu_id = xPortGetCoreID();
    __asm__ volatile (
        "rsr.prid %0\n"
        :"=r"(id));
    ESP_LOGI(TAG, "[%s] end CoreID=%d cpu_id=%d Priority=%d",my_name, id, cpu_id, my_prio);
    vTaskDelete( NULL );
}
I (626) task-test: [main] start CoreID=0 Priority=1
I (636) task-test: [main] portTICK_PERIOD_MS=10[ms]
I (636) task-test: [main] configMAX_PRIORITIES=25
I (646) task-test: [main] configMINIMAL_STACK_SIZE=768
I (646) task-test: [Task1] start CoreID=43947 cpu_id=1 Priority=1
I (646) task-test: [Task2] start CoreID=43947 cpu_id=1 Priority=2
I (2656) task-test: [Task1] end CoreID=43947 cpu_id=1 Priority=1
I (2666) task-test: [Task2] end CoreID=52685 cpu_id=1 Priority=2

@nopnop2002
Copy link
Author

nopnop2002 commented Feb 25, 2019

@chegewara

I changed my tick rate from 100Hz to 1000Hz.
But CoreID wasn't changed.

I (239) main: start CoreID=0 Priority=1
I (242) main: portTICK_PERIOD_MS=1[ms]
I (247) main: configMAX_PRIORITIES=25
I (251) main: configMINIMAL_STACK_SIZE=768
I (256) Task1: start CoreID=1 Priority=1
I (256) Task2: start CoreID=1 Priority=2
I (462) Task1: end CoreID=1 Priority=1
I (466) Task2: end CoreID=1 Priority=2

@nopnop2002
Copy link
Author

nopnop2002 commented Feb 25, 2019

@negativekelvin

I tried your code.
What is id ??
Is this value always the same value(43947 or 52685)?

I (239) main: start CoreID=0 Priority=1
I (239) main: portTICK_PERIOD_MS=10[ms]
I (239) main: configMAX_PRIORITIES=25
I (249) main: configMINIMAL_STACK_SIZE=768
I (249) Task1: start id=43947 cpu_id=1 Priority=1
I (249) Task2: start id=43947 cpu_id=1 Priority=2
I (2269) Task2: end id=52685 cpu_id=1 Priority=2
I (2279) Task1: end id=43947 cpu_id=1 Priority=1

@negativekelvin
Copy link
Contributor

43947 = core 1, 52685 = core 0

@chegewara
Copy link
Contributor

I would suggest to rename topic and ask @projectgus or @igrr for help.

@nopnop2002
Copy link
Author

@chegewara
@negativekelvin

Thank you for your help.

@nopnop2002
Copy link
Author

nopnop2002 commented Feb 25, 2019

I experienced it more strangely.

/* The example of esp-idf
 *
 * This sample code is in the public domain.
 */
#include <stdio.h>
#include "freertos/FreeRTOS.h"
#include "freertos/task.h"
#include "esp_log.h"

void ConsumptionTick(int delay) {
    TickType_t startTick;
    TickType_t endTick;
    TickType_t nowTick;
    startTick = xTaskGetTickCount();
    endTick = startTick + delay;
    //printf("startTick=%d endTick=%d\n",startTick,endTick);
    while(1) {
      nowTick = xTaskGetTickCount();
      if (nowTick > endTick) break;
    }
}

void task(void *pvParameter)
{
    int CoreId;
    int RealId;
    char * my_name = pcTaskGetTaskName( NULL );
    UBaseType_t my_prio = uxTaskPriorityGet( NULL );

    CoreId = xPortGetCoreID();
    __asm__  volatile (
        "rsr.prid %0\n"
        :"=r"(RealId));

    ESP_LOGI(my_name, "start RealId=%d CoreId=%d Priority=%d",RealId, CoreId, my_prio);
    ConsumptionTick(200);
    CoreId = xPortGetCoreID();
    __asm__  volatile (
        "rsr.prid %0\n"
        :"=r"(RealId));

    ESP_LOGI(my_name, "end RealId=%d CoreId=%d Priority=%d",RealId, CoreId, my_prio);
    vTaskDelete( NULL );
}

void app_main()
{
    char * my_name = pcTaskGetTaskName(NULL);
    int CoreId = xPortGetCoreID();
    UBaseType_t my_prio = uxTaskPriorityGet( NULL );
    int RealId;
    __asm__  volatile (
        "rsr.prid %0\n"
        :"=r"(RealId));


    ESP_LOGI(my_name, "start RealId=%d CoreId=%d Priority=%d",RealId,CoreId,my_prio);
    ESP_LOGI(my_name, "portTICK_PERIOD_MS=%d[ms]",portTICK_PERIOD_MS);
    ESP_LOGI(my_name, "configMAX_PRIORITIES=%d",configMAX_PRIORITIES);

#if 0
    xTaskCreatePinnedToCore(&task, "Task1", 2048, NULL, 1, NULL, 1);
    xTaskCreatePinnedToCore(&task, "Task2", 2048, NULL, 2, NULL, 0);
    xTaskCreatePinnedToCore(&task, "Task3", 2048, NULL, 3, NULL, 1);
#endif

#if 1
    xTaskCreatePinnedToCore(&task, "Task1", 2048, NULL, 1, NULL, 0);
    xTaskCreatePinnedToCore(&task, "Task2", 2048, NULL, 2, NULL, 1);
    xTaskCreatePinnedToCore(&task, "Task3", 2048, NULL, 3, NULL, 0);
#endif
}

Case 1
Task3(Most high priority) doesn't start first.
Task3 begins after Task2 ends.

I (239) main: start RealId=52685 CoreId=0 Priority=1
I (239) main: portTICK_PERIOD_MS=10[ms]
I (239) main: configMAX_PRIORITIES=25
I (249) Task2: start RealId=52685 CoreId=0 Priority=2
I (249) Task1: start RealId=43947 CoreId=1 Priority=1
I (2259) Task2: end RealId=52685 CoreId=0 Priority=2
I (2259) Task3: start RealId=43947 CoreId=1 Priority=3
I (4269) Task3: end RealId=43947 CoreId=1 Priority=3
I (4269) Task1: end RealId=43947 CoreId=1 Priority=1

Case 2
Task3(Most high priority) start first.

I (240) main: start RealId=52685 CoreId=0 Priority=1
I (240) main: portTICK_PERIOD_MS=10[ms]
I (240) main: configMAX_PRIORITIES=25
I (250) Task3: start RealId=52685 CoreId=0 Priority=3
I (250) Task2: start RealId=43947 CoreId=1 Priority=2
I (2260) Task3: end RealId=52685 CoreId=0 Priority=3
I (2260) Task1: start RealId=52685 CoreId=0 Priority=1
I (2270) Task2: end RealId=43947 CoreId=1 Priority=2
I (4270) Task1: end RealId=52685 CoreId=0 Priority=1

@chegewara
Copy link
Contributor

I dont know how to explain this more clearly. This code is occupying all core time and 3rd task (3rd xCreateTask) wont be called as long as it is running:

    while(1) {
      nowTick = xTaskGetTickCount();
      if (nowTick > endTick) break;
    }

If you replace it with vTaskDelay then 3rd xCreateTask will start immediately, before task1 or task2 will end.

@nopnop2002
Copy link
Author

nopnop2002 commented Feb 25, 2019

I know that If i replace it with vTaskDelay then 3rd xCreateTask will start immediately, before task1 or task2 will end.

But i can't understand why task3 that have priority 3 start after task2 that have priority 2.

At 249 Tick time, CoreID 1 is empty.

@chegewara
Copy link
Contributor

chegewara commented Feb 25, 2019

Please try this:

#if 1
    ESP_LOGI(__func__, "before task 1 start");
    xTaskCreate(&task, "Task1", 2048, NULL, 1, NULL);
    ESP_LOGI(__func__, "before task 2 start");
    xTaskCreate(&task, "Task2", 2048, NULL, 2, NULL);
    ESP_LOGI(__func__, "before task 3 start");
    xTaskCreate(&task, "Task3", 2048, NULL, 3, NULL);
#endif

At 249 Tick time, CoreID 1 is empty.

Its not true. Look at logs:

I (249) Task2: start RealId=52685 CoreId=0 Priority=2
I (249) Task1: start RealId=43947 CoreId=1 Priority=1

Task2 is running on core 0 and Task1 is running on core 1. Both cores are occupied.

@nopnop2002
Copy link
Author

nopnop2002 commented Feb 25, 2019

I understood a reason.
main task is running on CoreId=0.
Task2 begin with priority 2 using CoreID=0.
main task is deprived of execution rights by this timing.
So main task can't generate Task3.

I (239) main: start RealId=52685 CoreId=0 Priority=1
I (239) main: portTICK_PERIOD_MS=10[ms]
I (239) main: configMAX_PRIORITIES=25
I (249) Task2: start RealId=52685 CoreId=0 Priority=2
I (249) Task1: start RealId=43947 CoreId=1 Priority=1
I (2259) Task2: end RealId=52685 CoreId=0 Priority=2
I (2259) Task3: start RealId=43947 CoreId=1 Priority=3
I (4269) Task3: end RealId=43947 CoreId=1 Priority=3
I (4269) Task1: end RealId=43947 CoreId=1 Priority=1

My conclusion
xPortGetCoreID is not working properly.
xTaskCreatePinnedToCore shouldn't use it.

Thank you.

@Dazza0 Dazza0 self-assigned this Feb 25, 2019
@Dazza0
Copy link
Contributor

Dazza0 commented Feb 26, 2019

A few things to note

  • When creating a task with no affinity (i.e. calling xTaskCreate()), the preemption rules are as follows (see source):

    • If the task has higher priority than the current priority of both cores, it will preempt the core with the lower priority.
    • If the both cores have a equal current priority that is lower than the created task, the task will prefer to preempt the current core (i.e. the core that called xTaskCreate())
    • If the created task has equal priority to the current priority of one or both cores, the created task will round robin on the next tick.
  • When creating a task with affinity (i.e. calling xTaskCreatePinnedToCore()), the preemption rules are simpler (see source)

    • If the current priority of the target core is lower than that of the created task, the task will preempt the core
    • If the current priority of the target core is equal to that of the created task, the task will round robin with that core
    • If the current priority of the target core is higher than that of the created task, the task will not run preempt or round robin
  • When app_main() starts running, it is incorrect to assume that core1 is running IDLE1 at the same time. Instead, it is entirely possible that core 1 is still initializing during which multiple other tasks of higher priorities are created (e.g. ipc, dport, timer service, esp_timer etc). I suggest you add a vTaskDelay(10) at the very beginning of app_main(). This will give sufficient time for all initialization to complete, and ensure that when your own code starts running, core 0 is running app_main() and core 1 is running IDLE1.

  • xPortGetCoreID() should be working. The reason the start and end core can be different is because it is possible that an unpinned task can be preempted/round robin across the two cores cores whilst running ConsumptionTick(). Use a critical section or scheduler suspension to prevent a task from being switched out.

@chegewara
Copy link
Contributor

@Dazza0 it sounds reasonable, but what about those logs:

I (71) task-test: [Task1] start CoreID=1 Priority=1
I (76) task-test: [Task2] start CoreID=1 Priority=2
I (282) task-test: [Task1] end CoreID=1 Priority=1
I (287) task-test: [Task2] end CoreID=1 Priority=2
I (76) app_main: before task 3 start
I (287) task-test: [Task3] start CoreID=1 Priority=3
I (493) task-test: [Task3] end CoreID=1 Priority=3

As we can see Task1 and Task2 are running simultaneously on different cores but xPortGetCoreID reported core 1 for both. Can it be because of this:

  • When app_main() starts running, it is incorrect to assume that core1 is running IDLE1 at the same time. Instead, it is entirely possible that core 1 is still initializing during which multiple other tasks of higher priorities are created (e.g. ipc, dport, timer service, esp_timer etc). I suggest you add a vTaskDelay(10) at the very beginning of app_main(). This will give sufficient time for all initialization to complete, and ensure that when your own code starts running, core 0 is running app_main() and core 1 is running IDLE1

@negativekelvin
Copy link
Contributor

negativekelvin commented Feb 26, 2019

That is really weird, even with delay and increased priority both tasks switch cores exactly in between the calls to get the core id resulting in a mismatch?

I (1636) task-test: [Task1] start CoreID=43947 cpu_id=1 Priority=5
I (1636) task-test: [Task2] start CoreID=52685 cpu_id=0 Priority=6
I (3646) task-test: [Task1] end CoreID=52685 cpu_id=1 Priority=5
I (3646) task-test: [Task2] end CoreID=43947 cpu_id=0 Priority=6

Edit: even when inside a critical section they don't match.

@igrr
Copy link
Member

igrr commented Feb 26, 2019

Perhaps xPortGetCoreID doesn't have __volatile__ in its __asm__, and the 2nd call gets optimized out?

@negativekelvin can you please post the exact source you are compiling for this test?

@negativekelvin
Copy link
Contributor

negativekelvin commented Feb 26, 2019

code
/* The example of esp-idf
 *
 * This sample code is in the public domain.
 */
#include <stdio.h>
#include "freertos/FreeRTOS.h"
#include "freertos/task.h"
#include "esp_log.h"
#include "esp_system.h"
static const char *TAG = "task-test";


void ConsumptionTick(int delay) {
    TickType_t startTick;
    TickType_t endTick;
    TickType_t nowTick;
    startTick = xTaskGetTickCount();
    endTick = startTick + delay;
    //printf("startTick=%d endTick=%d\n",startTick,endTick);
    uint32_t ccount = xthal_get_ccount();
    while (xthal_get_ccount() - ccount < 2000000 * CONFIG_ESP32_DEFAULT_CPU_FREQ_MHZ) {
        ccount = ccount;
    }
}

void task1(void *pvParameter)
{
    static portMUX_TYPE task1_spinlock = portMUX_INITIALIZER_UNLOCKED;
    char * my_name = pcTaskGetTaskName( NULL );
    int cpu_id;
    UBaseType_t my_prio = uxTaskPriorityGet( NULL );
    int id;
    portENTER_CRITICAL(&task1_spinlock);
    cpu_id = xPortGetCoreID();
    __asm__  volatile (
        "rsr.prid %0\n"
        :"=r"(id));
    portEXIT_CRITICAL(&task1_spinlock);
    ESP_LOGI(TAG, "[%s] start CoreID=%d cpu_id=%d Priority=%d",my_name, id,cpu_id, my_prio);
    ConsumptionTick(200);
    portENTER_CRITICAL(&task1_spinlock);
    cpu_id = xPortGetCoreID();
    __asm__ volatile (
        "rsr.prid %0\n"
        :"=r"(id));
    portEXIT_CRITICAL(&task1_spinlock);
    ESP_LOGI(TAG, "[%s] end CoreID=%d cpu_id=%d Priority=%d",my_name, id, cpu_id, my_prio);
    vTaskDelete( NULL );
}

void task2(void *pvParameter)
{
    static portMUX_TYPE task2_spinlock = portMUX_INITIALIZER_UNLOCKED;
    char * my_name = pcTaskGetTaskName( NULL );
    int cpu_id;
    UBaseType_t my_prio = uxTaskPriorityGet( NULL );
    int id;
    portENTER_CRITICAL(&task2_spinlock);
    cpu_id = xPortGetCoreID();
    __asm__  volatile (
        "rsr.prid %0\n"
        :"=r"(id));
    portEXIT_CRITICAL(&task2_spinlock);
    ESP_LOGI(TAG, "[%s] start CoreID=%d cpu_id=%d Priority=%d",my_name, id,cpu_id, my_prio);
    ConsumptionTick(200);
    portENTER_CRITICAL(&task2_spinlock);
    cpu_id = xPortGetCoreID();
    __asm__ volatile (
        "rsr.prid %0\n"
        :"=r"(id));
    portEXIT_CRITICAL(&task2_spinlock);
    ESP_LOGI(TAG, "[%s] end CoreID=%d cpu_id=%d Priority=%d",my_name, id, cpu_id, my_prio);
    vTaskDelete( NULL );
}

void app_main()
{
    vTaskDelay(100);
    char * my_name = pcTaskGetTaskName(NULL);
    int cpu_id = xPortGetCoreID();
    UBaseType_t my_prio = uxTaskPriorityGet( NULL );
 
    ESP_LOGI(TAG, "[%s] start CoreID=%d Priority=%d",my_name, cpu_id, my_prio);
    ESP_LOGI(TAG, "[%s] portTICK_PERIOD_MS=%d[ms]",my_name, portTICK_PERIOD_MS);
    ESP_LOGI(TAG, "[%s] configMAX_PRIORITIES=%d",my_name, configMAX_PRIORITIES);
    ESP_LOGI(TAG, "[%s] configMINIMAL_STACK_SIZE=%d",my_name, configMINIMAL_STACK_SIZE);

#if 1
    xTaskCreate(&task1, "Task1", 2048, NULL, 5, NULL);
    xTaskCreate(&task2, "Task2", 2048, NULL, 6, NULL);
#endif

#if 0
    xTaskCreatePinnedToCore(&task, "Task1", 2048, NULL, 1, NULL, 1);
    xTaskCreatePinnedToCore(&task, "Task2", 2048, NULL, 2, NULL, 1);
#endif
}

@Dazza0
Copy link
Contributor

Dazza0 commented Feb 26, 2019

@negativekelvin I'm not be able recreate your issue, but looking at the assembly code of task2() , it appears that the final compiled code will only call cpu_id = xPortGetCoreID() once. I've compiled the code for task2() with xPortCoreID() as is, and with xPortCoreID() is being made volatile. Note that both compilations were at Debug (-Og) optimization level.

Assembly when xPortGetCoreID() is NOT volatile
(gdb) disassemble task2
Dump of assembler code for function task2:
   0x400d221c <+0>:     entry   a1, 48
   0x400d221f <+3>:     movi.n  a10, 0
   0x400d2221 <+5>:     call8   0x400854fc <pcTaskGetTaskName>
   0x400d2224 <+8>:     mov.n   a6, a10
   0x400d2226 <+10>:    movi.n  a10, 0
   0x400d2228 <+12>:    call8   0x40085a70 <uxTaskPriorityGet>
   0x400d222b <+15>:    mov.n   a7, a10
   0x400d222d <+17>:    l32r    a4, 0x400d0324 <_stext+780>
   0x400d2230 <+20>:    mov.n   a10, a4
   0x400d2232 <+22>:    call8   0x40085588 <vTaskEnterCritical>
   0x400d2235 <+25>:    rsr.prid        a3
   0x400d2238 <+28>:    extui   a3, a3, 13, 1
   0x400d223b <+31>:    rsr.prid        a5
   0x400d223e <+34>:    mov.n   a10, a4
   0x400d2240 <+36>:    call8   0x40085634 <vTaskExitCritical>
   0x400d2243 <+39>:    call8   0x40082648 <esp_log_timestamp>
   0x400d2246 <+42>:    l32r    a2, 0x400d0318 <_stext+768>
   0x400d2249 <+45>:    s32i.n  a7, a1, 8
   0x400d224b <+47>:    s32i.n  a3, a1, 4
   0x400d224d <+49>:    s32i.n  a5, a1, 0
   0x400d224f <+51>:    mov.n   a15, a6
   0x400d2251 <+53>:    mov.n   a14, a2
   0x400d2253 <+55>:    mov.n   a13, a10
   0x400d2255 <+57>:    l32r    a12, 0x400d031c <_stext+772>
   0x400d2258 <+60>:    mov.n   a11, a2
   0x400d225a <+62>:    movi.n  a10, 3
   0x400d225c <+64>:    call8   0x400824fc <esp_log_write>
   0x400d225f <+67>:    movi    a10, 200
   0x400d2262 <+70>:    call8   0x400d2184 <ConsumptionTick>
   0x400d2265 <+73>:    mov.n   a10, a4
   0x400d2267 <+75>:    call8   0x40085588 <vTaskEnterCritical>
   0x400d226a <+78>:    rsr.prid        a5
   0x400d226d <+81>:    mov.n   a10, a4
   0x400d226f <+83>:    call8   0x40085634 <vTaskExitCritical>
   0x400d2272 <+86>:    call8   0x40082648 <esp_log_timestamp>
   0x400d2275 <+89>:    s32i.n  a7, a1, 8
   0x400d2277 <+91>:    s32i.n  a3, a1, 4
   0x400d2279 <+93>:    s32i.n  a5, a1, 0
   0x400d227b <+95>:    mov.n   a15, a6
   0x400d227d <+97>:    mov.n   a14, a2
   0x400d227f <+99>:    mov.n   a13, a10
   0x400d2281 <+101>:   l32r    a12, 0x400d0320 <_stext+776>
   0x400d2284 <+104>:   mov.n   a11, a2
   0x400d2286 <+106>:   movi.n  a10, 3
   0x400d2288 <+108>:   call8   0x400824fc <esp_log_write>
   0x400d228b <+111>:   movi.n  a10, 0
   0x400d228d <+113>:   call8   0x400858f4 <vTaskDelete>
   0x400d2290 <+116>:   retw.n

Notice how at the first critical section (from +22 to +36), both xPortGetCoreID() and the inline assembly are called. However in the second critical section (from +75 to +83), only the inline assembly code is called. This may explain the mismatch of CoreID and cpu_id as the task may truly have switched cores whilst running ConsumptionTick(), but the old value of cpu_id was still being used due to compiler optimization.

Assembly when xPortGetCoreID() IS volatile
(gdb) disassemble task2
Dump of assembler code for function task2:
   0x400d2228 <+0>:     entry   a1, 48
   0x400d222b <+3>:     movi    a10, 0
   0x400d222e <+6>:     call8   0x40085520 <pcTaskGetTaskName>
   0x400d2231 <+9>:     mov.n   a6, a10
   0x400d2233 <+11>:    movi.n  a10, 0
   0x400d2235 <+13>:    call8   0x40085a98 <uxTaskPriorityGet>
   0x400d2238 <+16>:    mov.n   a7, a10
   0x400d223a <+18>:    l32r    a3, 0x400d0324 <_stext+780>
   0x400d223d <+21>:    or      a10, a3, a3
   0x400d2240 <+24>:    call8   0x400855ac <vTaskEnterCritical>
   0x400d2243 <+27>:    rsr.prid        a5
   0x400d2246 <+30>:    extui   a5, a5, 13, 1
   0x400d2249 <+33>:    rsr.prid        a4
   0x400d224c <+36>:    mov.n   a10, a3
   0x400d224e <+38>:    call8   0x40085658 <vTaskExitCritical>
   0x400d2251 <+41>:    call8   0x40082648 <esp_log_timestamp>
   0x400d2254 <+44>:    l32r    a2, 0x400d0318 <_stext+768>
   0x400d2257 <+47>:    s32i.n  a7, a1, 8
   0x400d2259 <+49>:    s32i.n  a5, a1, 4
   0x400d225b <+51>:    s32i.n  a4, a1, 0
   0x400d225d <+53>:    mov.n   a15, a6
   0x400d225f <+55>:    mov.n   a14, a2
   0x400d2261 <+57>:    mov.n   a13, a10
   0x400d2263 <+59>:    l32r    a12, 0x400d031c <_stext+772>
   0x400d2266 <+62>:    mov.n   a11, a2
   0x400d2268 <+64>:    movi    a10, 3
   0x400d226b <+67>:    call8   0x400824fc <esp_log_write>
   0x400d226e <+70>:    movi    a10, 200
   0x400d2271 <+73>:    call8   0x400d2188 <ConsumptionTick>
   0x400d2274 <+76>:    mov.n   a10, a3
   0x400d2276 <+78>:    call8   0x400855ac <vTaskEnterCritical>
   0x400d2279 <+81>:    rsr.prid        a5
   0x400d227c <+84>:    extui   a5, a5, 13, 1
   0x400d227f <+87>:    rsr.prid        a4
   0x400d2282 <+90>:    mov.n   a10, a3
   0x400d2284 <+92>:    call8   0x40085658 <vTaskExitCritical>
   0x400d2287 <+95>:    call8   0x40082648 <esp_log_timestamp>
   0x400d228a <+98>:    s32i.n  a7, a1, 8
   0x400d228c <+100>:   s32i.n  a5, a1, 4
   0x400d228e <+102>:   s32i.n  a4, a1, 0
   0x400d2290 <+104>:   mov.n   a15, a6
   0x400d2292 <+106>:   mov.n   a14, a2
   0x400d2294 <+108>:   mov.n   a13, a10
   0x400d2296 <+110>:   l32r    a12, 0x400d0320 <_stext+776>
   0x400d2299 <+113>:   mov.n   a11, a2
   0x400d229b <+115>:   movi.n  a10, 3
   0x400d229d <+117>:   call8   0x400824fc <esp_log_write>
   0x400d22a0 <+120>:   movi.n  a10, 0
   0x400d22a2 <+122>:   call8   0x40085918 <vTaskDelete>
   0x400d22a5 <+125>:   retw.n
However, when the assembly in `xPortGerCoreID()` is made volatile, the code between the two critical sections are identical.

@negativekelvin
Copy link
Contributor

Ok so will you add volatile keyword to xPortGetCoreID?

@Dazza0
Copy link
Contributor

Dazza0 commented Feb 26, 2019

@negativekelvin yes

@igrr igrr closed this as completed in 3576e54 Feb 28, 2019
igrr pushed a commit that referenced this issue Mar 1, 2019
When xPortGetCoreID() is called twice within a function,
it might only be called once after compilation. This
commit makes the inline assembly of the function volatile.

Closes #3093
igrr pushed a commit that referenced this issue Mar 6, 2019
When xPortGetCoreID() is called twice within a function,
it might only be called once after compilation. This
commit makes the inline assembly of the function volatile.

Closes #3093
igrr pushed a commit that referenced this issue Mar 16, 2019
When xPortGetCoreID() is called twice within a function,
it might only be called once after compilation. This
commit makes the inline assembly of the function volatile.

Closes #3093
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

5 participants