CPU usage on standby time

[wusikijeronii]

Hello.
I get +5–15% CPU usage. I have the same issue on my laptop (AMD Ryzen 5 5600H) and my PC (AMD Ryzen 5 2600X). The problem even exists when my app doesn't log any data.

The most poor function in my app (by Intel VTune Profiller) reaches 95.282 ms.
Callstack for this operation when my app is minimized (I have 10–12% CPU usage):

CPU Time
1 of 1: 100.0%  (0.095s of 0.095s)

app3d.exe ! func@0x1400a741f
app3d.exe ! [Loop at line 319 in quill::detail::BackendWorker::_populate_transit_event_buffer] + 0x8a - BackendWorker.h:321
app3d.exe ! quill::detail::BackendWorker::_populate_transit_event_buffer + 0xf9 - BackendWorker.h:319
app3d.exe ! quill::detail::BackendWorker::_main_loop + 0x67 - BackendWorker.h:774
app3d.exe ! [Loop at line 0 in quill::detail::BackendWorker::run(void)::{lambda()#1}::operator()] + 0x29 - BackendWorker.h:275
app3d.exe ! quill::detail::BackendWorker::run(void)::{lambda()#1}::operator() + 0x2db - BackendWorker.h
app3d.exe ! func@0x1400a45b0 + 0x12
app3d.exe ! func@0x1400a4570 + 0x1e
app3d.exe ! func@0x1400a401c + 0x7c
ucrtbase.dll ! func@0x1800292c5 + 0x9d
KERNEL32.DLL ! BaseThreadInitThunk + 0x1c
ntdll.dll ! RtlUserThreadStart + 0x27

I also tried to disable all quill calls, and then I got 0% CPU usage when my app was minimized.

[brendene]

This might help: #275

[wusikijeronii]

Thanks for your reply. I understand the reasons why the Quill library uses the sleep/unsleep algorithm, but in my case, it makes logging functionality too expensive for my app. Is it possible to switch the logging approach to a more simple async mode (without sleeping)? just async tasks. I just use a few messages per 1 ms.

[odygrd]

hey, the library is designed to offer low latency to the hot threads that are logging.
To achieve this the backend logging thread has to spin / busy wait.
Otherwise, there is a cost that you will pay on the hot threads as they will have to notify the backend logging thread to wake up by the use of a condition variable.
Also by design the backend logging thread needs to periodically wake up as it performs some other tasks e.g. garbage collection, resync rdtsc clock etc...
It is possible to have a mode where it only wakes up if there is a logging message but it is not straight forward to add it as all the above have to be taken into consideration. I don't have much free time to add it right now but i will probably find time in the next 1-2 months.
The way it usually works for high performance applications is to pin the backend logging thread to a non-critical core

[wusikijeronii]

Thanks for the explanation. Yes, maybe this approach is mostly correct, but I think wake up on request can be a pleasant function for different cases. At least it will make this awesome library more controllable ;)

[odygrd]

waking up the logging thread on demand is simpler to implement than waking up automatically by itself when there are remaining messages to process. I did that in #281

Can you check if this example is good enough for your use case and then i can merge it to master
https://github.com/odygrd/quill/blob/wake_up_logging_thread/examples/example_wake_up_logging_thread.cpp ?

[wusikijeronii]

Hello. I am ashamed a little. Just I still think this function is a usefull function. I think it's important to develop the library. And this library has its own architectural design: first, for apps with multithreading; but in my case, I use the CPU in 95% of cases as a conveyer for tasks to the GPU. I began to make my own multithreaded task manager to mostly optimize it for my case. So then I will add logging functionality.
But about your question: yes, I think it can solve the issue.
P.S. I'm not sure it's worth it to close the ticket. You wanted to add an automatic mechanism to wake upping.

[odygrd]

No worries, I also think it is a useful function to be able to wake up the logging thread on demand if you want to use long sleep durations so I added it. Just the user needs to be aware of the extra costs when calling the wake_up function but probably you can log a few messages first and then call it just once a few ms later.

I also noticed that there are false positives with cv and the thread sanitizer on clang 11 so i moved the CI build to clang 12

This ticket will close when i merge the existing PR. For waking up automatically when the queues are not empty it is much more complicated as we are using one SPSC queue per hot thread and not a common queue for all hot threads so i will just leave it for later for now