Issues encountered when processing hot logger in asynchronous mode

[menghaikang]

Dear experts,

Hello! I am a Linux server-side developer. In my typical use of the spdlog library, one logger instance is bound to only one daily_file_sink.
I noticed that in spdlog’s asynchronous logging implementation, all loggers share the same message queue.

Suppose my program has high logging demands, and I want to start multiple logging worker threads (async threads) to process log messages in the queue, thereby accelerating consumption speed.

However, the vast majority of log messages in my program must be output through the same daily_file_sink instance—meaning the number of "hot daily_file_sink instances" is less than the number of worker threads (hot daily_file_sink instance count < thread count). In this case, multiple logging threads will frequently compete for the mutex lock of the same sink instance, which may lead to the following issues:

• Thread A fetches a log message that needs to be output to sink_M via logger_M; Threads B, C, D do the same.
• Threads A, B, C, D then compete for sink_M’s mutex lock, resulting in log messages in the queue that belong to other loggers/sinks not being processed in a timely manner.

In this scenario, increasing the number of async threads from 1 to multiple does not significantly improve log consumption speed.

For this scenario, might the following design be better?

1. Each logger has its own internal message queue (called a secondary message queue).

2. Add a global queue (called a primary message queue), which only stores loggers that have pending messages in their secondary queues.

3. Thread pool threads are scheduled based on the primary queue:

   • When a thread works, it fetches a logger from the primary queue and processes the accumulated messages in its secondary queue.

   • To prevent a thread from continuously consuming messages from a single hot logger (causing messages from other loggers to backlog), assign a "weight" to each worker thread.

   • When a logging thread fetches a logger and processes its secondary queue, it decides (based on the thread’s assigned weight) whether to:

     • Process all messages in the secondary queue before finishing;
     • Process half of the current messages in the secondary queue, then push the logger back to the primary queue;
     • Process a quarter of the current messages in the secondary queue, then push the logger back to the primary queue;
     • And so on.

   • This ensures that "cold" loggers also receive relatively fair and timely processing.

4. Both enqueue and dequeue operations for the primary and secondary queues must be protected by locks (e.g., std::mutex).

I would like to ask for your thoughts on this problem. How did you consider such scenarios when designing the spdlog library?

[tt4g]

Is this about the async logger provided by spdlog?
The async logger sends log messages to a message queue managed by the internal thread pool. The logs in this message queue are then sent to a sink by worker threads.
This is similar to the message queue and worker threads you're thinking of, but some parts of the implementation differ.

By the way, even if you use threads to parallelize log output operations, the final destination for log messages is still disk. Fundamentally, log output speed will never exceed disk I/O speed.

[menghaikang]

Yes, I am indeed discussing the async logger provided by spdlog.

What I mean is that if my log output is only concentrated on a few specific daily_file_sink_mt instances, increasing the number of threads in the asynchronous thread pool may result in multiple worker threads competing for the built-in std::mutex of the same sink, which in turn means the consumption speed of the message queue does not improve significantly.

In my usage scenario, each async_logger is only bound to one daily_file_sink. Therefore, my solution is to create a separate message queue for each logger instance, thereby avoiding multiple worker threads competing for the built-in std::mutex of the same sink and allowing multiple worker threads to run in parallel more smoothly to complete log output operations.

In this specific scenario, it really requires certain performance tests to prove which solution is better.

I understand your point: you are saying that even if I alleviate the competition for the std::mutex of the same sink among multiple log output threads, the degree of optimization may not be substantial for the final outcome. This is because for log output operations, the real bottleneck is generally whether the disk can support such a large write load, rather than multi-thread competition. That’s why spdlog adopts a single message queue design for its asynchronous mode and allows multiple threads to compete for the sink's std::mutex.

is that correct?

[tt4g]

First off, please note that spdlog's async logger is slower than the synchronous logger when it comes to log output speed.
This is because the purpose of the async logger is to prevent the logging thread from being blocked during log output, not to speed up log output itself.
Please also see the related issues: #1391, #2282

I understand your point ...

The purpose of the async logger is as described above.
it is designed to avoid blocking the application's main processing. Therefore, to output a large number of log messages to a file at high speed, a better solution may be required.

As you pointed out, the std::mutex in the sink may cause lock contention and potentially degrade performance, but I have never seen any reports of this becoming an issue.

[menghaikang]

Regarding the extra overhead you mentioned for log output performed by separate threads (i.e., the async logger), including lock contention on the message queue and message copying during enqueuing, I fully understand this point.

Thank you very much for your patient explanation; my confusion has been mostly resolved.

In my working scenario, the performance of spdlog is more than sufficient. I raised this question purely out of curiosity. If I ever encounter a real bottleneck, I will perform more detailed performance analysis based on my actual use case.

This discussion can be closed now. Thanks again for your reply!

[tt4g]

The exact same question #3547