Skip to content
New issue

Have a question about this project? # for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “#”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? # to your account

Accidentally writing to file system when printing to stdout with ESP_LOGx() (IDFGH-12416) #13439

Closed
3 tasks done
voedipus opened this issue Mar 21, 2024 · 3 comments
Closed
3 tasks done
Assignees
Labels
Resolution: NA Issue resolution is unavailable Status: Done Issue is done internally Type: Bug bugs in IDF

Comments

@voedipus
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.

General issue report

Steps to reproduce:

  1. Select "None" as channel for console output
    image
  2. Open a file in file system with fopen() and see that it is opened with fileno = 0 (with debugging)
  3. Call fopen() once again(to open stdout with fileno = 1)
  4. Print something to stdout with ESP_LOGx()
  5. Read second opened file and see that ESP_LOGx() write there

If channel for console output is UART0 then fopen() opens first file with fileno = 3

@espressif-bot espressif-bot added the Status: Opened Issue is new label Mar 21, 2024
@github-actions github-actions bot changed the title Accidentally writing to file system when printing to stdout with ESP_LOGx() Accidentally writing to file system when printing to stdout with ESP_LOGx() (IDFGH-12416) Mar 21, 2024
@igrr
Copy link
Member

igrr commented Mar 21, 2024

@voedipus Would you mind posting the code you used in these two steps?

Open a file in file system with fopen() and see that it is opened with fileno = 0 (with debugging)
Call fopen() once again(to open stdout with fileno = 1)

Could you also mention the version of ESP-IDF you are using?

@voedipus
Copy link
Author

voedipus commented Mar 21, 2024

@igrr I used example project named "file_serving" with minor changes in app_main and changing channel console output to "None" in menuconfig:

void app_main(void)
{
    ESP_LOGI(TAG, "Starting example");
    ESP_ERROR_CHECK(nvs_flash_init());
    ESP_ERROR_CHECK(esp_netif_init());
    ESP_ERROR_CHECK(esp_event_loop_create_default());

    /* Initialize file storage */
    const char* base_path = "/data";
    ESP_ERROR_CHECK(example_mount_storage(base_path));

    /* This helper function configures Wi-Fi or Ethernet, as selected in menuconfig.
     * Read "Establishing Wi-Fi or Ethernet Connection" section in
     * examples/protocols/README.md for more information about this function.
     */
    ESP_ERROR_CHECK(example_connect());

    /* Start the file server */
    ESP_ERROR_CHECK(example_start_file_server(base_path));
    ESP_LOGI(TAG, "File server started");
    FILE* first = NULL;
    first = fopen("/data/test1.txt", "w");
    FILE* second = NULL;
    second = fopen("/data/test2.txt", "w");

    while (1){
        ESP_LOGE(TAG, "Is this written to FS?");
        vTaskDelay(200);
    }
}

As you can see I open 2 files(test1.txt and test2.txt) and write to stdout using ESP_LOGE()
image

There were no explicit writes to test2.txt, but it's size is more than 0

Contents of the test2.txt file
image

I was able to reproduce this bug using spiffs and littlefs using versions of esp-idf 5.1.2 and 5.2.1

@haberturdeur
Copy link
Collaborator

haberturdeur commented Apr 3, 2024

The issue seems to be that vfs doesn't reserve have "default" file descriptors 0 (STDIN), 1(STDOUT) and 2(STDERR):
So when the second file gets open it gets fd 1. Then vprintf in ESP_LOGX assumes that fd 1 is STDOUT, and writes to it...
image

Edit: Posix doesn't require the 0,1 and 2 file descriptors to be reserved, and after closing the original files these should be available for allocation and <stdion.h> functions should be bound to these fd's.

@espressif-bot espressif-bot added the Type: Bug bugs in IDF label Apr 3, 2024
@espressif-bot espressif-bot added Status: Selected for Development Issue is selected for development Status: In Progress Work is in progress and removed Status: Opened Issue is new Status: Selected for Development Issue is selected for development labels Apr 17, 2024
@espressif-bot espressif-bot added Status: Reviewing Issue is being reviewed Status: Done Issue is done internally Resolution: NA Issue resolution is unavailable and removed Status: In Progress Work is in progress Status: Reviewing Issue is being reviewed labels May 27, 2024
# for free to join this conversation on GitHub. Already have an account? # to comment
Labels
Resolution: NA Issue resolution is unavailable Status: Done Issue is done internally Type: Bug bugs in IDF
Projects
None yet
Development

No branches or pull requests

4 participants