Zięcik, Piotr <piotr.ziecik@...>
Hi.Still not quite following you, but I'll look at the code some more.5) What does it mean if CONFIG_LOG_INPLACE_PROCESS=n, butKrch: It is possible to use deferred mode and not use the thread. Most likely that would be the case when multithreading is disabled.
Since Krzysztof already left the office, I will try to answer that.
When logs are deffered, you need to call LOG_PROCESS() periodically to format log messages and push them to the backends.
If CONFIG_LOG_PROCESS_THREAD=y, you are creating dedicated thread which does that for you and you just don't care about
that in your application. If the CONFIG_LOG_PROCESS_THREAD is set to n, then calling LOG_PROCESS() is the application responsibility.
Also, if multithreading is disabled, "manual" calling of LOG_PROCESS() becomes the only way to use deffered logs.
PIOTR ZIĘCIK | Senior Firmware Engineer
M +48 698 726 973| Kraków, Poland
nordicsemi.com | devzone.nordicsemi.com
From: email@example.com <firstname.lastname@example.org> On Behalf Of Boie, Andrew P
Sent: Thursday, November 29, 2018 6:28 PM
To: Cufi, Carles <Carles.Cufi@nordicsemi.no>; Chruściński, Krzysztof <Krzysztof.Chruscinski@nordicsemi.no>; zephyr-devel <email@example.com>; Rzeszutko, Jakub <Jakub.Rzeszutko@nordicsemi.no>
Cc: zephyr-devel <firstname.lastname@example.org>
Subject: Re: [Zephyr-devel] logging subsys questions / concerns
For some reason I did not get your email, Carles had to forward to me.
1) The default priority of the logging thread is -2. This is a veryKrch: Intention was to set it to the lowest possible value - K_LOWEST_APPLICATION_THREAD_PRIO. Now I've noticed that it's -2 only when CONFIG_PREEMPT_ENABLED is set. So it can be updated or fixed to K_LOWEST_APPLICATION_THREAD_PRIO in the code.
apboie: OK cool
I think we need to move theKrch: please suggest the better place. Note that ideally it should be as early as possible when non-recoverable error is hit since by doing that we reduce the risk of losing any logs (as before panic we keep using msg pool so there is a chance of overflow).
apboie: Good point, we don't want to deal with overflow in this situation. I think what we need is an API call to clear the panic mode state if _SysFatalErrorHandler() decides not to hang the system, immediately before the API call to k_thread_abort().
3) It does not appear that there is any support for invoking LOG()Krch: currenly it is not supported, should be addded
apboie: Cool. I can help with this. I'll open a bug.
I think CONFIG_LOG_PROCESS_SLEEP_MS andKrch: Speed was the purpose of not using semaphores and sticking to simple counter. Currently, it takes ~250 cycles (nrf52 - ~4us @64MHz) to log an average log message (up to 2 arguments). k_sem_give would add 1,5us so logging time would increase 4us->5,5us. Is that acceptable? I don't know. What do we gain? Solution is cleaner. Is it worth ~35% performance degradation?
apboie: I think the k_sleep() call in the log thread is not ideal, the system might be idle and have some bandwidth to dump logs, but instead the log thread can be sitting there in a sleep() call. In addition the log thread will be waking up all the time even when it has nothing to do.
As mentioned in my follow-up email, what I really think we need is instead of a semaphore, drop the custom list implementation and just use a k_queue. They are fast, are callable from IRQ context, and with the variant k_queue_alloc_append() API, also callable from user mode (when we cross that bridge). Producer-consumer problems like this are what k_queues are intended for.
If you can show using a k_queue would add a lot of overhead I could be convinced otherwise, but I really thing we should pursue this route as it will also make the code simpler and let the scheduler do its job. How are you measuring latencies btw?
5) What does it mean if CONFIG_LOG_INPLACE_PROCESS=n, butKrch: It is possible to use deferred mode and not use the thread. Most likely that would be the case when multithreading is disabled.
Still not quite following you, but I'll look at the code some more.