Filesystem logging backend not keeping up and stopping

[JVKran]

Hi there!

I'm currently in the process of migrating an 'old' nRF5X based application already in the field to the nRF Connect SDK, and am stumbling upon issues with logging to the filesystem.

The issue is reproducible with the nRF Connect SDK V2.0.0 and an nRF52832 DK. Just make sure to connect the SD-card correctly; SCK to P0.12, MOSI to P0.13, MISO to P0.14 and CS to P0.11. I've also attached our custom board definition for completeness sake.

The issue is that the logfiles aren't being opened and/or created when there are multiple transaction going on. In the provided application, for instance, I create a new file and log simultaneously. This results in error -2 ENOENT (No such file or directory) or error -5 EIO (I/O-error).

I'm very interested if this is known/defined behaviour, logical behaviour (max SD write/read speeds) or just undocumented/undefined behaviour.

Kind regards,

Jochem

log_backend_issue_reproduction.zip

[Edvin]

Hello Jochem, 

Sorry for the late reply,

This results in error -2 ENOENT (No such file or directory) or error -5 EIO (I/O-error).

What sort of functions is returning these values?

Are you using some premade SD card backend to write log messages to flash, or did you implement this yourself? If it is something already available, can you please let me know what you are using? (Because I am currently not aware of this feature in NCS).

It sounds to me like you have some issues with several instances trying to access the SD card at once. If you have not implemented some sort of queue function, you will probably see collisions like this. 

You should consider adding some semaphore, queue or buffer that you can use to handle several simultaneous interrupts/operations like this. 

Best regards,

Edvin

[JVKran]

Hi Edvin,

Not a late reply at all, thanks. I'm using Zephyrs Filesystem Logging Backend as documented here. 

Multi-threaded use of SD-card by the filesystem should also be supported with the use of the configuration variable CONFIG_FS_FATFS_NUM_FILES. As a result, I would expect several simultaneous operations should be supported.

What do you think?

Kind regards,

Jochem

[Edvin]

Hello Jochem,

I was not aware. Well. The FATFS filesystem is not necessarily the same as an SD card. It could also refer to an area of the internal (or external QSPI) flash. External QSPI flash would be XiP, execute in place, which differs from an SD card. XiP will treat the attached flash as if it was internal flash. Just for testing, you could try to remove the SD card, and log directly to the internal flash of the nRF52832 and see whether the issue remains? I suspect that logging to flash on an SD card is a corner case that isn't really covered, even though logging to flash (internal) and using fatfs on an sd card both work separately. The challenge here is that you only have a simple SPI connection to the SD card, and using this SPI bus is fairly slow compared to your application running on the nRF52832. 

What functions was it that returned the -2 and -5 errors?

Best regards,

Edvin

[JVKran]

Hi Edvin,

Sorry for the delay. We've ditched logging to the SD-card because, as it turns out, FatFS doesn't support having multiple files open for writing by default. See the appnote about re-entrancy over on the site of elm-chan.

Logging to flash works just fine. Thanks for helping.

Kind regards,

Jochem