esp_littlefs icon indicating copy to clipboard operation
esp_littlefs copied to clipboard

Loss of Open Files on Power Loss or Reset

Open justintconroy opened this issue 2 years ago • 15 comments

I'm not sure if this is a problem with this project, or with littleFS itself, but I'm going to start here.

The main problem is that I have files open when resetting the device. When I try to open the files again after reboot, the files appear to be empty. It doesn't really matter how much data is written. As long as the file stream isn't closed, the data is lost. Doing the same set of steps with SPIFFS, the data is not lost.

Here's as minimal of a repro as I can get. Run this, then hit the reset on the ESP32. Expected behavior is that the first read would read what was written in the previous run. Actual behavior is that it prints nothing and reports a 0 byte file size.

#include "lipsum.h" // This just contains the char* lipsum, which is a bunch of lorem ipsum.

#include <fstream>
#include <esp_littlefs.h>
#include <freertos/FreeRTOS.h>
#include <freertos/task.h>

#ifdef __cplusplus
extern "C" void app_main(void);
#endif

void app_main(void) {
  esp_vfs_littlefs_conf_t cfg;
  cfg.base_path              = "/lfs";
  cfg.partition_label        = "littlefs";
  cfg.format_if_mount_failed = true;
  cfg.dont_mount             = false;
  esp_vfs_littlefs_register(&cfg);

  std::fstream strm;
  strm.open("/lfs/lips.txt",
            std::fstream::in | std::fstream::out | std::fstream::app);

  printf("tellp:%d tellg:%d\n", (int)strm.tellp(), (int)strm.tellg());

  // Read.
  strm.seekg(0);
  char* data = (char*)malloc(10000);
  auto len   = strm.readsome(data, 10000);
  printf("Reading %d bytes.\n", len);

  data[len] = '\0';
  printf("%s\n", data);

  // Write.
  strm.write(lipsum, 2048);
  strm.flush();

  // strm.close();

  // Delay forever so the stream doesn't go out of scope and close
  // automatically.
  vTaskDelay(portMAX_DELAY);
}

If you uncomment // strm.close(); at the end, or remove the vTaskDelay(...), this code works as expected.

For what it's worth, my real-life use case here is for saving logs to the filesystem. Losing everything that was logged at every reset is no bueno. :-/

justintconroy avatar Dec 09 '21 17:12 justintconroy

A couple other observations which may or may not be relevant to this ticket. It might be appropriate to create additional issues for these:

  • If we move the "read" to happen after the "write", using the same stream, this read also fails.
    • In the version where we close the stream at the end, the same read only fails to read what was most recently written. That is, run 1 writes 2048 bytes, reads 0 bytes. Run 2 writes another 2048 bytes (total of 4096 bytes written), reads 2048 bytes.
    • If we close, and then re-open the stream, it works as expected.
  • seekg()/seekp() and tellg()/tellp() seem to both affect the same internal pointer. That is, if we change the input position, the output position is also changed. tellg() and tellp() always return the same value.
  • If I dump flash after writing to a file stream without closing it and analyze it, it looks like data is actually written to flash, but maybe invalid. I'm not familiar enough with the internals of littleFS to actually tell what is and isn't valid data, but I can find the text that should have been written in the dump.

justintconroy avatar Dec 09 '21 17:12 justintconroy

I think you just need to call strm.sync(). See:

https://github.com/littlefs-project/littlefs/issues/370

BrianPugh avatar Dec 09 '21 18:12 BrianPugh

I added a call to strm.sync() immediately after the strm.flush() in the above example. This made no difference in the outcome.

justintconroy avatar Dec 09 '21 18:12 justintconroy

I also tried the case of moving the read after the write (and the call to sync()), and that also is still failing.

justintconroy avatar Dec 09 '21 18:12 justintconroy

are you seeking before reading? What kind of errors are you seeing?

BrianPugh avatar Dec 09 '21 18:12 BrianPugh

Yes, I call strm.seekg(0) just before attempting to read with strm.readsome(...). strm.rdstate() returns 0 after every operation on the stream. strm.sync() also returns 0. So, no errors.

justintconroy avatar Dec 09 '21 19:12 justintconroy

@BrianPugh Any more insight on this issue?

justintconroy avatar Dec 13 '21 19:12 justintconroy

the seekg/seekp/tellg/tellp issue is a limitation of upstream littlefs. As far as syncing to disk, no idea what could be causing your issues

BrianPugh avatar Dec 13 '21 19:12 BrianPugh

Were you able to reproduce it with the code snippet I provided above?

justintconroy avatar Dec 13 '21 19:12 justintconroy

I haven't had a chance to test this, i'll try to when i get a chance.

BrianPugh avatar Dec 13 '21 19:12 BrianPugh

@BrianPugh Is this still on your radar? It would be nice if we can get this resolved. Let me know if there's anything I can do to help.

justintconroy avatar Jan 14 '22 19:01 justintconroy

yeah sorry, been busy with the holidays and work. I'll try and reproduce it this weekend, but not sure if there will be any actionable items. It's PROBABLY an upstream issue, but i'll try and verify that its not something wrong with my port.

BrianPugh avatar Jan 14 '22 20:01 BrianPugh

@BrianPugh I'm also interested in this topic. Any insight or pointers you can provide? Based on littlefs documentation, I wasn't expecting this behavior but I may be misunderstanding something.

abarangan avatar Feb 04 '22 18:02 abarangan

Note that we were eventually able to work around this issue by using file pointers instead of streams. Using fflush and fsync works for persisting the files through reboots without first needing to close the file.

justintconroy avatar Aug 05 '22 16:08 justintconroy

During extensive testing I recognized sometimes an fsync is not enough to have all data actually written. Because we are working with small blocks of data (64 bytes), I had to artificially flood the buffer when I really want to have all data written:

void LOG_QuickSync(bool bFloodBuffer)
{
  if (logFileWriteHandle != NULL)
  {
    if (bFloodBuffer)
    {
      /* Fill Cache with enough data that definitely all events are written. */
      static const uint8_t DataBufferFiller[CONFIG_LITTLEFS_WRITE_SIZE] = {0};
      fwrite((void *) DataBufferFiller, sizeof(uint8_t), sizeof(DataBufferFiller), logFileWriteHandle);
      ESP_LOGI(TAG, "Forced quick sync for up-to-date log done!");
    }
    fsync(fileno(logFileWriteHandle));
  }
}

All tests with different littlefs configurations (changed PAGE, READ, WRITE, LOOKAHEAD and CACHE size) did not help. So I am posting this here that it might resolve the problem for others - or maybe someone comes up with a solution that the workaround is not needed.

M-Bab avatar Aug 25 '22 07:08 M-Bab