NOR Flash becomes gradually slow over time

[quan1328]

Hi,

I'm developing my app on nRF52840, NCS2.7.0 on VS Code 1.100.0.

My application needs to save settings data (4 x int32_t ) to external the NOR Flash (mx25r64) in `settings_storage` partition defined in pm_static.yml (in the attached zip file) before system reboots.

I use this snippet to read the saved settings:

static int direct_loader_immediate_value(const char *name, size_t len,
										 settings_read_cb read_cb, void *cb_arg,
										 void *param)
{
	const char *next;
	size_t name_len;
	int rc;
	struct direct_immediate_value *one_value =
		(struct direct_immediate_value *)param;

	name_len = settings_name_next(name, &next);

	if (name_len == 0)
	{
		if (len == one_value->len)
		{
			rc = read_cb(cb_arg, one_value->dest, len);
			if (rc >= 0)
			{
				one_value->fetched = 1;
				LOG_INF("immediate load: OK.");
				return 0;
			}

			printk(FAIL_MSG, rc);
			return rc;
		}
		return -EINVAL;
	}

	/* other keys aren't served by the callback
	 * Return success in order to skip them
	 * and keep storage processing.
	 */
	return 0;
}

int load_immediate_value(const char *name, void *dest, size_t len)
{
	int rc;
	struct direct_immediate_value dov;

	dov.fetched = 0;
	dov.len = len;
	dov.dest = dest;

	rc = settings_load_subtree_direct(name, direct_loader_immediate_value,
									  (void *)&dov);
	if (rc == 0)
	{
		if (!dov.fetched)
		{
			rc = -ENOENT;
		}
	}

	return rc;
}

int main()
{
	int my_var= 0;
	(void)load_immediate_value("dfu", &my_var, sizeof(dfu_mode));
	printk("my_var: %d\\n", my_var);
}

and this to write:

void save_params()
{

		int some_var = 5
    settings_save_one("some_var", &some_var, sizeof(some_var));
    // and some more vars
    settings_save();
    LOG_INF("saved: %d", some_var);
}

I noticed that after ~100 times of writing, flash accessing (both reading and writing) becomes gradually slow: It can take up to 5-6 seconds to read 1 record of 4 bytes.

Erasing the settings partition in the NOR flash DOES help it recover, i.e. reading/writing becomes fast: 50-60 millisecond to read a record.

Is there something wrong in my snippets causing the external NOR flash getting slower over time? Why and how to fix this issue?

Best regards,

Quan

1643.Archive.zip

[Susheel Nuguru]

I think the issue is with your direct_loader_immediate_value callback function.

When you find your key you are doing a return 0, 

	if (name_len == 0)
	{
		if (len == one_value->len)
		{
			rc = read_cb(cb_arg, one_value->dest, len);
			if (rc >= 0)
			{
				one_value->fetched = 1;
				LOG_INF("immediate load: OK.");
				return 0;  // <--- This might be a bug
			}

When you return 0, you are telling your settings to keep searching according to the documentation here settings_load_direct_cb

Returns
When nonzero value is returned, further subtree searching is stopped.

So I think when you find your key, you should return non zero here instead of zero.

		if (len == one_value->len)
		{
			rc = read_cb(cb_arg, one_value->dest, len);
			if (rc >= 0)
			{
				one_value->fetched = 1;
				LOG_INF("immediate load: OK.");
				return 1;  // <--- FIXED stop the search now
			}

[quan1328]

Hi Susheel,

I agree with you about the non-zero value returned once it's found to stop further searching.

I made a new version that:

1. Apply you fix: `return 1` instead of zero once a value is found
2. Shrink the settings_storage partition in the external NOR flash from 2MiB down to 16KiB. Our application only has BLE stack (with pairing features) and ~20-30 bytes of our custom data, so I think 16KiB is good enough?

pm_static.yml.zip

Rerunning the test: reboot firmware every 20 seconds.

I still see flash access becoming gradually slow: for the first few times, it would take ~100ms, over time, it will increase to 200ms, 300ms, ...

My opinion:

Since `settings_save_one()` API uses NVS subsystem to store id-data pair, does this tear the NOR flash, causing wear leveling?

I mean that:

• App needs to save these pairs: `"some_var": 3`.
• Next time: when it saves `"some_var": 5` ️ actually, the API/driver will write to another space available, not the space at `"some_var": 3` => `"some_var":3` becomes zombie. Reason for this is because flash cannot switch from 0 -> 1 unless we erase it. (it can only switch from 1 -> 0 instead)
• When reading, the API/driver will scan through the zombie before it reaches the real value: `5`

Is this the scheme causing flash access getting slower and slower? How should we overcome this? Does Nordic has solution for this scheme?

Best regards,

Quan

[Susheel Nuguru]

Sorry for late reply Quan,

quan1328 said:

Rerunning the test: reboot firmware every 20 seconds.

The fix we did was necessary, so we need to understand what this reboot is. Can you please give me your minimalistic project so that I can quickly debug this? If you cannot give me your project then please put a breakpoint at sys_reboot in your project, start the debugger and wait until the breakpoint is hit. One hit, show us the functional call stack and we will then have enough info to understand the context of the reboot.

[quan1328]

Hi Susheel,

I'm trying to make a minimal project for you to grab the context quickly.

In the mean time, can you look at my other questions, opinion (about flash wear leveling)? Do you have some comments about them?

 Regards

[Susheel Nuguru]

quan1328 said:

In the mean time, can you look at my other questions, opinion (about flash wear leveling)? Do you have some comments about them?

There was a lot of thought put on flash wear leveling and the settings should take this into account by using sector rotation done by the NVS backend Old entries are not overwritten but they are appended , that is old values are still there but they become stake (old) until garbage collection is run to clean them. When you are reading the key value pair, the system always returns the most recent value as the old one becomes stale and irrelevant. 

If your nvs_storage have only one sector defined in your dts file, then the garbage collection will never be run. 

Just for the sake of example if I want to have 3 sectors for NVS (backend for settings when CONFIG_SETTINGS_NVS is enabled) then I will have this in my overlay file.

/ {
  chosen {
    ncs,storage = &nvs_storage;
  };
};

&flash0 {
  partitions {
    compatible = "fixed-partitions";
    #address-cells = <1>;
    #size-cells = <1>;

    nvs_storage: partition@f0000 {
      label = "storage";
      reg = <0x000f0000 0x3000>; // 3 flash sectors
    };
  };
};

Also have the NVS logs enabled so that you can see if garbage collection is called or not.

CONFIG_LOG=y
CONFIG_NVS_LOG_LEVEL_DBG=y

[quan1328]

HI Susheel,

Currently, we are having 16KiB `settings_storage` partition defined in pm_static.yml as I had updated with you in the previous thread. System log prints out confirming that we have 4 sectors:

[00:00:00.734,405] <inf> fs_nvs: 4 Sectors of 4096 bytes
[00:00:00.740,539] <inf> fs_nvs: alloc wra: 0, f08
[00:00:00.746,124] <inf> fs_nvs: data wra: 0, 354

 

The GC will be triggered automatically by the system? How, when will it be triggered? When triggered, how does it affect our application?

Unfortunately, I cannot give you the full source code of our project, but I can give you an overview of how my application reboots when it receives reboot event:

1. Reboot event is put to the work queue so that it will be processed later.
2. Once processed, it will proceed the following procedure:

 

static void reboot(uint8_t reason)
{
    disconnect_ecg_bluetooth("util");
    deinit_ecg_bluetooth();

    stop_data_thread();

    if (reason == ECG_REBOOT_REASON_BOND_DELETED_BY_APP ||
        reason == ECG_REBOOT_REASON_BOND_DELETED_BY_BUTTON)
    {
        erase_nor();
    }
    else
    {
        settings_save_one(KEY_REBOOT_REASON, &reason, sizeof(reason));
        save_params();
    }

    k_sleep(K_SECONDS(2));
    LOG_INF("Rebooting... with reason: %d", reason);
    sys_reboot(SYS_REBOOT_COLD);
}

void save_params()
{
    settings_save_one("NAddr", &NAND_Addr, sizeof(NAND_Addr)); // 4 bytes
    settings_save_one("PktNum", &Pkt_num, sizeof(Pkt_num)); // 4 bytes
    settings_save_one("NMode", &NAND_mode, sizeof(NAND_mode)); // 4 bytes
    if (NAND_mode == 1)
    {
        settings_save_one("NLen", &NOff_len, sizeof(NOff_len)); // 4 bytes
    }
    settings_save();

    LOG_INF("NAND params updated: 0x%04x %d %d %d",
            NAND_Addr,
            NAND_mode,
            NOff_len,
            Pkt_num);
}

As you may observe, we don't do anything special, we just save app's parameters to the external NOR flash at `settings_storage` partition.

Over time, NOR flash access is getting slower and slower. I created a test version, which I reboots the system ~2000 times using the reboot flow above, reading flash increases from ~40ms to ~400ms. 400ms is much better than 3s when I started this ticket, maybe because I have made 2 changes:

1. Apply your suggestion in `return 1` to prevent the driver from searching more. (Thanks a lot for this point)
2. Shrink the `settings_storage` partition from 2MiB down to 16KiB. Since it's smaller, GC has better "chance" to trigger itself to do its job?

Due to the nature of NOR flash key-value writing, getting slower over time is inevitable?

Regards,

Quan 

[quan1328]

Hi Susheel, 

Have you got any updates about my case? Please update me.

Thanks.

Quan