High Priority Task Appearing Not to Preempt Low Priority Task???

[gfvalvo]

Hello.
In the MRE below, the Consumer Task has a higher priority than the Producer Task. So, when the Producer sets the Event Group bit, I would expect the Consumer Task to preempt it, do its printing, and then block itself again BEFORE the (lower priority) Producer Task resumes executing. Therefore, it seems that the printing sequence should be:

Code: Select all

[338536][I][sketch_aug28a.ino:24] producerFunction(): Producer Function: Setting Event Bits
[338537][I][sketch_aug28a.ino:34] consumerFunction(): Consumer Task Received Event Bit
[338536][I][sketch_aug28a.ino:26] producerFunction(): Producer Function: Event Bits Set

However, what I'm seeing is this:

Code: Select all

[338536][I][sketch_aug28a.ino:24] producerFunction(): Producer Function: Setting Event Bits
[338536][I][sketch_aug28a.ino:26] producerFunction(): Producer Function: Event Bits Set
[338537][I][sketch_aug28a.ino:34] consumerFunction(): Consumer Task Received Event Bit

Hope someone can explain where I went wrong. BTW, this is with Core 2.0.11 on an ESP32 Dev Board.
Thanks.

Code:

Code: Select all

#include "Arduino.h"

void producerFunction(void *pvParameters);
void consumerFunction(void *pvParameters);

EventGroupHandle_t controlGroupHandle;

void setup() {
  Serial.begin(115200);
  vTaskDelay(2000);
  log_i("Starting");

  controlGroupHandle = xEventGroupCreate();
  xTaskCreatePinnedToCore(consumerFunction, "Consumer Task 1", 2000, NULL, 6, NULL, CONFIG_ARDUINO_RUNNING_CORE);
  vTaskDelay(500);
  xTaskCreatePinnedToCore(producerFunction, "Producer Task", 2000, NULL, 2, NULL, CONFIG_ARDUINO_RUNNING_CORE);
}

void producerFunction(void *pvParameters) {
  log_i("Producer Task Started\n");

  for (;;) {
    vTaskDelay(2000);
    log_i("Producer Function: Setting Event Bits");
    xEventGroupSetBits(controlGroupHandle, 1);
    log_i("Producer Function: Event Bits Set");
  }
}

void consumerFunction(void *pvParameters) {
  log_i("Consumer Task Started");
  for (;;) {
    xEventGroupWaitBits(controlGroupHandle, 1, pdTRUE, pdFALSE, portMAX_DELAY);
    log_i("Consumer Task Received Event Bit");
  }
}

void loop() {
}

[gfvalvo]

Interestingly, it works as expected when using a Task Notification. So perhaps unblocking tasks using Event Groups doesn't happen immediately (regardless of the task's priority), but on the FreeRTOS tick boundaries???

Code: Select all

#include "Arduino.h"

void producerFunction(void *pvParameters);
void consumerFunction(void *pvParameters);

TaskHandle_t consumerTaskHandle;

void setup() {
  Serial.begin(115200);
  vTaskDelay(2000);
  log_i("Starting");

  xTaskCreatePinnedToCore(consumerFunction, "Consumer Task 1", 2000, NULL, 6, &consumerTaskHandle, CONFIG_ARDUINO_RUNNING_CORE);
  vTaskDelay(500);
  xTaskCreatePinnedToCore(producerFunction, "Producer Task", 2000, NULL, 2, NULL, CONFIG_ARDUINO_RUNNING_CORE);
}

void producerFunction(void *pvParameters) {
  log_i("Producer Task Started\n");

  for (;;) {
    vTaskDelay(2000);
    log_i("Producer Function: Sending Notification");
    xTaskNotifyGive(consumerTaskHandle);
    log_i("Producer Function: Event Bits Set");
  }
}

void consumerFunction(void *pvParameters) {
  log_i("Consumer Task Started");
  for (;;) {
    ulTaskNotifyTake(pdTRUE, portMAX_DELAY);
    log_i("Consumer Task: Received Notification");
  }
}

void loop() {
}

Output:

Code: Select all

[  4545][I][sketch_aug28a.ino:23] producerFunction(): Producer Function: Sending Notification
[  4545][I][sketch_aug28a.ino:33] consumerFunction(): Consumer Task: Received Notification
[  4550][I][sketch_aug28a.ino:25] producerFunction(): Producer Function: Notification Sent

[ESP_Sprite]

That is odd. As far as I can see from the documentation, event groups are supposed to be pre-emptive as well, so I can't explain this behaviour. I'm thinking that this may be some weird behaviour in the log_i function rather than the event groups, but I don't have a theory for how that could work.

[gfvalvo]

I'm thinking that this may be some weird behaviour in the log_i function rather than the event groups, but I don't have a theory for how that could work.

Yes, I'd be hard pressed to explain that. Especially when it works as expected if I use a Task Notification rather than an Event Group bit.

[gfvalvo]

I'm thinking that this may be some weird behaviour in the log_i function

Also, it behaves the same way with Serial.print(). FYI, see the code below using Task Notifications. Note the relative priority of the 3 tasks (1 Producer + 2 Consumers). You'll see that reflected in the order of the printouts. Exactly what would be expected when a higher-priority task preempts.

Code: Select all

#include "Arduino.h"

void producerFunction(void *pvParameters);
void consumerFunction(void *pvParameters);

TaskHandle_t consumer0TaskHandle;
TaskHandle_t consumer1TaskHandle;

void setup() {
	Serial.begin(115200);
	vTaskDelay(2000);
	Serial.println("Starting");

	uint32_t ConsumerTaskNumber = 0;
	xTaskCreatePinnedToCore(consumerFunction, "Consumer Task 0", 2000, &ConsumerTaskNumber, 2, &consumer0TaskHandle, CONFIG_ARDUINO_RUNNING_CORE);
	vTaskDelay(500);

	ConsumerTaskNumber = 1;
	xTaskCreatePinnedToCore(consumerFunction, "Consumer Task 1", 2000, &ConsumerTaskNumber, 6, &consumer1TaskHandle, CONFIG_ARDUINO_RUNNING_CORE);
	vTaskDelay(500);

	xTaskCreatePinnedToCore(producerFunction, "Producer Task", 2000, NULL, 4, NULL, CONFIG_ARDUINO_RUNNING_CORE);
}

void producerFunction(void *pvParameters) {
	Serial.println("Starting Producer Task");
	vTaskDelay(2000);
	Serial.printf("\nProducer Task: Sending Notifications\n");
	xTaskNotifyGive(consumer0TaskHandle);
	xTaskNotifyGive(consumer1TaskHandle);
	Serial.printf("Producer Task: Notifications Sent\n");

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

void consumerFunction(void *pvParameters) {
	uint32_t taskNumber = *reinterpret_cast<uint32_t*>(pvParameters);
	Serial.printf("Starting Consumer Task # %d\n", taskNumber);

	for (;;) {
		ulTaskNotifyTake(pdTRUE, portMAX_DELAY);
		Serial.printf("Consumer Task %d Received Notification\n", taskNumber);
	}
}

void loop() {
}

Output:

Code: Select all

Producer Task: Sending Notifications
Consumer Task 1 Received Notification
Producer Task: Notifications Sent
Consumer Task 0 Received Notification

[ESP_Sprite]

What particular chip is this on, btw? (As in ESP32, ESP32-S2, ESP32-C3, ...)

[gfvalvo]

What particular chip is this on, btw? (As in ESP32, ESP32-S2, ESP32-C3, ...)

Confirmed the same behavior on:
Adafruit ESP32 Feather Huzzah: ESP-WROOM-32
ESP32 CAM: ESP32-S

[ESP_Sprite]

Okay, checked this. I can also replicate this under ESP-IDF:
- This is not a logging oddity; checked this by setting/reading an atomic variable.
- This is an Espressif freertos port issue; changing over to the Amazon kernel fixes the behaviour.
- It seems to be Xtensa-specific, and/or happens only when FreeRTOS runs on both cores (I don't have a dual-core RiscV chip, so can't test on that).

I'll file this internally as an issue so my colleagues can take a look at this.