I can add code to work around that, but I would like to know why that is occurring as according to the docs t should wait until at least 500ms have expired (or it has received an event). NB it doesn't always expire early and is non-deterministic. Approximately once every 3 times I run this code it will expire early on the first iteration.
Here is some log showing the 2nd xQueueReceive invocation timing out after 497 (at 3984). NB I have seen as low as 490ms.
Code: Select all
I (734) serial: Starting serial tasks
D (744) serial: Waiting for TX message timeout_ms=-1 now=127 free_heap=288220 free_stack=3792
D (3484) serial: Received TX queue event - sending msg_id==128
D (3484) serial: Doing something
D (3484) serial: Waiting for TX message timeout_ms=500 now=2860 free_heap=291600 free_stack=2432
D (3984) serial: TX queue timed out - then=3357 then_and_now_diff_ms=497
D (3984) serial: Doing somethingelse
D (3984) serial: Waiting for TX message timeout_ms=500 now=3357 free_heap=291600 free_stack=2432
D (4484) serial: TX queue timed out - then=3857 then_and_now_diff_ms=500
D (4484) serial: Doing somethingelse
Code: Select all
static void do_something() {
ESP_LOGD(TAG, "Doing something");
}
static void do_somethingelse() {
ESP_LOGD(TAG, "Doing somethingelse");
}
/**
* Testing why xQueueReceive doesn't always wait the full timeout even when no event is received.
*/
static void tx_task_test(__attribute__((unused)) void *arg) {
application_message_t *application_message;
TickType_t queue_timeout_ms = -1;
while (true) {
int64_t now = wt_millis();
const TickType_t queue_timeout_ticks = (queue_timeout_ms == -1) ? portMAX_DELAY : queue_timeout_ms / portTICK_PERIOD_MS;
ESP_LOGD(TAG, "Waiting for TX message timeout_ms=%d now=%lld free_heap=%d free_stack=%d", queue_timeout_ms, now, heap_caps_get_free_size(MALLOC_CAP_DEFAULT), uxTaskGetStackHighWaterMark(NULL));
if (xQueueReceive(tx_queue, &application_message, queue_timeout_ticks)) {
ESP_LOGD(TAG, "Received TX queue event - sending msg_id==%d", application_message->msg_id);
do_something();
} else {
// Timed out.
const int64_t then = wt_millis();
ESP_LOGD(TAG, "TX queue timed out - then=%lld then_and_now_diff_ms=%lld", then, then - now);
do_somethingelse();
}
queue_timeout_ms = 500;
}
}
void init_serial() {
ESP_LOGI(TAG, "Starting serial tasks");
tx_queue = xQueueCreate(MAX_TX_QUEUE_SIZE, sizeof(application_message_t *));
xTaskCreate(tx_task_test, "uart_tx_task", STACK_SIZE_SMALL, NULL, configMAX_PRIORITIES-2, NULL);
}