Best way to avoid recursion in Zephyr when enabling logging to backend with littlefs to flash memory

[jthmp]

We are working on an nrf54l15dk board but want to log directly to the nrf flash memory (instead of the ext flash) - which we are doing successfully.

In Zephyr we have logging to backend enabled working so any call to LOG_ERR, LOG_INF ...etc gets directly stored in our flash memory (littlefs).

However, we want to avoid a situation where the low level flash code (whether this is the SPI or internal flash code) get's into a recursive loop if it tries to call a LOG function within the flash driver code itself.

Is this handled already by Zephyr (4.1.99) and nordic and what is the best way to work around this?
Obviously disabling FS logging (CONFIG_FS_LOG_LEVEL_OFF=y) will prevent this, but we would prefer seeing those in the shell terminal if possible.

Here is a snippet of the prj.conf that relates to what we are doing:

# Logging
CONFIG_LOG=y
CONFIG_LOG_CMDS=y

# Enable the FS log backend
CONFIG_LOG_MODE_DEFERRED=y
CONFIG_LOG_BACKEND_FS=y
CONFIG_LOG_BACKEND_FORMAT_TIMESTAMP=y
CONFIG_LOG_BACKEND_FS_AUTOSTART=y
CONFIG_LOG_BACKEND_FS_DIR="/lfs"
CONFIG_LOG_BACKEND_FS_FILE_SIZE=4096  
# Increase log processing thread stack (try 4096 first, bump to 8192 if needed)
CONFIG_LOG_PROCESS_THREAD_STACK_SIZE=4096


# Disable nrf54 dk qspi flash chip so we can use the default nrf54 flash for littlefs
CONFIG_SPI_NOR=n 

# littlefs flash support
CONFIG_FLASH=y
CONFIG_FLASH_MAP=y
CONFIG_FILE_SYSTEM=y
CONFIG_FILE_SYSTEM_LITTLEFS=y

[Elfving]

Hi Joshua, 

So after a quick look it seems to me as if you could use two backends (LOG_BACKEND_UART and LOG_BACKEND_FS) and then filter for a certain module at a given backend. Let me know if that works for you, otherwise I have to get back to you next week.

Regards,

Elfving

[jthmp]

Hi Elfving, 

Yes that's a great idea. Is there example code for this?

Also, is there a correct way to handle if the flash driver / low level code fails and 'fs_write' starts returning errors? Since it will lock up the firmware and we would like to catch this and disable the backend if that happens.

[Elfving]

jthmp said:

Yes that's a great idea. Is there example code for this?

Looks like there is some use of it in this sample that you can have a look at. 

jthmp said:

Also, is there a correct way to handle if the flash driver / low level code fails and 'fs_write' starts returning errors? Since it will lock up the firmware and we would like to catch this and disable the backend if that happens

I am bit uncertain about this, but the samples for handling flash drivers would typically show a good workflow for handling the potential issues that comes with it as well. Have you had a look at the checks that are being done in the samples?

Regards,

Elfving

[jthmp]

Hi Elfving,
We used the samples as a starting point, but since we are using backend logging there is no example I could find that is addressing our use case:

Every time we use something like LOG_INF, or LOG_WRN it gets stored in a ext or internal flash memory. Looking at the zephyr code 'log_backend_fs.c' it seems like there is no contingency for detecting a persistent fs_write error. 

Because of this the firmware seems to get stuck if the flash IC no longer responds. But we really need Zephyr to simply disable the backend logger if this happens so the firmware can continue to run and just not attempt logging to flash memory.

I had to update the zephyr log_backend_fs.c code to detect continuous errors from the fs_write and then disable the backend logger. However, I would obviously rather use something that Zephyr put in place for such a case. 

If there isn't anything that's fine, I just wanted to make sure I wasn't duplicating work.

[jthmp]

Hi Elfving,
I've found an issue with our flash failure test. We've observed the following:
1. if we prevent the little fs flash write from working only (read still works) then the system hangs
2. if we prevent both the flash read and write from working the the backend logger code successfully disables itself and the system does not hang

So, in the event that only the flash write fails (indefinitely) the Zephyr sdk doesn't seem to handle this well. In any case, it's unlikely we will encounter only the flash write failing. 

[Elfving]

jthmp said:

We used the samples as a starting point, but since we are using backend logging there is no example I could find that is addressing our use case:

Every time we use something like LOG_INF, or LOG_WRN it gets stored in a ext or internal flash memory. Looking at the zephyr code 'log_backend_fs.c' it seems like there is no contingency for detecting a persistent fs_write error. 

As in there not being a sample that handles the issues with flash writes for logging? I do not know of any that handles this exact problem myself, though it seems as if a few customers have run into a similar issue previously. I assume you are not for instance running into the same situation as this guy here, who had this issue because he wanted to initialize LWM2M_CARRIER at the same time? Either way it might be a good idea to have a look at that thread.

If you see this often happen on a DK, could you get me something minimal that reproduces this? 

Regards,

Elfving