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

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

Closed
3 tasks done
james-corticallabs opened this issue Sep 13, 2024 · 6 comments · May be fixed by #14948
Closed
3 tasks done
Assignees
Labels
Resolution: NA Issue resolution is unavailable Status: Done Issue is done internally Type: Bug bugs in IDF

Comments

@james-corticallabs
Copy link

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:

  1. Acquire space for multiple items on a ring buffer using xRingbufferSendAcquire until the ring buffer is full.
  2. 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.
  3. 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.

  1. Create a no split ring buffer
  2. Create a task which reads from the ring buffer
  3. Acquire first item on the ring buffer using xRingbufferSendAcquire (labelled as item1 in the steps and code below)
  4. 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
  5. Write a value to item1
  6. 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.

@james-corticallabs james-corticallabs added the Type: Bug bugs in IDF label Sep 13, 2024
@espressif-bot espressif-bot added the Status: Opened Issue is new label Sep 13, 2024
@github-actions 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
@sudeep-mohanty
Copy link
Collaborator

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

@espressif-bot espressif-bot added Status: In Progress Work is in progress Status: Reviewing Issue is being reviewed Status: Done Issue is done internally Resolution: NA Issue resolution is unavailable and removed Status: Opened Issue is new Status: In Progress Work is in progress Status: Reviewing Issue is being reviewed labels Sep 16, 2024
@james-corticallabs
Copy link
Author

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

@sudeep-mohanty
Copy link
Collaborator

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

espressif-bot pushed a commit that referenced this issue Sep 22, 2024
…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
espressif-bot pushed a commit that referenced this issue Sep 24, 2024
…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
espressif-bot pushed a commit that referenced this issue Sep 25, 2024
…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
espressif-bot pushed a commit that referenced this issue Oct 16, 2024
…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
Copy link

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
Copy link
Collaborator

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!

@sudeep-mohanty
Copy link
Collaborator

Closing this issue. Fix to be evaluated under #14948.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Resolution: NA Issue resolution is unavailable Status: Done Issue is done internally Type: Bug bugs in IDF
Projects
None yet
4 participants