Ringbuf: Acquiring entire ring buffer results in items being received prematurely (IDFGH-13694) #14568

james-corticallabs · 2024-09-13T05:28:05Z

Answers checklist.

I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
I have searched the issue tracker for a similar issue and not found a similar issue.

IDF version.

v5.4-dev-2744-g59e1838270

Espressif SoC revision.

ESP32-D0WD-V3 (revision v3.0)

Operating System used.

Linux

How did you build your project?

Command line with idf.py

If you are using Windows, please specify command line type.

None

Development Kit.

Custom Board

Power Supply used.

External 3.3V

What is the expected behavior?

I expect to:

Acquire space for multiple items on a ring buffer using xRingbufferSendAcquire until the ring buffer is full.
For each item, write a value to it and complete the sending of it using xRingbufferSendComplete. I expect to be able to do this in a different order from which the items were acquired in step 1.
Receive the items using xRingbufferReceive on a separate task in the order they were acquired in step 1 and containing their expected values.

What is the actual behavior?

Instead, when the buffer is full, the oldest acquired item is returned by xRingbufferReceive even if that item has not been sent yet using xRingbufferSendComplete. If the sending task has not yet finished writing to this oldest acquired item then it results in the receiving task reading the wrong value for that item.

Steps to reproduce.

Create a no split ring buffer
Create a task which reads from the ring buffer
Acquire first item on the ring buffer using xRingbufferSendAcquire (labelled as item1 in the steps and code below)
Repeat the following until the ring buffer is full
4a. Acquire item using xRingbufferSendAcquire
4b. Write a value to item
4c. Send item using xRingbufferSendComplete
Write a value to item1
Send item1 using xRingbufferSendComplete

Code to reproduce:

#include <stdio.h>

#include "freertos/FreeRTOS.h"
#include "freertos/ringbuf.h"

#define QUEUE_LENGTH            3
#define FREERTOS_RB_HEADER      8   // sizeof(ItemHeader_t)
#define BUFFER_SIZE             ((FREERTOS_RB_HEADER + sizeof(uint32_t)) * QUEUE_LENGTH)

#define STACK_SIZE              2048

RingbufHandle_t xRingBuffer;
StaticRingbuffer_t xRingBufferStruct;
uint8_t xRingBufferStorage[BUFFER_SIZE];

StackType_t xStack[STACK_SIZE];
StaticTask_t xTaskBuffer;

void receive_task(void* pvParameters)
{
    size_t item_size;

    while (true)
    {
        uint32_t* item = (uint32_t*)xRingbufferReceive(xRingBuffer, &item_size, portMAX_DELAY);
        if (item != NULL)
        {
            printf("Item: %ld\n", *item);
        }
    }
}

void app_main(void)
{
    xRingBuffer = xRingbufferCreateStatic(BUFFER_SIZE, RINGBUF_TYPE_NOSPLIT, xRingBufferStorage, &xRingBufferStruct);
    xTaskCreateStatic(receive_task, "receive_task", STACK_SIZE, NULL, 2, xStack, &xTaskBuffer);

    printf("Start\n");

    uint32_t* item1;
    xRingbufferSendAcquire(xRingBuffer, (void**)&item1, sizeof(uint32_t), 0);
    *item1 = 1000;

    uint32_t* item2;
    xRingbufferSendAcquire(xRingBuffer, (void**)&item2, sizeof(uint32_t), 0);
    *item2 = 2;
    xRingbufferSendComplete(xRingBuffer, item2);

    uint32_t* item3;
    xRingbufferSendAcquire(xRingBuffer, (void**)&item3, sizeof(uint32_t), 0);
    *item3 = 3;

    vTaskDelay(3000 / portTICK_PERIOD_MS);

    // This call to xRingbufferSendComplete causes item1 to be received by receive_task prematurely 
    xRingbufferSendComplete(xRingBuffer, item3);

    vTaskDelay(3000 / portTICK_PERIOD_MS);

    *item1 = 1;
    xRingbufferSendComplete(xRingBuffer, item1);
}

Expected result of above code:

Start
Item: 1
Item: 2
Item: 3

Actual result of above code:

Start
Item: 1000
Item: 2
Item: 3

Debug Logs.

I (13) boot: ESP-IDF v5.4-dev-2744-g59e1838270 2nd stage bootloader
I (14) boot: compile time Sep 13 2024 04:37:33
I (14) boot: Multicore bootloader
I (18) boot: chip revision: v3.0
I (22) boot.esp32: SPI Speed      : 40MHz
I (27) boot.esp32: SPI Mode       : DIO
I (31) boot.esp32: SPI Flash Size : 2MB
I (36) boot: Enabling RNG early entropy source...
I (41) boot: Partition Table:
I (45) boot: ## Label            Usage          Type ST Offset   Length
I (52) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (60) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (67) boot:  2 factory          factory app      00 00 00010000 00100000
I (75) boot: End of partition table
I (79) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=09c10h ( 39952) map
I (101) esp_image: segment 1: paddr=00019c38 vaddr=3ffb0000 size=0230ch (  8972) load
I (105) esp_image: segment 2: paddr=0001bf4c vaddr=40080000 size=040cch ( 16588) load
I (113) esp_image: segment 3: paddr=00020020 vaddr=400d0020 size=13a14h ( 80404) map
I (143) esp_image: segment 4: paddr=00033a3c vaddr=400840cc size=097a0h ( 38816) load
I (165) boot: Loaded app from partition at offset 0x10000
I (165) boot: Disabling RNG early entropy source...
I (177) cpu_start: Multicore app
I (186) cpu_start: Pro cpu start user code
I (186) cpu_start: cpu freq: 160000000 Hz
I (186) app_init: Application information:
I (189) app_init: Project name:     idf-ringbuf-test
I (194) app_init: App version:      1
I (199) app_init: Compile time:     Sep 13 2024 04:37:25
I (205) app_init: ELF file SHA256:  84dc7f4bf...
I (210) app_init: ESP-IDF:          v5.4-dev-2744-g59e1838270
I (217) efuse_init: Min chip rev:     v0.0
I (221) efuse_init: Max chip rev:     v3.99 
I (226) efuse_init: Chip rev:         v3.0
I (231) heap_init: Initializing. RAM available for dynamic allocation:
I (238) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (244) heap_init: At 3FFB35B8 len 0002CA48 (178 KiB): DRAM
I (251) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (257) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (263) heap_init: At 4008D86C len 00012794 (73 KiB): IRAM
I (271) spi_flash: detected chip: generic
I (274) spi_flash: flash io: dio
W (278) spi_flash: Detected size(16384k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (292) main_task: Started on CPU0
I (302) main_task: Calling app_main()
Start
Item: 1000
Item: 2
Item: 3
I (6302) main_task: Returned from app_main()

More Information.

I am building using the docker image espressif/idf:latest.

The text was updated successfully, but these errors were encountered:

sudeep-mohanty · 2024-09-13T06:32:01Z

Thanks for reporting the issue, @james-corticallabs. We shall take a look and get back to you on this.

james-corticallabs · 2024-09-20T00:10:34Z

Thanks @sudeep-mohanty for fixing this. Will this fix be backported to a current release of esp-idf?

sudeep-mohanty · 2024-09-20T06:13:28Z

Hi @james-corticallabs, Yes, the fix will be back ported to the release branches once our internal tests pass. Thanks.

…ms prematurely This commit fixes a bug in the no-split buffer which could receive an item prematurely if the space on the buffer is acquired until the buffer is full. The commit also adds a unit test for this scenario. Closes #14568

upolc-lg · 2024-11-27T13:25:15Z

Hi,
according to my testing this issue is still not resolved.
I'm attaching a sample code that causes the ringbuffer to stop returning items.

#include "esp_log.h"
#include "sdkconfig.h"

#include "freertos/FreeRTOS.h"
#include "freertos/ringbuf.h"
#include "freertos/task.h"

#include <inttypes.h>
#include <stdio.h>
#include <string.h>

static const char tag_c[] = "RB_TST";

void ringbuffer_test(void *pvParameters)
{
    char *item = NULL;
    char *item_1 = NULL;
    char *item_2 = NULL;
    size_t size = 0;

    esp_log_level_set(tag_c, ESP_LOG_VERBOSE);

    RingbufHandle_t rb = xRingbufferCreate(64, RINGBUF_TYPE_NOSPLIT);

    xRingbufferSendAcquire(rb, (void **)&item_1, 15, 0);
    xRingbufferSendAcquire(rb, (void **)&item_2, 15, 0);

    xRingbufferSendComplete(rb, item_1);
    xRingbufferSendComplete(rb, item_2);

    while ((item = xRingbufferReceive(rb, &size, 0)) != NULL)
    {
        ESP_LOGI(tag_c, "1: received message size %u from %p", size, item);
        vRingbufferReturnItem(rb, item);
    }

    vTaskDelay(100);

    xRingbufferSendAcquire(rb, (void **)&item_1, 15, 0);
    xRingbufferSendAcquire(rb, (void **)&item_2, 15, 0);

    sprintf(item_1, "Hello ");

    sprintf(item_2, "This is fine");
    xRingbufferSendComplete(rb, item_2);

    while ((item = xRingbufferReceive(rb, &size, 0)) != NULL)
    {
        ESP_LOGI(tag_c, "2: received message size %u from %p: %s", size, item, item);
        vRingbufferReturnItem(rb, item);
    }

    sprintf(&item_1[6], "world");
    xRingbufferSendComplete(rb, item_1);

    while ((item = xRingbufferReceive(rb, &size, 0)) != NULL)
    {
        ESP_LOGI(tag_c, "3: received message size %u from %p: %s", size, item, item);
        vRingbufferReturnItem(rb, item);
    }

    ESP_LOGI(tag_c, "done");

    while (1)
    {
        vTaskDelay(1000);
    }
}

void app_main(void)
{
    xTaskCreate(ringbuffer_test, "RB_TST", 4096, NULL, 0, NULL);
}

I ran the same code three times. Here are the results:

esp-idf v5.3 without the fix:

I (310) RB_TST: 1: received message size 15 from 0x3fc974e0
I (310) RB_TST: 1: received message size 15 from 0x3fc974f8
I (1320) RB_TST: 2: received message size 15 from 0x3fc974e0: Hello
I (1320) RB_TST: 3: received message size 15 from 0x3fc974f8: This is fine
I (1320) RB_TST: done

esp-idf v5.3 with the fix:

I (310) RB_TST: 1: received message size 15 from 0x3fc974e0
I (310) RB_TST: 1: received message size 15 from 0x3fc974f8
I (1320) RB_TST: done

esp-idf v5.3 with my own fix:

I (310) RB_TST: 1: received message size 15 from 0x3fc974e0
I (310) RB_TST: 1: received message size 15 from 0x3fc974f8
I (1320) RB_TST: 3: received message size 15 from 0x3fc974e0: Hello world
I (1320) RB_TST: 3: received message size 15 from 0x3fc974f8: This is fine
I (1320) RB_TST: done

It looks like the problem still happens after wraparound if there were any dummy bytes at the end of ringbuffer.

sudeep-mohanty · 2024-11-27T13:56:49Z

Thanks for reporting the issue @upolc-lg. We shall investigate it further. I'll re-open the ticket. Since you have done some investigation already, would you mind sharing your fix or creating a PR for us? Thanks!

james-corticallabs added the Type: Bug bugs in IDF label Sep 13, 2024

espressif-bot added the Status: Opened Issue is new label Sep 13, 2024

github-actions bot changed the title ~~Ringbuf: Acquiring entire ring buffer results in items being received prematurely~~ Ringbuf: Acquiring entire ring buffer results in items being received prematurely (IDFGH-13694) Sep 13, 2024

espressif-bot assigned sudeep-mohanty Sep 13, 2024

espressif-bot closed this as completed in 6a82497 Sep 19, 2024

sudeep-mohanty reopened this Nov 27, 2024

upolc-lg linked a pull request Nov 28, 2024 that will close this issue

fix(esp_ringbuf): Fixed no split buffer in case of wrap around with dummy data (IDFGH-14146) #14948

Open

6 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Ringbuf: Acquiring entire ring buffer results in items being received prematurely (IDFGH-13694) #14568

Ringbuf: Acquiring entire ring buffer results in items being received prematurely (IDFGH-13694) #14568

james-corticallabs commented Sep 13, 2024

sudeep-mohanty commented Sep 13, 2024

james-corticallabs commented Sep 20, 2024

sudeep-mohanty commented Sep 20, 2024

upolc-lg commented Nov 27, 2024

sudeep-mohanty commented Nov 27, 2024

Ringbuf: Acquiring entire ring buffer results in items being received prematurely (IDFGH-13694) #14568

Ringbuf: Acquiring entire ring buffer results in items being received prematurely (IDFGH-13694) #14568

Comments

james-corticallabs commented Sep 13, 2024

Answers checklist.

IDF version.

Espressif SoC revision.

Operating System used.

How did you build your project?

If you are using Windows, please specify command line type.

Development Kit.

Power Supply used.

What is the expected behavior?

What is the actual behavior?

Steps to reproduce.

Debug Logs.

More Information.

sudeep-mohanty commented Sep 13, 2024

james-corticallabs commented Sep 20, 2024

sudeep-mohanty commented Sep 20, 2024

upolc-lg commented Nov 27, 2024

sudeep-mohanty commented Nov 27, 2024