NVS as a ring logger

nicolasludwig
Posts: 4
Joined: Tue Jan 21, 2025 12:34 pm

NVS as a ring logger

Postby nicolasludwig » Tue Jan 21, 2025 1:40 pm

Hello everyone!

I'm trying to use NVS as a ring logger in my project. I've already written all the code manually to accept 10 logs, each of them being a small string with a timestamp and a code (yes, I know NVS is not recommended for storing strings/blobs, but considering that the strings are short and I only want 10 entries, I think it's "acceptable"). In the worst case, about 30 logs will be written per day.

The problem is that the entire NVS partition is being filled with the logs, even when I update an existing key (my keys are hardcoded 0 to 9). I realized it by reading the ESP32 flash with esptool. So, when the partition reaches the end, I'm forced to erase the entire partition before continuing to read/write the partition, otherwise my code simply stops running because the partition doesn't initialize, it keeps returning ESP_ERR_NVS_NO_FREE_PAGES.

How can I avoid having to erase all the partition (I can't lose the previous data)?
Even if the partition is being filled to the end of its size, shouldn't the already filled entries have a flag bit, or something like that, so that the API understands that the data at that memory address can be rewritten?

I'd be very happy if someone could help me with this situation!

PS: I can't change the NVS method to another one, because my partitions are configured like this:

Code: Select all

# Name, Type, SubType, Offset, Size, Flags
nvs,data,nvs,0xb000,16K,
otadata,data,ota,0xf000,8K,
phy_init,data,phy,0x11000,4K,
nvs_key,data,nvs_keys,0x12000,8K,
credentials,data,nvs,0x14000,1M,
temp,data,nvs,0x114000,1072K,
factory,app,factory,0x220000,4M,
ota_0,app,ota_0,0x620000,4M,
ota_1,app,ota_1,0xa20000,4M,
Here's part of my code that implements the ring logger:

Initialization in main (code is encrypted):

Code: Select all

esp_err_t BravasLogInit()
{
    esp_err_t err;
    nvs_sec_cfg_t cfg;
    size_t crypt_efuse_bits = 0;

    // Check number of bits set in eFuse FLASH_CRYPT_CNT
    esp_efuse_read_field_cnt(ESP_EFUSE_FLASH_CRYPT_CNT, &crypt_efuse_bits);

    if (crypt_efuse_bits % 2 != 0) // If odd number of bits set: flash encrypted
    {
        ESP_LOGW(TAG, "Flash encrypted. Starting NVS by finding nvs_key partition.");

        // Find partition with nvs_keys
        const esp_partition_t *partition = esp_partition_find_first(ESP_PARTITION_TYPE_DATA,
                                                                ESP_PARTITION_SUBTYPE_DATA_NVS_KEYS,
                                                                "nvs_key");
        
        if (partition == NULL) {
            ESP_LOGE(TAG, "Could not locate nvs_key partition.");
            return ESP_FAIL;
        }

        // Read nvs_keys from key partition
        err = nvs_flash_read_security_cfg(partition, &cfg);
        if (err != ESP_OK) {
            ESP_LOGE(TAG, "Failed to read nvs keys (rc=0x%x)", err);
            return err;
        }

        // Initialize nvs partition
        err = nvs_flash_secure_init_partition("temp", &cfg);
        if (err == ESP_ERR_NVS_NO_FREE_PAGES || err == ESP_ERR_NVS_NEW_VERSION_FOUND) {
            // NVS partition was truncated and needs to be erased
            // Retry nvs_flash_init
            ESP_ERROR_CHECK(nvs_flash_erase_partition("temp"));
            err = nvs_flash_secure_init_partition("temp", &cfg);
        }
        if (err != ESP_OK) {
            ESP_LOGE(TAG, "Failed to initialize nvs partition (err=0x%x).", err);
            return err;
        };
    }
    else // Even number of bits set or zero: flash not encrypted
    {
        ESP_LOGW(TAG, "Flash not encrypted. Starting NVS.");

        err = nvs_flash_init_partition("temp");
        if (err == ESP_ERR_NVS_NO_FREE_PAGES || err == ESP_ERR_NVS_NEW_VERSION_FOUND) {
            // NVS partition was truncated and needs to be erased
            // Retry nvs_flash_init
            ESP_ERROR_CHECK(nvs_flash_erase_partition("temp"));
            err = nvs_flash_init_partition("temp");
        }
        ESP_ERROR_CHECK( err );
    }

    // Open (default for both encrypted or not)
    ESP_LOGI(TAG, "Opening Non-Volatile Storage (NVS) handle... ");
    err = nvs_open_from_partition("temp", "logNamespace", NVS_READWRITE, &log_nvs_handle);

    return err;
}
Function that saves the logs (SaveTempLog), where "lastIndex" stores the next index of the ring logger and "key" just copies the number to a string.

Code: Select all

#define MAX_LOG_SIZE 9
#define MAX_STR_LOG_SIZE 128

esp_err_t SaveTempLog(uint8_t type, char *data, int64_t timestamp)
{
    esp_err_t err;
    uint32_t index;
    char key[10];
    char log[MAX_STR_LOG_SIZE];
    size_t log_size;

    log_size = GetDataLog(type, data, timestamp, log);

    if (log_size >= MAX_STR_LOG_SIZE)
    {
        ESP_LOGW(TAG, "Log data size greater than %d.", MAX_STR_LOG_SIZE);
        return ESP_FAIL;
    }

    //Get index to be stored
    if (nvs_get_u32(log_nvs_handle, "lastIndex", &index) != ESP_OK)
    {
        index = 0;
    }

    //ESP_LOGI(TAG, "Last index: %ld", index);

    //Store log event
    sprintf(key, "%ld", index);
    ESP_LOGI(TAG, "Storing log \"%s\" at index %ld.", log, index);
    err = nvs_set_str(log_nvs_handle, key, log);
    if (err != ESP_OK)
    {
        ESP_LOGW(TAG, "Storing log event failed.");
        return err;
    }

    //Increase index value
    if (++index > MAX_LOG_SIZE)
    {
        index = 0;
    }
    err = nvs_set_u32(log_nvs_handle, "lastIndex", index);
    if (err != ESP_OK)
    {
        ESP_LOGW(TAG, "Increasing index value failed.");
        return err;
    }

    err  = nvs_commit(log_nvs_handle);
    if (err != ESP_OK)
    {
        ESP_LOGW(TAG, "Failed to commit logs.");
        return err;
    }

    ESP_LOGI(TAG, "New logs commited.");

    return err;
}

size_t GetDataLog(uint8_t type, char *data, int64_t timestamp, char *output)
{
    char *data_str = NULL;
    size_t data_str_size = 0;
    size_t output_size = 0;

    data_str_size = GetDataLogSize(type);
    if (data_str_size <= 0)
    {
        return MAX_STR_LOG_SIZE;
    }

    data_str = malloc(data_str_size + 1); //+1 for '\0'
    snprintf(data_str, data_str_size + 1, "%s", data);

    if (strlen(data) > data_str_size)
    {
        ESP_LOGW(TAG, "Data size > max allocated.");
    }

    output_size = snprintf(output, MAX_STR_LOG_SIZE, LOG_DATA_FORMAT, timestamp, type, data_str);
    free(data_str);
    return output_size;
}

size_t GetDataLogSize(uint8_t type)
{
    uint16_t i;
    uint16_t LogTableArraySize = sizeof(LogTableArray) / sizeof(LogTableArray[0]);

    for (i = 0; i < LogTableArraySize; i++)
    {
        if (LogTableArray[i].type == type)
        {
            return LogTableArray[i].max_size;
        }
    }
    return 0;
}

MicroController
Posts: 1954
Joined: Mon Oct 17, 2022 7:38 pm
Location: Europe, Germany

Re: NVS as a ring logger

Postby MicroController » Tue Jan 21, 2025 4:12 pm

nicolasludwig wrote:
Tue Jan 21, 2025 1:40 pm
The problem is that the entire NVS partition is being filled with the logs, even when I update an existing key (my keys are hardcoded 0 to 9).
That's not a problem, it's a feature called wear-levelling.
So, when the partition reaches the end, I'm forced to erase the entire partition before continuing to read/write the partition, otherwise my code simply stops running because the partition doesn't initialize, it keeps returning ESP_ERR_NVS_NO_FREE_PAGES.
Have you tried? NVS's wear-levelling should take care of automatically erasing pages of stale data when needed.

The actual problem may be that your NVS partition originally was not big enough. NVS needs at least 3 pages of flash memory to work with, i.e. 3x4kB = 12kB.

nicolasludwig
Posts: 4
Joined: Tue Jan 21, 2025 12:34 pm

Re: NVS as a ring logger

Postby nicolasludwig » Tue Jan 21, 2025 4:45 pm

Thanks for your response!
Have you tried? NVS's wear-levelling should take care of automatically erasing pages of stale data when needed.
Yes. I kept my hardware logging for several days, and yesterday I noticed that it was rebooting continuously. The root cause was NVS initialization which was returning ESP_ERR_NVS_NO_FREE_PAGES. So, to solve the problem, I wrote this condition right after the nvs_flash_secure_init_partition function, and then the hardware started working normally again, except my entire partition was erased.

Code: Select all

if (err == ESP_ERR_NVS_NO_FREE_PAGES || err == ESP_ERR_NVS_NEW_VERSION_FOUND) {
            // NVS partition was truncated and needs to be erased
            // Retry nvs_flash_init
            ESP_ERROR_CHECK(nvs_flash_erase_partition("temp"));
            err = nvs_flash_secure_init_partition("temp", &cfg);
        }
The actual problem may be that your NVS partition originally was not big enough. NVS needs at least 3 pages of flash memory to work with, i.e. 3x4kB = 12kB.
I'm using the "temp" partition for logging, not "nvs". It's 1072KB (over 1MB).

MicroController
Posts: 1954
Joined: Mon Oct 17, 2022 7:38 pm
Location: Europe, Germany

Re: NVS as a ring logger

Postby MicroController » Tue Jan 21, 2025 9:21 pm

about 30 logs will be written per day
logging for several days
partition for logging, not "nvs". It's 1072KB
There must be something else going wrong. 1072kB/(10days*30entries/day) ~ 3.4kB/entry. You shouldn't be able to fill up a 1MB NVS partition in 10 days with MAX_STR_LOG_SIZE 128.

nicolasludwig
Posts: 4
Joined: Tue Jan 21, 2025 12:34 pm

Re: NVS as a ring logger

Postby nicolasludwig » Wed Jan 22, 2025 11:52 am

The hardwares (about five) that experienced this situation had more than 30 logs/day, because some events were triggered (many of them) during tests. Also, the max length of the logs does not exceed 20 characters each. Yet, each hardware continued working for a month before this.

I'm still trying to figure out how this happened and how to prevent it without erasing the entire partition.

Who is online

Users browsing this forum: Google [Bot] and 106 guests