Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

Settings FS: Duplicate finding is extremely slow when dealing with larger number of settings entries #34554

Closed
optical-o opened this issue Apr 25, 2021 · 19 comments
Assignees
Labels
area: Settings Settings subsystem bug The issue is a bug, or the PR is fixing a bug priority: low Low impact/importance bug Stale Waiting for response Waiting for author's response

Comments

@optical-o
Copy link
Contributor

The settings backends are trying to save write/erase cycles by storing duplicate settings entries and later resolving their duplicates by using the latest entry.

It should also include duplicate free storing and loading settings from memory. (Overwriting the whole settings when saving) The loading would be much faster then loading. Or at-least it should not resolve duplicates when loading the settings when it is resolved when saving it.

When settings reaches 30-60 options the duplicate resolution reaches nearly 10s of loading time. This process can be repeated multiple times if user is using settings_load_subtree due to some limitation such as loading bt settings before application settings.

I have been able to change boot time in my application from 60s to 5s by disabling the duplicate checking during settings load.
I had 2x settings_load_subtree and single settings_load.

@optical-o optical-o added the bug The issue is a bug, or the PR is fixing a bug label Apr 25, 2021
@Laczen
Copy link
Collaborator

Laczen commented Apr 26, 2021

@optical-o, indeed 60s seems like a long boot time.

However it is not possible to reduce the load time without introducing a lot of wear in flash. When settings save is called it will only save something when it is changed, that is why a save will take a longer time. The result of the save will be a file that contains multiple items for the same settings entry.

Loading the setting will need to go trough the complete file to find the latest written value. If this is not done older values will be restored. So it is not possible to disable the duplicate settings checking during load.

The load time can be reduced by creating a new file with settings from each settings store, but this increases flash wear. Another way to avoid this would be to process the settings file from the end to the start, but even in this case the settings_load would need to process the whole file. Processing from the end to the start could reduce the settings load subtree (but only in the case it needs to load ONE setting, when multiple settings need to be restored from a subtree it is needed to process the complete file).

To reduce the boot time the best approach is to reduce the number of calls to settings_load. To do this it would be best if a subsystem (bt) does not call settings_load, but the loading is delayed until everything is setup to call the settings_load one time from the application.

@de-nordic de-nordic added the area: Settings Settings subsystem label Apr 26, 2021
@de-nordic
Copy link
Collaborator

@optical-o Can you give some more details on backends you have been testing and the flash device that you use?

@optical-o
Copy link
Contributor Author

I'm using nrf9160 chip with 16Mbit macronix flash - MX25 clocked at 8Mhz.
prj.conf for Settings backends is:

CONFIG_SETTINGS=y
CONFIG_SETTINGS_DYNAMIC_HANDLERS=n
CONFIG_SETTINGS_RUNTIME=y
CONFIG_FILE_SYSTEM=y
CONFIG_SETTINGS_FS=y
CONFIG_SETTINGS_FS_FILE="/settings/zephyr_settings/settings"
CONFIG_SETTINGS_FS_DIR="/settings/zephyr_settings"

I understand that the wear on the flash is significant, however i think that settings changing is very rare occasion for most of the devices. The loading is done during every boot sequence, which is much critical part of the settings implementation and should be as quick as possible.
Even with singular settings_load the load time reaching 20s is really bad. The duplicate could be optimized so that it does not search entire file for every key loaded, by loading the entire file into the memory.

@optical-o
Copy link
Contributor Author

Regarding my Runtime storage it is simple array containing the settings, key and value.
The h_set and h_get function only searchers this runtime table for the key and sets/gets the value.

I have some macros to help me with the table definitions.
Such as:

static struct dt_settings_entry settings_table[] = {
    DT_CONF_ROW_B(ant_ext, dt_bt_adv_ant_sel),
    DT_CONF_ROW_I(adv_tx_pwr, NULL),
    DT_CONF_ROW_B(adv_coded, NULL),
    DT_CONF_ROW_B(adv_leg_en, NULL),
    DT_CONF_ROW_B(adv_ea_en, NULL),
    DT_CONF_ROW_I(odid_basic_int, NULL),
    DT_CONF_ROW_I(odid_loc_int, NULL),
    DT_CONF_ROW_B(odid_ea_basic_packed, NULL),
    DT_CONF_ROW_S(odid_operator, NULL),
    DT_CONF_ROW_END  /* Terminating entry */
};

Each table is defined as its own subtree.

@de-nordic
Copy link
Collaborator

Which file system do you have mounted at /settings?

@optical-o
Copy link
Contributor Author

I have mounted littlefs with configuration:

FS_LITTLEFS_DECLARE_DEFAULT_CONFIG(littlefs_settings_config);
static struct fs_mount_t littlefs_settings_mnt = {
    .type = FS_LITTLEFS,
    .fs_data = &littlefs_settings_config,
    .storage_dev = (void *)FLASH_AREA_ID(external_settings),
    .mnt_point = "/settings"
};

prj.conf - CONFIG_FILE_SYSTEM_LITTLEFS with other default settings.

I have tried to increase some ram buffers for the littlefs in hope of caching the file inside the memory to decrease the boot time with no luck. The Cache options had little or no effect on the load time.

@Laczen
Copy link
Collaborator

Laczen commented Apr 26, 2021

I'm using nrf9160 chip with 16Mbit macronix flash - MX25 clocked at 8Mhz.
prj.conf for Settings backends is:

CONFIG_SETTINGS=y
CONFIG_SETTINGS_DYNAMIC_HANDLERS=n
CONFIG_SETTINGS_RUNTIME=y
CONFIG_FILE_SYSTEM=y
CONFIG_SETTINGS_FS=y
CONFIG_SETTINGS_FS_FILE="/settings/zephyr_settings/settings"
CONFIG_SETTINGS_FS_DIR="/settings/zephyr_settings"

I understand that the wear on the flash is significant, however i think that settings changing is very rare occasion for most of the devices.

Unfortunately, that is not true, in bt-mesh application every (received) communication requires storing data for replay protection, this is done using settings. The flash wear would be unacceptable.

The loading is done during every boot sequence, which is much critical part of the settings implementation and should be as quick as possible.

That is also questionable, the critical part is the storage where you would like to make sure that you have stored the data when a unforeseen power failure happens.

Even with singular settings_load the load time reaching 20s is really bad. The duplicate could be optimized so that it does not search entire file for every key loaded, by loading the entire file into the memory.

I agree that 20s is really bad, I have no experience with littlefs but this seems very slow. In your use case the worst condition that could appear is that it has to proces 60 + 59 + 58 + ... + 1 = 30 * 30.5 = 915 line reads (this is theoretical), resulting in about 20ms per line read. Maybe @de-nordic has more experience with this.

To reduce the loading time you could reduce the number of lines in the file before compacting happens. If you would set it equal to the number of parameters you would like to store you would create a new file for every store and achieve the behaviour you are trying to get.

@Laczen
Copy link
Collaborator

Laczen commented Apr 26, 2021

@optical-o, BTW you are not by accident or intentionally calling a save settings during the loading ?

@optical-o
Copy link
Contributor Author

I have check again to be sure, but no.

I tested if i omit call inside settings_fs: settings_file_load_priv.
If i commented settings_file_check_duplicate then the boot time shorten by mentioned 53 seconds.

Currently i added to my code option CONFIG_SETTINGS_FS_NO_DUP which disables the settings_file_check_duplicate call.

		if (filter_duplicates &&
		    (!read_entry_len(&entry_ctx, name_len+1) ||
		     settings_file_check_duplicate(&entry_ctx, name))) {
			pass_entry = false;
		}

And in save function clears the whole file. This is only temporary solution for now. I'm missing indication that something in settings changed so that i know if i have to call settings_save when the device is turning off. So now the file is clear every time device turns off, which is no means ideal.

@Laczen
Copy link
Collaborator

Laczen commented Apr 26, 2021

@optical-o, could you test again with only disabling the check duplicate during settings_file_load_priv(). I am wondering if something is failing in the check_duplicate().

@de-nordic
Copy link
Collaborator

@optical-o, could you test again with only disabling the check duplicate during settings_file_load_priv(). I am wondering if something is failing in the check_duplicate().

Can you also check the settings subsystem performance with other backend (nvs for example?)

@optical-o
Copy link
Contributor Author

I will try to create some sample demonstrating. However it will be probably next week due to some deadlines i have to meet.

@ioannisg ioannisg changed the title Settings FS: Duplicite finding is extremely slow when dealing with larger number of settings entries Settings FS: Duplicate finding is extremely slow when dealing with larger number of settings entries Apr 27, 2021
@ioannisg ioannisg added the priority: low Low impact/importance bug label Apr 27, 2021
@carlescufi carlescufi added the Waiting for response Waiting for author's response label May 11, 2021
@carlescufi
Copy link
Member

I will try to create some sample demonstrating. However it will be probably next week due to some deadlines i have to meet.

@optical-o could you please provide the sample so we can look into this?

@carlescufi carlescufi added this to the v2.6.0 milestone May 11, 2021
@Laczen
Copy link
Collaborator

Laczen commented May 11, 2021

@carlescufi, @de-nordic, @optical-o, maybe this is related to CONFIG_SETTINGS_FS_MAX_LINES. If anything during start up does a write (and I guess bt does this) compression is called with the described properties. @optical-o could you retry by increasing MAX_LINES (e.g 100)?

@galak galak removed this from the v2.6.0 milestone Jun 4, 2021
@carlescufi
Copy link
Member

@Laczen could be, yes. @optical-o please update based on the feedback above.

@github-actions
Copy link

This issue has been marked as stale because it has been open (more than) 60 days with no activity. Remove the stale label or add a comment saying that you would like to have the label removed otherwise this issue will automatically be closed in 14 days. Note, that you can always re-open a closed issue at any time.

@optical-o
Copy link
Contributor Author

optical-o commented Jan 21, 2022

Issues are:

  1. settings_file opens and closes file for each writen value. It does not utilizes csi_save_start and csi_save_end
  2. settings_file each time it writes a value seek till the end of file, little fs flushes write operation on seek.

These changes changed saving time from 14s->200ms.

@Laczen
Copy link
Collaborator

Laczen commented Jan 21, 2022

@optical-o, could you create a PR with the proposed changes ?

How do you guarantee that after a settings_save has been succesfully performed that a reboot contains the updated values ?

@optical-o
Copy link
Contributor Author

optical-o commented Jan 21, 2022

The csi_save_end will close the file and flush the value. When settings_save finishes then the values will be in the flash.

If the reboot occurs during function call of settings_save before the csi_save_end the data will be lost.
However, i think that is intended behavior, isn't it ?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area: Settings Settings subsystem bug The issue is a bug, or the PR is fixing a bug priority: low Low impact/importance bug Stale Waiting for response Waiting for author's response
Projects
None yet
Development

No branches or pull requests

7 participants