espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
12.91k stars 7.08k forks source link

Incorrect semaphore behavior in FreeRTOS under esp-idf (IDFGH-7260) #8849

Open matt-mjm opened 2 years ago

matt-mjm commented 2 years ago

Environment

Problem Description

We have identified a problem with the FreeRTOS Semaphore API under esp-idf. When creating two tasks which each attempt to give and take a mutex repeatedly inside a loop, one task (task A) can become blocked permanently during a take operation. Meanwhile, the other task (task B) is able to give and take the mutex inside itself repeatedly for over five seconds, completely starving out the first task of access.

Procedure

The table below outlines the basic process of each of the two tasks in our sample code

Task A Task B
Take the mutex Take the mutex
busywait (esp_rom_delay_us) vTaskDelay
Give the semaphore busywait (esp_rom_delay_us)
vTaskDelay Give the semaphore

Notes

Affected Versions

All three tested esp-idf versions were affected, but not under the same conditions. The matrix below indicates the conditions under which the two different log outputs were generated.

v5.0 v4.4.1 v4.3
2 2 1 Unpinned Same Priority
1 1 1 A higher priority than B
2 2 2 B higher priority than A
2 2 1 Pinned to same core Same Priority
1 1 1 A higher priority than B
2 2 2 B higher priority than A
2 2 2 Pinned to different core Same Priority
2 2 2 A higher priority than B
2 2 2 B higher priority than A
1 1 1 FREERTOS_UNICORE Same Priority
1 1 1 A higher priority than B
2 2 2 B higher priority than A

Expected Behavior

The intuitive expectation is that a "first-come-first-serve" system should exist for tasks of the same priority, with threads waiting the longest for the mutex being serviced first as the mutex becomes available.

Indeed, in FreeRTOS, semaphores are implemented as queues, which appear to offer this guarantee: Queues can have multiple readers, so it is possible for a single queue to have more than one task blocked on it waiting for data. [...] If the blocked tasks have equal priority, then the task that has been waiting for data the longest will be unblocked. Taken from: https://www.freertos.org/fr-content-src/uploads/2018/07/161204_Mastering_the_FreeRTOS_Real_Time_Kernel-A_Hands-On_Tutorial_Guide.pdf

It appears that this guarantee is being violated here: although A has been waiting to receive from the queue for many seconds and hundreds of queue sends and receives, xQueueSemaphoreTake in B continues to be serviced first before the same call in A.

#define xSemaphoreGive( xSemaphore )    xQueueGenericSend( ...
#define xSemaphoreTake( xSemaphore, xBlockTime )    xQueueSemaphoreTake( ...

In our example, we would expect Task A to be able to intermittently acquire the mutex during the test period.

Actual Behavior

After an initial period, Task A blocks forever while Task B takes and gives the semaphore to itself, starving task A entirely until the loop in Task B exits.

Possible Explanations

During our testing with v5.0-dev-2443-g047903c612, we determined that xQueueGenericSend in Task B was indeed identifying that another task of equal priority was waiting to acquire the mutex (or, receive from the queue), and correctly yielding control to the scheduler. The scheduler, however, chose to once again schedule task B to run again, as tasks A and B are both of the same priority. Task B then called xQueueSemaphoreTake, which quickly acquired the mutex / dequeued with no need to block. Task A does run at the next opportunity, when Task B calls vTaskDelay, but it is too late; the mutex has already been taken, and it must block again and wait for another opportunity.

As v4.3 is also affected when the priority of task A is set above the priority of task B, some other unidentified mechanism may be involved in that case.

Steps to reproduce

  1. Create a fresh project with idf.py create-project.
  2. Paste the example code into a .c file.
  3. Flash the image to an ESP32-WROOM32
  4. Monitor the serial console
  5. Compare the output to the attached logs / Observe that following the initial period, B repeatedly prints "Taken" while A doesn't get the semaphore until the loop in B exits
  6. In the case that the problem cannot be reproduced, the attached binary can also be tested

Code to reproduce this issue

#include "esp_log.h"

#include "freertos/FreeRTOS.h"
#include "freertos/FreeRTOSConfig.h"
#include "freertos/task.h"
#include "freertos/semphr.h"

SemaphoreHandle_t sem;

// print is set to true while Task A is waiting for the mutex.
// Task B will print its "Taken" message only while Task A is
// waiting for the mutex, to avoid cluttering the console output
bool print = false;

static void task_a(void *arg) {
    static const char* TAG = "A";
    for (int i = 0; i < 3; i++) {
        ESP_LOGI(TAG, "Take");
        print = true;
        xSemaphoreTake(sem, portMAX_DELAY);
        print = false;
        ESP_LOGI(TAG, "Taken");
        esp_rom_delay_us(5000);
        ESP_LOGI(TAG, "Give");
        xSemaphoreGive(sem);
        vTaskDelay(pdMS_TO_TICKS(1000));
    }
    vTaskDelete(NULL);
}

static void task_b(void *arg) {
    static const char* TAG = "B";
    for (int i = 0; i < 500; i++) {
        xSemaphoreTake(sem, portMAX_DELAY);
        if (print) ESP_LOGI(TAG, "Taken");
        vTaskDelay(pdMS_TO_TICKS(10));
        esp_rom_delay_us(3546);
        xSemaphoreGive(sem);
    }
    vTaskDelete(NULL);
}

void app_main() {
    sem = xSemaphoreCreateMutex();

// For v4.4.1 and v5.0, PA and PB we have reproduced the issue with PA == PB == 1
// For v4.3, we have reproduced the issue with PA == PB == 1 and PA == 2, PB == 1
#define PA 1
#define PB 1

    // Unpinned (for versions 4.4 and 5.0)
    xTaskCreate(task_b, "taskb", 2048, NULL, tskIDLE_PRIORITY + PB, NULL);
    vTaskDelay(pdMS_TO_TICKS(100));
    xTaskCreate(task_a, "taska", 2048, NULL, tskIDLE_PRIORITY + PA, NULL);

    // Pinned to same core
    // xTaskCreatePinnedToCore(task_b, "taskb", 2048, NULL, tskIDLE_PRIORITY + PB, NULL, 1);
    // vTaskDelay(pdMS_TO_TICKS(100));
    // xTaskCreatePinnedToCore(task_a, "taska", 2048, NULL, tskIDLE_PRIORITY + PA, NULL, 1);

    // Pinned to different core (for version 4.3)
    // xTaskCreatePinnedToCore(task_b, "taskb", 2048, NULL, tskIDLE_PRIORITY + PB, NULL, 0);
    // vTaskDelay(pdMS_TO_TICKS(100));
    // xTaskCreatePinnedToCore(task_a, "taska", 2048, NULL, tskIDLE_PRIORITY + PA, NULL, 1);

    for (;;) {
        vTaskDelay(pdMS_TO_TICKS(1000));
    }
}

Debug Logs

Note that A successfully takes the semaphore prior to B starting Once B starts A is not able to take the semaphore again until B's loop has ended and its task has exited. Then A is able to take the semaphore and complete its loop

Output 1 (Expected):

I (512) A: Take
I (522) A: Taken
I (522) A: Give
I (1522) A: Take
I (1522) A: Taken
I (1522) A: Give
I (2522) A: Take
I (2522) A: Taken
I (2522) A: Give

Output 2 (Actual):

I (510) A: Take
I (510) A: Taken
I (510) A: Give
I (1510) A: Take
I (1510) B: Taken
I (1520) B: Taken
... (Continue to loop "B: Taken")
I (5380) B: Taken
I (5390) B: Taken
I (5400) B: Taken
I (5410) A: Taken
I (5410) A: Give
I (6410) A: Take
I (6410) A: Taken
I (6410) A: Give

Other items

good-log.txt bad-log.txt source.zip binaries.zip

nopnop2002 commented 2 years ago

This is not an issue for esp-idf.

There is no wait between xSemaphoreGive and xSemaphoreTake in task_b

static void task_b(void *arg) {
    static const char* TAG = "B";
    for (int i = 0; i < 500; i++) {
        xSemaphoreTake(sem, portMAX_DELAY);
        if (print) ESP_LOGI(TAG, "Taken");
        vTaskDelay(pdMS_TO_TICKS(10));
        esp_rom_delay_us(3546);
        xSemaphoreGive(sem);
    }
    vTaskDelete(NULL);
}

This is work.

static void task_b(void *arg) {
    static const char* TAG = "B";
    for (int i = 0; i < 500; i++) {
        xSemaphoreTake(sem, portMAX_DELAY);
        if (print) ESP_LOGI(TAG, "Taken");
        esp_rom_delay_us(3546);
        xSemaphoreGive(sem);
        vTaskDelay(pdMS_TO_TICKS(10));
    }
    vTaskDelete(NULL);
}
I (423) A: Take
I (423) A: Taken
I (423) A: Give
I (1423) A: Take
I (1423) A: Taken
I (1423) A: Give
I (2423) A: Take
I (2423) A: Taken
I (2423) A: Give
acf-bwl commented 2 years ago

The problem is indeed solved if you add a delay, but the bug exists because it does not work in our test cases (ie, without a delay). These should still work, as indicated by freertos documentation. Even with delays, it seems the scheduling code may still allow theoretical conditions where such deadlocks can take place, as long as the process remains deterministic.

nopnop2002 commented 2 years ago

@acf-bwl

I did more testing.

TEST Case 1

Disable vTaskDelay. This can work.

static void task_b(void *arg) {
    static const char* TAG = "B";
    UBaseType_t prio = uxTaskPriorityGet( NULL );
    ESP_LOGI(pcTaskGetName(NULL), "Start Priority=%d",(int)prio);
    for (int i = 0; i < 500; i++) {
        xSemaphoreTake(sem, portMAX_DELAY);
        //vTaskDelay(pdMS_TO_TICKS(10));
        esp_rom_delay_us(3546);
        xSemaphoreGive(sem);
    }
    ESP_LOGI(TAG, "finish");
    vTaskDelete(NULL);
}
I (322) taskb: Start Priority=1
I (422) taska: Start Priority=1
I (422) A: Take
I (422) A: Taken
I (422) A: Give
I (1422) A: Take
I (1422) A: Taken
I (1422) A: Give
I (2122) B: finish
I (2422) A: Take
I (2422) A: Taken
I (2422) A: Give

TEST Case 2

Enable vTaskDelay. This can't work

static void task_b(void *arg) {
    static const char* TAG = "B";
    UBaseType_t prio = uxTaskPriorityGet( NULL );
    ESP_LOGI(pcTaskGetName(NULL), "Start Priority=%d",(int)prio);
    for (int i = 0; i < 500; i++) {
        xSemaphoreTake(sem, portMAX_DELAY);
        vTaskDelay(pdMS_TO_TICKS(10));
        esp_rom_delay_us(3546);
        xSemaphoreGive(sem);
    }
    ESP_LOGI(TAG, "finish");
    vTaskDelete(NULL);
}
I (322) taskb: Start Priority=1
I (422) taska: Start Priority=1
I (422) A: Take
I (422) A: Taken
I (422) A: Give
I (1422) A: Take
I (5332) B: finish
I (5332) A: Taken
I (5332) A: Give
I (6332) A: Take
I (6332) A: Taken
I (6332) A: Give

Test Case 3

Enable vTaskDelay. Changed taska Priority from 1 to 2. This can work.

static void task_b(void *arg) {
    static const char* TAG = "B";
    UBaseType_t prio = uxTaskPriorityGet( NULL );
    ESP_LOGI(pcTaskGetName(NULL), "Start Priority=%d",(int)prio);
    for (int i = 0; i < 500; i++) {
        xSemaphoreTake(sem, portMAX_DELAY);
        vTaskDelay(pdMS_TO_TICKS(10));
        esp_rom_delay_us(3546);
        xSemaphoreGive(sem);
    }
    ESP_LOGI(TAG, "finish");
    vTaskDelete(NULL);
}
I (322) taskb: Start Priority=1
I (422) taska: Start Priority=2
I (422) A: Take
I (422) A: Taken
I (422) A: Give
I (1422) A: Take
I (1422) A: Taken
I (1422) A: Give
I (2422) A: Take
I (2422) A: Taken
I (2422) A: Give
I (5332) B: finish

This may be a bug in the V4.4.1 scheduler using multi core. Scheduler


@wmy-espressif

It is better not to leave this defect.

AxelLin commented 1 year ago

Any update? @Dazza0 @KonstantinKondrashov

AxelLin commented 1 year ago

@Dazza0 Any comment abut this issue? The starvation looks like a fundamental issue.

I tested above code with v5.1-dev-1879-g96b0cb2828 using esp32c3 (which is single core), and confirm the same behavior. i.e. After an initial period, Task A blocks forever while Task B takes and gives the semaphore to itself, starving task A entirely until the loop in Task B exits.

AxelLin commented 1 year ago

@Dazza0

It does not make sense there is no response for 7 months. If you are not the correct assignee please speak up and forward this to proper developers. As I said the starvation is a fundamental issue, I hope to get clarify if this is a bug or not.

@Alvin1Zhang @igrr

acf-bwl commented 1 year ago

When we were originally investigating this issue, we also determined it was a fundamental issue, and that it might be very difficult to fix on the current Espressif multi-core FreeRTOS implementation. This was a pattern we used in parts of our code, and we have had to work around this issue. The Espressif developers have to decide what issues make sense to prioritize based on importance and ability to fix. Being a small customer and not paying for support means waiting for espressif to get around to it or fixing it ourselves. We do believe this is an important issue, though.

Dazza0 commented 1 year ago

@acf-bwl @AxelLin I've taken a look at this issue and have been able to recreate this locally on multiple releases. The issue you're seeing is one scenario of the more general "spinlock acquire race condition" previously described in this comment.

This issue is quite difficult to explain, so I'll provide a quick, summary here and leave the full explanations below.

Critical Section Race Condition

All FreeRTOS queues/semaphores/mutex read/write functions will internally use a loop. The pseudo code below illustrates the rough behavioral flow of these functions:

BaseType_t xQueueSend/Receive/SemaphoreTake(...)
{
    // Main fucntion loop
    for(;;) {
        // Race condition happens here, before we enter the critical section.
        taskENTER_CRITICAL();
        // Check for empty/full queue/semaphore/mutex
        if (not empty/full) {
            // Read/write here
        else {
            // Flow downwards to enter timeout
        }
        taskEXIT_CRITICAL();

        // Handle timeout stuff
        vTaskSuspendAll();
        prvLockQueue( pxQueue );
        if (not_timed_out) {
            // Haven't timed out yet. Yield (i.e., block) on the queue/sempahore/mutex
            prvUnlockQueue( pxQueue );
            ( void ) xTaskResumeAll();
            portYIELD_WITHIN_API();
        } else {
            prvUnlockQueue( pxQueue );
            ( void ) xTaskResumeAll();
        }
        /* Once we are here, we either:
        - Have timed out, in which case we return just return from this function
        - Have blocked from portYIELD_WITHIN_API(), then been unblocked because a message has been received/emptied. So we...
            - loop back around
            - Enter the critical section
            - Check for a message/empty space
            - Read/write our message
        */
    }
}

Note: In IDF's SMP FreeRTOS, we replace the queue locks with a critical section, but this doesn't affect the race condition.

From the pseudo code above, you'll notice that after a task blocks on a queue/semaphore/mutex, it will remain blocked until it times out, or is unblocked by another task/ISR by reading/writing a message to the queue/semaphore/mutex.

For example, if a "task A" tires to read an empty queue, it will block at the point of the portYIELD_WITHIN_API() call. If another "task B" then writes to the queue, "task A" will unblock and resume execution right after the portYIELD_WITHIN_API(). You'll notice that "task A" must then...

  1. Loop back around to the top of the loop
  2. Then re-enter a critical section so that the queue can be read safely.

It is at this point where the race condition can occur. If a "task C" of lower priority but running on the other core also attempts to read the queue at the same time, "task C" can beat "task A" in entering that critical section first (in SMP this means "task C" acquires the spinlock first). Thus, the following occurs:

  1. "task C" of lower priority enters the critical section first (i.e., acquires the spinlock first) while "task A' is still looping back around
  2. "task C" sees that the queue has a message and reads it. Meanwhile, "task A" is still stuck trying to enter the critical section (waiting for the spinlock to be released)
  3. "task C" has read a message so it doesn't need to block. It exits the critical and simply returns from the function
  4. "task A" is now able to enter the critical section, but now the queue is empty (because "task C" stole the message). "task A" follows the same flow of blocking on an empty queue.

Thus, as a result, under some narrow timing circumstances, it is possible for a lower priority "task C" to "cut in line" of the queue and get a message before a blocked higher priority "task A".

On single-core, this race condition cannot occur because only one task (which is the highest priority task) can run at any one time. Thus, in single core, if the same "task A" is looping back around after being unblocked:

Implications on SMP in IDF

This race condition isn't an issue in most IDF applications for the following reasons:

Narrow Timing Window

This race condition requires a very specific timing window (with one core looping back around just after being unblocked, and the other core contesting the queue at the same time). Thus to get a full starvation scenario requires very careful and repeatable timing (as demonstrated in the example code you have provided).

In the vast majority of queue/semaphore/mutex use cases, a task will receive/take the queue/sempahore/mutex, and then carry out some some sort of action (either process the message, handle the event indicated by the semaphore, or access the resource protected by the mutex). These actions are usually variable time, thus making it unlikely for the race condition timing window to consistently occur.

Furthermore, timing variance introduced by timer interrupts and cache misses further makes it unlikely for a task to be consistently starved.

Priority Inversion Tolerance

Even if this race condition occasionally occurs, the usual result is that a task simply blocks until the next message (while the previous message was stolen by the lower priority task). However IDF components don't rely on task priority for correct behavior. For example, some single core FreeRTOS applications may relay on the fact that a task is the highest priority task, thus has exclusive access to a particular resource. But this assumption is never made in IDF (because a task on the other core is running concurrently). Thus (sequential order/exclusive access) in IDF components is always guarded by using queues/semaphores/mutexes/spinlocks.

Possible Fixes and their trade-offs

Reserving the next reader

It might be possible to maintain a next_reader_task field in the queue structure somewhere indicating the task that was just unblocked on the queue. This would mean that any contesting task would need to check if there is a next_reader_task and block themselves even if a message is available. For example, "task A" (priority 5, core 0) has just been unblocked to read the queue, "task B" (priority 4, core 1) gets the critical section first but does not read the message as there is next_read_task is set. "task B' blocks itself thus allowing "task A" to read the message as intended.

This would solve the immediate race condition mentioned above, but introduces further issues:

Ensuring only the highest priority tasks run

In this approach, only tasks of the current highest priority would run. For example, if the highest ready priority was 10, then only priority 10 tasks would run. If a core does not have an available task of that priority to run, it will run the idle task. This approach is actually provided in Amazon SMP FreeRTOS (see the configRUN_MULTIPLE_PRIORITIES option) and would restore the single core assumption of the highest priority task running at any one time. However, the down side to this is a severe reduction in processing throughput, as the cores cannot run tasks of different priorities at the same time.

If you have any ideas/considerations/suggestions about this issue, I'm happy to hear them.

acf-bwl commented 1 year ago

@Dazza0 Thank you for the detailed analysis. I can see you've put a lot of thought into this issue; it's much appreciated.

Note that from our testing, this can also happen with two tasks of the same priority as well, which was the biggest issue for us. We have a pattern we had been using in our code:

for (;;) {
    take mutex
    //  most of the time is spent in here waiting for I/O
    give mutex

    // allow other tasks of same or greater priority that are waiting, to access shared resource before taking mutex once again
}

Reserving the next reader

I think some variation of this solution is the most workable. I do feel that some fix to this issue to bring it in line with POSIX semaphores / most other platforms semantics is inevitable eventually.

Should "task Y" block and leave the message for "task A", waiting for "task A" to schedule back to read the message (i.e., strict FIFO order)? Or should "task Y" read the message immediately given that it would be more efficient as "task A" cannot immediately read the message (i.e., first come first serve model)?

Implementing the desired semantics strictly might be easiest until the problem is not reproducible anymore, and then loosening them up, but that's just my two cents ;)

AxelLin commented 1 year ago

@acf-bwl @AxelLin I've taken a look at this issue and have been able to recreate this locally on multiple releases. The issue you're seeing is one scenario of the more general "spinlock acquire race condition" previously described in this comment.

This issue is quite difficult to explain, so I'll provide a quick, summary here and leave the full explanations below.

  • This bug essentially involves a lower priority task A on core X stealing a (queue message/mutex/semaphore) from a higher priority blocked task B on core Y. It is a result of some single-core FreeRTOS assumptions no longer being true under SMP.

How about the starvation issue happened with "the sam priority" case?

Dazza0 commented 1 year ago

@AxelLin

How about the starvation issue happened with "the sam priority" case?

The race condition is the same, In this case the task B on the other core of the same priority is able to enter the critical section first, thus leading to "task B" stealing the message.

AxelLin commented 1 year ago

Implications on SMP in IDF

This race condition isn't an issue in most IDF applications for the following reasons:

But @acf-bwl and @matt-mjm already prove this issue can happen in a real project, especially with "the same priority" case.

wuyuanyi135 commented 1 year ago

@Dazza0 @matt-mjm @acf-bwl Thanks for raising up this issue. I also notice the similar inconsistent behavior when using the C++20 semaphore to implement a producer-consumer-like library. See the code below:

Problematic case on ESP32S3 (v5.1-dev-3027-gdace03fccd)

The following code will block very quickly at either producer or consumer's acquire. It worths noting that if I uncomment the delay line it could run fine. That's why I suspect this is a similar issue related to this one.

#include <esp_log.h>
#include <mutex>
#include <semaphore>
#include <thread>
static const char* TAG = "MAIN";
std::counting_semaphore<10> filled_sem{0};
std::counting_semaphore<10> empty_sem{2};
extern "C" void app_main() {
  int count = 0;

  while (true) {
    const size_t repeat = 100;
    ESP_LOGI("MAIN", "Count = %d", count);
    std::thread producer_thread([&] {
      for (int i = 0; i < repeat; ++i) {
        empty_sem.acquire();
        ESP_LOGI("MAIN", "Produced an element");
        filled_sem.release();
      }
    });
    std::thread consumer_thread([&] {
      for (int i = 0; i < repeat; ++i) {
        filled_sem.acquire();
        ESP_LOGI("MAIN", "Consumed an element");
        empty_sem.release();
        //        vTaskDelay(pdMS_TO_TICKS(10)); // With this like it runs OK
      }
    });
    producer_thread.join();
    consumer_thread.join();
  }
}

Also see the stack backtrace:

#0  0x40375c69 in esp_ptr_executable (p=0xfffffffd)
    at C:/Espressif/frameworks/esp-idf-master/components/esp_hw_support/include/esp_memory_utils.h:207
#1  esp_backtrace_get_next_frame (frame=<optimized out>)
    at C:/Espressif/frameworks/esp-idf-master/components/esp_system/port/arch/xtensa/debug_helpers.c:33
#2  0x4037eaa4 in insert_free_block (sl=-2143819100, fl=1070552304, block=0x3fcf54b0, control=0x3fcf54f0)
    at C:/Espressif/frameworks/esp-idf-master/components/heap/tlsf/tlsf.c:371
#3  block_insert (block=0x3fcf54b0, control=0x3fcf54f0)
    at C:/Espressif/frameworks/esp-idf-master/components/heap/tlsf/tlsf.c:388
#4  block_trim_free (size=<optimized out>, block=0x3fc9d375, control=0x3fcf54f0)
    at C:/Espressif/frameworks/esp-idf-master/components/heap/tlsf/tlsf.c:502
#5  block_prepare_used (size=<optimized out>, block=0x3fc9d375, control=0x3fcf54f0)
    at C:/Espressif/frameworks/esp-idf-master/components/heap/tlsf/tlsf.c:579
#6  tlsf_malloc (tlsf=0x3fcf54f0, size=<optimized out>)
    at C:/Espressif/frameworks/esp-idf-master/components/heap/tlsf/tlsf.c:1005
#7  0x403856c8 in ?? ()
#8  0x403800fc in spi_flash_chip_mxic_opi_detect_size (chip=<optimized out>, size=0x0)
    at C:/Espressif/frameworks/esp-idf-master/components/spi_flash/spi_flash_chip_mxic_opi.c:44
#9  0x4037f24f in __atomic_fetch_add_8 (ptr=0x3fcecf20, value=4597840332355272704, memorder=0)
    at C:/Espressif/frameworks/esp-idf-master/components/newlib/stdatomic.c:447
#10 0x40375606 in call_start_cpu0 ()
    at C:/Espressif/frameworks/esp-idf-master/components/esp_system/port/cpu_start.c:513

Working case on MINGW64

This is the similar code above but run on Windows MINGW64 platform. It runs flawlessly.

#include <cstdio>
#include <mutex>
#include <semaphore>
#include <thread>
std::counting_semaphore<10> filled_sem{0};
std::counting_semaphore<10> empty_sem{2};
int main() {
  int count = 0;
  while (true) {
    const size_t repeat = 100;
    printf("Count = %d\n", count);
    std::thread producer_thread([&] {
      for (int i = 0; i < repeat; ++i) {
        empty_sem.acquire();
        printf("Produced an element\n");
        filled_sem.release();
      }
    });
    std::thread consumer_thread([&]{
      for (int i = 0; i < repeat; ++i) {
        filled_sem.acquire();
        printf("Consumed an element\n");
        empty_sem.release();
      }
    });
    producer_thread.join();
    consumer_thread.join();
  }
}

The good news is that this race condition shouldn't be an issue in IDF applications, thus why the same queue/mutex/semaphore implementation has been used in IDF for many releases without this race condition causing a noticeable error (see explanation below).

@Dazza0 Sorry I may have missed some key information in your detailed messages. But I think this could be a very common issue since it can easily trigger deadlock in the multithread or buffered IO codes. Could you elaborate why is this race condition shouldn't be an issue in IDF applications and what would be the recommended approach to work around this issue? I found adding 1 tick delay the only useful workaround. Could you confirm this delay (or yield of time frame) is necessary when using semaphore?

nopnop2002 commented 1 year ago

this issue can happen in a real project, especially with "the same priority" case.

That's exactly right.

It is common practice to prepare separate tasks for the input and output of a single resource and mutually control them with a semaphore.

Such a design would have this problem.

Zmmfly commented 1 year ago

This problem also exists in IDF version 5.0.1

AxelLin commented 11 months ago

@AxelLin

How about the starvation issue happened with "the sam priority" case?

The race condition is the same, In this case the task B on the other core of the same priority is able to enter the critical section first, thus leading to "task B" stealing the message.

@Dazza0 @zikalino

I just check FreeRTOS V10.6.0 changelog ( https://github.com/FreeRTOS/FreeRTOS-Kernel/releases/tag/V10.6.0 )

I'm wondernig if below fixes mentioned in changelog are realted to this issue?

AxelLin commented 9 months ago

@Dazza0

You said there is no easy way to fix this. But you are aware the bug is real and this has been reported by many people. So what make you think it's ok to live with this bug?

SravanMaddukuri commented 3 days ago

Hi, I am using a recursive semaphore in one of my tasks to call the 'mqtt_enqueue' function. According to the logs, the MQTT_API_LOCK semaphore is acquired by the mqtt_task (from the framework - mqtt_client.c) and is never released until my task exits.

Is anyone else using a recursive semaphore experiencing a similar issue and has found a workaround? I am using ESP-IDF Release v4.4.3.