I am getting valgrind leak reports from a server side application that use boostlog that is distributed with boost 1.56. the valgrind report is :
==8021== 37,088 bytes in 1,159 blocks are definitely lost in loss record 1,613 of 1,642
==8021== at 0x4A05588: memalign (vg_replace_malloc.c:727)
==8021== by 0x3FDA61118F: tls_get_addr_tail (in /lib64/ld-2.12.so)
==8021== by 0x3FDA61165F: __tls_get_addr (in /lib64/ld-2.12.so)
==8021== by 0x3FE6ABBDCB: __cxa_get_globals (in /usr/lib64/libstdc++.so.6.0.13)
==8021== by 0x730C528: boost::log::v2_mt_posix::aux::unhandled_exception_count() (in /opt/sesteksdk/lib/libboost_log.so.1.56.0)
==8021== by 0x5D54D1F: sestek::mrcp::audio::recognition::AsynchronousRecognizer::Notify(sestek::voice::recognition::IRecognizerNotification const*) (record_ostream.hpp:259)
this leak is coming from a line as simple as :
LOGGER(debug)<< _chanProp->GetId() << " got recognition ended notification from recognizer";
We get 5 of these leaks just from a single, short lived test run.
we use text file backend, with syncronous sink, auto flush is on. Basically:
void InitializeFileLog(const std::string & logDir)
{
boost::shared_ptr< logging::core > loggingCore = logging::core::get();
loggingCore->add_global_attribute("TimeStamp", attrs::local_clock());
string logPath = logDir + "/gvzmrcpsr_%N.txt";
boost::shared_ptr< sinks::text_file_backend > backend =
boost::make_shared< sinks::text_file_backend >(
// file name pattern
keywords::file_name = logPath,
// rotate the file upon reaching 5 MiB size...
keywords::rotation_size = 5 * 1024 * 1024,
// ...or at midnight, whichever comes first
keywords::time_based_rotation = sinks::file::rotation_at_time_point(0, 0, 0)
);
backend->auto_flush(true);
// Wrap it into the frontend and register in the core.
// The backend requires synchronization in the frontend.
typedef sinks::synchronous_sink< sinks::text_file_backend > sink_t;
boost::shared_ptr< sink_t > sink = boost::make_shared< sink_t>(backend);
loggingCore->add_sink(sink);
sink->flush();
sink->set_formatter
(
expr::stream
<< expr::attr< boost::posix_time::ptime >("TimeStamp")
<< " : [" << expr::attr< sestek::log::LogLevel >("Severity")
<< "] " << expr::smessage
);
backend->set_file_collector(sinks::file::make_collector(
// rotated logs will be moved here
keywords::target = logDir + "/old_mrcpsr_plugin_logs",
// oldest log files will be removed if the total size reaches 100 MiB...
keywords::max_size = 100 * 1024 * 1024,
// ...or the free space in the target directory comes down to 50 MiB
keywords::min_free_space = 50 * 1024 * 1024
));
try
{
backend->scan_for_files(sinks::file::scan_all);
}
catch(std::exception & )
{
//LOGGER(sestek::log::fatal) << "exception during scanning : " << e.what();
}
}
The system is compiled and run on centos 6.6 using devtoolkit2.0. gcc version is 4.8.2.
So is there a problem in our usage of boost log? Or does boost log really have such problem(s). I think our usage can be considered as a trivial one, we just run the configuration code above during start-up.
Note: Even though a single leak size may be small enough, our software is run as a service on a server, so this kind of repetitive leak is problematic for us.
Boost Log - like many other logging libraries - uses tls internally. It is hard(and it seems sometimes impossible) for a logging system to clean up tls variables when a thread terminates. Boost faces the same difficulties.
For a long running application that contains logging code, detaching many threads and terminating them when their task is done is not a good use. A better approach in a heavily multitasking system is to use a thread-pool instead of kicking off new threads each and every time.
I converted the application to use a thread pool and the leaks in the question have disappeared. Tls variables are still there but since now threads are reused tls variables too are reused by their corresponding threads.