With thread-pool of 1 thread, can I use _st-sinks?
#1852
-
|
I have a multi-threaded application (Linux), some of it's threads have real-time priority (RT Kernel patch in place). I intend to
I have not checked the implementation details of SpdLog, but from a logical standpoint, I would have assumed that with a thread pool of 1 thread, the sink(s) will be accessed by that single thread only and therefore I could use the "single threaded sinks" ( Is my thinking correct? Or more broadly: Is my approach of using single-threaded-thread-pool to decouple the "application path" from the "logging path" ok? |
Beta Was this translation helpful? Give feedback.
Replies: 6 comments 8 replies
-
Right. As long as all loggers with the shared sinks use async logging.
Sounds right. Please see full queue policies to choose how to handle cases when the queue gets full. |
Beta Was this translation helpful? Give feedback.
-
|
Thanks for the quick/good response, I appreciate! |
Beta Was this translation helpful? Give feedback.
-
|
IMPORTANT: Against what has been discussed above, the Today, we had a situation in which much logs were generated and we ended up in application crashes. We did not spend much time understanding the issue, but the thread pool still existed (thus, the error message is kind of misleading). Admittedly, it's not fully proofed that the change to |
Beta Was this translation helpful? Give feedback.
-
|
Strange.. I don't understand how “_st/_mt” sinks can affect to the lifetime of the thread pool. How do you create the thread pool and loggers? can you share ? |
Beta Was this translation helpful? Give feedback.
-
|
Sure, I can share (a very minimally modified version):
|
Beta Was this translation helpful? Give feedback.
-
Does it happen in some static init section before main? Or perhaps the CreateLogger() calls? this might cause using different thread pools due to the undefined init order of statics. Also, spdlog’s stdout sinks all share same global console mutex, so there a chance that there is a use of stdout logger elsewhere(e.g. call to spdlog::info(..))? btw the |
Beta Was this translation helpful? Give feedback.
-
|
Interesting. The saying "You can't solve a problem you did not yet understand" seems to have hit me her I do first use Since we moved from a "legacy logger" to BUT: I just realized that my system ends up with two
Thanks for the hint of the useless call to the |
Beta Was this translation helpful? Give feedback.
-
|
I've created the following "stress test" that should resemble our situation: #include <spdlog/spdlog.h>
#include <spdlog/async.h>
#include <spdlog/sinks/stdout_color_sinks.h>
#include <spdlog/sinks/rotating_file_sink.h>
#include <gtest/gtest.h>
#include <thread>
#include <future>
class Logger {
public:
Logger() {
SetupSinks();
}
void SetupSinks()
{
spdlog::init_thread_pool(8192, 1);
m_pStandardOutputSink = std::make_shared<spdlog::sinks::stdout_color_sink_st >();
auto nMaxFileSize = 10 * 1024 * 1024; // 10 MBytes
auto nMaxFileCount = 3;
m_pFileOutputSink = std::make_shared<spdlog::sinks::rotating_file_sink_st >("/tmp/XXX", nMaxFileSize, nMaxFileCount);
spdlog::flush_every(std::chrono::seconds(5));
}
std::shared_ptr<spdlog::logger> CreateLogger(const std::string& i_LoggerName)
{
std::vector<spdlog::sink_ptr> sinks{m_pStandardOutputSink};
#ifndef NDEBUG
// in "Debug builds", we output to a log file always.
sinks.push_back(m_pFileOutputSink);
#endif
auto pLogger = std::make_shared<spdlog::async_logger>(
i_LoggerName, sinks.begin(), sinks.end(), spdlog::thread_pool(), spdlog::async_overflow_policy::overrun_oldest);
// const auto level = ...
// pLogger->set_level(level);
pLogger->set_pattern("[%Y-%m-%d %T.%e] [%n] [%^%l%$] [%s:%# %!] %v");
return pLogger;
}
private:
std::shared_ptr<spdlog::sinks::sink> m_pStandardOutputSink;
std::shared_ptr<spdlog::sinks::sink> m_pFileOutputSink;
};
class SpdLogStressTest : public testing::Test {
};
TEST_F(SpdLogStressTest, DefaultValues_NotRunning)
{
Logger log;
const size_t cLogCnt = 100000000;
auto t1 = std::thread([&]() {
auto logger = log.CreateLogger("Logger1");
for (size_t i=0; i<cLogCnt; ++i) {
logger->warn("Logger1 {}", i);
}
});
auto t2 = std::thread([&]() {
auto logger = log.CreateLogger("Logger2");
for (size_t i=0; i<cLogCnt; ++i) {
logger->warn("Logger2 {}", i);
}
});
t1.join();
t2.join();
}Unfortunately, the issue does not happen as in our real application. But "sometimes" I run into the following crash with that code (but I assume it's because of the call to On the following line of code (see SPDLOG_INLINE void pattern_formatter::format(const details::log_msg &msg, memory_buf_t &dest)
{
auto secs = std::chrono::duration_cast<std::chrono::seconds>(msg.time.time_since_epoch());
if (secs != last_log_secs_)
{
cached_tm_ = get_time_(msg);
last_log_secs_ = secs;
}
for (auto &f : formatters_)
{
---> f->format(msg, cached_tm_, dest);
}
// write eol
details::fmt_helper::append_string_view(eol_, dest);
} |
Beta Was this translation helpful? Give feedback.
-
|
Does that all make sense to you? Should it also resolve if I remove the call to |
Beta Was this translation helpful? Give feedback.
-
|
I could not reproduce this Any hypothesis on why this test (as well as our application) ends up with two "spdlog" threads? |
Beta Was this translation helpful? Give feedback.
-
Right, set_pattern propagates to the sink, so no wonder it crashes if called from 2 threads(and the sink is _st). You can call Would be good if you fix and try again to make sure the test indeed passes as expected.
It has no effect since the loggers are not registered. |
Beta Was this translation helpful? Give feedback.
-
Yes. seems normal. one for the thread pool and one for the flush_every() thread. Should not cause crash. |
Beta Was this translation helpful? Give feedback.
-
|
I'll improve/fix our applications and ask my colleague, whether he may try to reproduce the initially reported crash using the Many thanks for the great help! |
Beta Was this translation helpful? Give feedback.
-
|
ok..feel free to update on any news. |
Beta Was this translation helpful? Give feedback.
Right. As long as all loggers with the shared sinks use async logging.
Sounds right. Please see full queue policies to choose how to handle cases when the queue gets full.