Runtime disable log backend FS in nRF Connect 1.7.0

[Ben_R831]

Hello,

I am trying to store logs using the backend FS. However, I would like the opportunity to unmount the file system at run time. As currently that results in a hard fault as the backend is expecting the mount for the file system, I am trying to disable that backend temporarily before the unmount. 

I saw this post about disabling log backend FS. However, as I am using NCS 1.7.0, I only have log_backend_get() and log_backend_activate/deactivate(). How can I use those to reach the same effect as log_backend_disable(log_backend_get_by_name("log_backend_fs")) ?

I attempted to modify the SDK based off of this commit, but it won't work due to missing dependencies. 

Thank you,

Ben

[Raoul]

Hi Ben, thanks for your question and the update.

I haven't been able to get to this case yet, but I hope to have time tomorrow. Just wanted to let you know.

Best regards,

Raoul

[Ben_R831]

Hello Raoul,

No problem at all. Thank you. Sounds good.

Best regards,

Ben

[Raoul]

Hi Ben, sorry for the delay.

Thanks again for your descriptions so far. The logging system is a beast, I can't say I understand the internals well.

Ben_R831 said:

But, I also noticed that when the backend is re-activated, the logs since deactivation are also stored on the flash. I am assuming it is because the backend places on a queue all messages while its deactivated.

Yes, log messages are queued, although I didn't realise this persisted even past the disabling and reenabling of a logging backend. Are you saying this queueing is unwanted, you don't care about missing messages? Or do you have a second backend set up?

Ben_R831 said:

Also, as I have been running it more, I occasionally get Hard Faults and Bus Faults with the layout above. It happens once in awhile with this section of code. I also noticed that the ctx pointer is NULL.

Strange, so the log_backend_get_by_name() function that you backported doesn't consistently work?

I've been looking at other options that are available in NCS v1.7.0 (assuming that that's currently a strict requirement for you) and one other option I can think of is to use run-time filtering (discussed in for example this case).

You have to enable CONFIG_LOG_RUNTIME_FILTERING=y and then use log_filter_set() to set the level to 0.

Unfortunately I'm not actually sure if this will prevent your hard faults from occurring, but it might be worth trying.

By the way, can I ask why you need to unmount the filesystem? Are you removing an SD card or similar? Just asking in case your actual objective can be achieved in a different way.

Best regards,

Raoul

[Ben_R831]

Hello Raoul,

Thank you for your response. No problem at all. 

Raoul said:

Yes, log messages are queued, although I didn't realise this persisted even past the disabling and reenabling of a logging backend. Are you saying this queueing is unwanted, you don't care about missing messages? Or do you have a second backend set up?

Actually, this queuing suits the application perfectly. Currently, I am using two back-ends: UART and the Flash FS backend. 

After trying more things, I found that the hard fault occurs while unmounting the flash after the file system backend was already deactivated. So, the above implementation of log_backend_get_by_name() does work. Could it be because the log module is not fully finished writing, so an unmount would lead to a bus fault?

This morning I actually can't reproduce the bus fault. :(  It's funny that I want the error to appear now.

My final code is this:

void flashLog_detach(bool unmount)
{
    if(!isAttached)
    {
        LOG_ERR("Trying to detach when already detached!");
        return;
    }
#ifdef CONFIG_MCUMGR_CMD_FS_MGMT
	// requires system to be mounted.
	// fs_mgmt_register_group();
	fs_mgmt_deregister_group();
#endif
    isAttached = false;
    fslog = log_backend_get_by_name("log_backend_fs");
	originalCTX = fslog->cb->ctx;
    log_backend_deactivate(fslog);
    log_backend_disable(fslog);
    if(unmount)
    {
        if(!isMount)
        {
            LOG_ERR("Trying to unmount when already unmounted!");
        }
        isMount = false;
        LOG_INF("Unmounting...");
        fs_unmount(mp); // right here is where the hard bus fault was occurring
    }
}
void flashLog_reattach(bool mount)
{
    if(isAttached)
    {
        LOG_ERR("Trying to reattach when already attached!");
        return;
    }
    if(mount)
    {
        if(isMount)
        {
            LOG_ERR("Trying to mount when already mounted!");
        }
        LOG_INF("Mounting...");
        fs_mount(mp);
        isMount = true;
    }
    log_backend_enable(fslog,originalCTX,LOG_LEVEL_FILTER_FLASH);
    log_backend_activate(fslog,originalCTX);
#ifdef CONFIG_MCUMGR_CMD_FS_MGMT
	// requires system to be mounted.
	fs_mgmt_register_group(); // <<< it doesn't seem like I can reenable the fs commands either as of now.
	// fs_mgmt_deregister_group();
#endif
    isAttached = true;
}

Two questions:

What is the difference between log_backend_enable/disable() vs log_backend_activate/deactivate()?

And, what does the "user context" (ctx) pointer do? I noticed that it is NULL and the documentation only states that it is a "user context" pointer. 

Raoul said:

By the way, can I ask why you need to unmount the filesystem? Are you removing an SD card or similar? Just asking in case your actual objective can be achieved in a different way.

That's a good question. So, a side goal is to reduce power consumption. My original thought was to unmount the file system and shutdown the flash chip. Then, at specific times, turn on the flash chip and mount the flash, and then enable logging. Would there be a better way to conserve power? The main application will only generate logs every few hours. Also, the message queuing is very good, just in case a log message occurred while the flash chip was down.  

Raoul said:

You have to enable CONFIG_LOG_RUNTIME_FILTERING=y and then use log_filter_set() to set the level to 0.

That sounds like a good idea. I see you can customize it by backend too, which is great. May try that out. Wondering though if there is a more power-efficient way with turning off the flash chip. Maybe combining a log_filter_set() and something from Zephyr's Power Management library like pm_device_state_set()?

God bless,

Ben

[Raoul]

Ben_R831 said:

What is the difference between log_backend_enable/disable() vs log_backend_activate/deactivate()?

Ben_R831 said:

And, what does the "user context" (ctx) pointer do? I noticed that it is NULL and the documentation only states that it is a "user context" pointer. 

I'm not actually sure, I will have to read more about this. Unfortunately there are a lot of cases coming in currently, so my responses will be a bit delayed.

I'll try to get to your other questions soon. Thanks for elaborating on your intentions.

But let me know if you reach a satisfying solution in the mean time!

Best regards,

Raoul

[Ben_R831]

Ok. Sounds good. No problem at all. 

Thanks,

Ben

[Ben_R831]

Ben_R831 said:

Also, as I have been running it more, I occasionally get Hard Faults and Bus Faults with the layout above. It happens once in awhile with this section of code.

Raoul said:

Unfortunately I'm not actually sure if this will prevent your hard faults from occurring, but it might be worth trying.

Since the discussion, had more time to work on this.

Thought to put this here as it likely will help someone else, I was getting bus and hard faults when I was doing the above while also at the same time initializing the LWM2M_CARRIER library. When the modem is initializing certificates and I try to do any flash operation (even log back-end stuff), a bus fault occurs.

Workaround: do the flash logging utilization first, and then initialize the LWM2M_CARRIER library. 

[Raoul]

Hi Ben, sorry that I didn't get around to answering those remaining questions in your last reply. Thanks a lot for sharing your workaround with our other users!

So is the thing you initially wanted to do now in order? Or do you still need help with achieving that?

Best regards,

Raoul