Esp-idf: WL FAT FS read file error (IDFGH-1063)

[no1seman]

Environment

• Development Kit: ESP32-Wrover-Kit
• Kit version (for WroverKit/PicoKit/DevKitC): v4.1
• Module or chip used: ESP32-WROVER-B
• IDF version (run git describe --tags to find it): v4.0-dev-461-g17a3bdb8c
• Build System: CMake
• Compiler version (run xtensa-esp32-elf-gcc --version to find it): 1.22.0-80-g6c4433a
• Operating System: Linux
• Power Supply: (USB|external 5V)&Battery

Problem Description

In my project i've creating fat fs via https://github.com/jkearins/ESP32_mkfatfs. This tool creates partition binary with WL FS v1 and after first mounting this partiton on device wl lib converts fs from v1 to v2.
After it some files, that was created by mkfatfs and burned during flash procedure are read and some new files are created (config.json). Everything works well even after reset (by button or by idf_monitor.py), but if i power off my dev board and power it again I'v got the following message: 'W (236) vfs_fat_spiflash: f_mount failed (13)' during boot.
If i set .format_if_mount_failed = true in mount_config where in esp_vfs_fat_spiflash_mount() returns 'ESP_OK', so in this case there is no way to determine if fs was mounted as is, or it was formated.
If i set .format_if_mount_failed = false in mount_config fs mounts without any warnings but i've got another porblem. Files, that was created by mkfatfs and burned during flash procedure reads without any problems, but files, that was created by my programm itself is not readable. Program opens a file (config.json), fopen, ftell, fseek, fread, fclose doesn't raise any errors but file is empty.

So, I can't understand why esp_vfs_fat_spiflash_mount() with .format_if_mount_failed = true not mounting fs but formats it while with .format_if_mount_failed = false it successfully mount fs? but files created on device is not readable.

Also there is a problem that esp_vfs_fat_spiflash_mount() and esp_vfs_fat_sdmmc_mount() doesn't return 'pdrv'. It will be very useful for futher usage of ff.h functions.

Expected Behavior

1. esp_vfs_fat_spiflash_mount must return a special return error if esp_vfs_fat_spiflash_mount can't mount fs and it was formated to have an ability to process that case.
2. After poweroff/poweron device all files on wl fs must be readable even they changed or not during previous device runs.
3. There must be a way to determine 'pdrv' (ff_diskio_register_wl_partition() registration number) that esp_vfs_fat_spiflash_mount() & esp_vfs_fat_sdmmc_mount() got during execution for further usage with ff.h functions.
4. If there any other more right way to create wl v2 fat fs binary from directory except ESP32_mkfatfs?

Actual Behavior

1. There is no ways to determine fs was mounted or formatted if .format_if_mount_failed = true in mount_config.
2. Files that was written by program running on device has no content after power off.
3. No way to get 'pdrv' from esp_vfs_fat_spiflash_mount() & esp_vfs_fat_sdmmc_mount().
4. https://github.com/jkearins/ESP32_mkfatfs generates only WL v1 FS and official documentation doesn't contain any descriptions of procedure to create WL v2 FS binary from folder on development system.

Steps to repropduce

1. make fat fs: mkfatfs -c ~/DIR_WITH_FILES_TO_PUT_INTO_FATFS_BINARY -s FS_SIZE ~/FAT_FS.bin
2. burn fat fs: esptool.py --chip esp32 --port /dev/ttyUSB0 --baud 921600 --before default_reset write_flash -z --flash_mode dio --flash_freq 40m --flash_size detect 0x0000000 ~/FAT_FS.bin
3. Mount fat fs via esp_vfs_fat_spiflash_mount()
4. Create new file, write some data to a new file and close it (do not unmount fs!!!)
5. Reset device via button or idf_monitor.py and check that all files readable
6. Fully poweroff the device, power on it again, wait for load and find out that file created on step 4 has zero size.

Code to reproduce this issue

esp_err_t flash_fs_mount(void)
{
ESP_LOGD(TAG, "Initializing SPI flash FS");
const esp_vfs_fat_mount_config_t mount_config = {
.max_files = 4,
.format_if_mount_failed = false,
.allocation_unit_size = 512};

esp_err_t ret = esp_vfs_fat_spiflash_mount(FLASH_FS_MOUNT_PATH, "storage", &mount_config, &s_wl_handle);
if (ret != ESP_OK)
{
    ESP_LOGE("SPI flash FS initialization error: %s", esp_err_to_name(ret));
    return ret;
}

return ESP_OK;
}

esp_err_t config_save_file(const char *filename)
{
FILE *fp;
fp = fopen(filename, "w");
if (fp != NULL)
{
char *config = "{"data":"some data"}";
fprintf(fp, "%s", config);
fclose(fp);
ESP_LOGI(TAG, "Config successfully saved");
if (config)
{
vPortFree(config);
config = NULL;
}
return ESP_OK;
}
ESP_LOGE(TAG, "Config save error!");
return ESP_FAIL;
}

Debug Logs

sdkconfig.zip

[dmitry1945]

Hi @no1seman Yaroslav,
Could you please look into the file /components/wear_levelling/WL_Flash.cpp
and check if the lines around line 370 are equal to these:

        this->state.version = 2;
        this->state.pos = 0;
        this->state.device_id = esp_random();
        memset(this->state.reserved, 0, sizeof(this->state.reserved));
        this->state.crc = crc32::crc32_le(WL_CFG_CRC_CONST, (uint8_t *)&this->state, WL_STATE_CRC_LEN_V2);

Or you have different one?

Thanks,
Dmitry

[no1seman]

@dmitry1945, my WL_Flash.cpp have the following code near 370-th line:
this->state.version = 2;
this->state.pos = 0;
this->state.device_id = esp_random();
memset(this->state.reserved, 0, sizeof(this->state.reserved));
this->state.crc = crc32::crc32_le(WL_CFG_CRC_CONST, (uint8_t *)&this->state, WL_STATE_CRC_LEN_V2);
File length: 27224 bytes and it's the same as latest master branch.

[dmitry1945]

@no1seman
thanks,
It's strange that you have this error.
I will look.
Thanks again.

Dmitry

[no1seman]

@dmitry1945, I have to say that i'm using also SD card simultaneously with SPI flash WL FS.
May be that is the root of the problem?

[dmitry1945]

@no1seman, I don't think so.
I will try to reproduce the problem. Then we will see. )

[dmitry1945]

@no1seman, By the way, Yaroslav, could you please provide me an fatfs image that you make, as a file to flash?

[no1seman]

@dmitry1945,
https://drive.google.com/file/d/10S7yFepZcDKdJGIYNm8W63OMY-2XSFM5/view?usp=sharing

[dmitry1945]

@no1seman Yaroslav,

Thank! )

[no1seman]

@dmitry1945,
seems to me that I found solution.
If I add setvbuf(fp, NULL, _IONBF, 0); before fprintf(fp, "%s", config); and fflush(fp); before fclose(fp); all begins to work perfectly.
Adding only fflush(fp); doesn't helps. So seems that the problem is in buffers fflush and/or file cache logic. When file closes by fclose() driver doesn't clean buffers/cache. In my opinion it's not proper behaivor, in GNU/Linux fclose() fixes all unwritten data to disk.

[dmitry1945]

@no1seman Yaroslav, thanks a lot!
Great work!
Thanks!

[no1seman]

@dmitry1945, today I'm tested fwrite() and it looks like that it has the same behavior. If you fwrite() some data and make fclose() after you can't get data written to the flash. Data will be avaible until device will not be off or correctly unmounted.
Are there any plans to fix it? Unbuffered writing is not a good way to write files...

[dmitry1945]

@no1seman Yaroslav, I will fix it soon. I hope even today.

Dmitry

[no1seman]

@dmitry1945, and whats about other problems:

1. utility to get v2 WL FAT FS binary?
2. Getting 'pdrv' of mounted fs?
3. Determining mounted or formatted fs if .format_if_mount_failed = true?

[dmitry1945]

@no1seman Hi Yaroslav,

I have tried to reproduce the error, and I'm not able to do this. I did it with SD card and without.
The simple application just waint 30 seconds, read file contents with expected name, if it exist, write file with the same name. Then reset (I do not call unmount).
.format_if_mount_failed = false,
Sector size is 512, mode - performance (safety also checked)

I do next:

1. Flash the application.
2. Flash your bin file.
3. Restart application (make monitor).
   I see next:

I (30452) example: Mounting FAT filesystem
I (30452) wl_flash: updateV1_V2 Update from V1 to V2, crc=0x0e06d47d,
I (30462) wl_flash: updateV1_V2 max_pos=505, pos=117, state.ver=1, state2.ver=1
I (30712) example: Reading file step 1
E (30712) example: Failed to open file for reading
I (30712) example: Opening file
I (31052) example: File written
I (31052) example: Unmounting FAT filesystem
I (31052) example: Done

I see expected error because file was not created up to now.
Then I switch off the board, switch on and restart it with (make monitor).
I see next:

I (30452) example: Mounting FAT filesystem
I (30462) example: Reading file step 1
I (30462) example: Read from file: 'written using ESP-IDF v4.0-dev-288-g83d2ff07
c-dirty'
I (30462) example: Opening file
I (30902) example: File written
I (30912) example: Unmounting FAT filesystem
I (30912) example: Done

Now I see the that file contains the data as expected.

I simply not able to reproduce your problem. Could you provide me the stack size that you are using for your operations?

V1 and V2 are converted internally and should not affect FS. For fatfs there is no difference.

Thanks,
Dmitry

[no1seman]

@dmitry1945,
seems to me that problem was in SPI_FLASH_ROM_DRIVER_PATCH. I'm using QIO flash SPI mode and, I didn't set it to =y, so file wrote to flash, but after full poweroff all written data was discarded. After switching on SPI_FLASH_ROM_DRIVER_PATCH=y all works fine. So the problem was not in WL FAT FS stack, but in SPI flash driver settings.
Thanks for your help.

P.S. There are some problems, I've mentioned in issues header:

1. There must be a way to determine 'pdrv' (ff_diskio_register_wl_partition() registration number) that esp_vfs_fat_spiflash_mount() & esp_vfs_fat_sdmmc_mount() got during execution for further usage with ff.h functions. s_pdrv is local in vfs_fat_sdmmc.c and theres no way to find out the driver registration number of sd card fs.
2. If there any other more right way to create wl v2 fat fs binary from directory except ESP32_mkfatfs?

[dmitry1945]

@no1seman Yaroslav,
Thanks and respect for the info.

About point 4.
The conversion from V1 to V2 not affect the file system and only take few milliseconds to update from 1 to 2, that's why we did not change it up to now. I think we will do this in future, but not now.

About 3 the same. We will think.

[no1seman]

@dmitry1945,
about point 4 - Ok, but point 3 - it's very uncomfortable. In my project i'm using both: SPI flash FS & SD card FS. If I need to use for example f_opendir() i can't use mount_path that I passed to esp_vfs_fat_sdmmc_mount() and for now the only way is to make own registration table. Why not to include s_pdrv into sdmmc_card_t structure?

[igrr]

Quoting the docs, esp_vfs_fat_sdmmc_mount is a convenience function. It is mainly intended to be used in example applications to make the code less verbose. It does very limited error checking, and developers are encouraged to look at its source code and incorporate more advanced versions into production applications. The steps which the application needs to take to use FATFS with an SD card are listed here: https://docs.espressif.com/projects/esp-idf/en/latest/api-reference/storage/fatfs.html#using-fatfs-with-vfs. This approach will also give you access to the pdrv value you are looking for.

On a related note, FATFS version 0.13b has added the ability to use a Unix-style path prefix as the volume name (via the FF_STR_VOLUME_ID configuration option). Once the version of FATFS used in IDF gets updated to the latest release, getting access to the pdrv might get easier. For example, esp_vfs_fat_sdmmc_mount may then set pdrv equal to the VFS mount point (base_path), which would be more transparent for the application.

[no1seman]

@igrr, thanks for comments? I'll try to. Closing issue.