避免 Boost Log 琐碎使用中的泄漏答案

【问题标题】：Avoid leak in Boost Log trivial usage避免 Boost Log 琐碎使用中的泄漏
【发布时间】：2015-02-04 12:50:25
【问题描述】：

我从使用 boostlog 的服务器端应用程序获取 valgrind 泄漏报告，该应用程序与 boost 1.56 一起分发。 valgrind 报告是：

==8021== 1,159 个块中的 37,088 个字节在 1,642 的丢失记录 1,613 中肯定丢失了

==8021== at 0x4A05588: memalign (vg_replace_malloc.c:727)

==8021== by 0x3FDA61118F: tls_get_addr_tail（在 /lib64/ld-2.12.so 中）

==8021== by 0x3FDA61165F: __tls_get_addr (in /lib64/ld-2.12.so)

==8021== by 0x3FE6ABBDCB: __cxa_get_globals（在 /usr/lib64/libstdc++.so.6.0.13 中）

==8021== by 0x730C528: boost::log::v2_mt_posix::aux::unhandled_exception_count()（在 /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)

这个泄漏来自简单的一行：
LOGGER(debug)<< _chanProp->GetId() << " got recognition ended notification from recognizer";

我们仅通过一次短暂的测试运行就发现了其中的 5 个泄漏。

我们使用文本文件后端，带有同步接收器，自动刷新已打开。基本上：

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();

        }

    }

系统使用devtoolkit2.0在centos 6.6上编译运行。 gcc 版本是 4.8.2。

那么我们对boost log的使用是不是有问题呢？还是boost log真的有这样的问题。我认为我们的使用可以认为是微不足道的，我们只是在启动时运行上面的配置代码。

注意：即使单个泄漏大小可能足够小，但我们的软件在服务器上作为服务运行，因此这种重复泄漏对我们来说是个问题。

【问题讨论】：

我认为 Boost Log 在初始化时会创建一些初始对象，一个在整个过程生命周期中都存在的对象。这意味着在检查泄漏时将被视为误报，因为它会在进程结束时被释放。
valgrind 将这些泄漏报告为“肯定丢失”。您解释的那种将被报告为“可能丢失”。在一次运行中，我得到五个这样的报告，因此它不能是一次性初始化。
你在使用线程吗？有多少线程正在运行？线程中的“泄漏”语句（第一次记录？最后一次记录？在中间的某个地方？）何时何地在线程中（如果您使用）是“泄漏”语句？
第一个日志没有泄漏，它也不是最后一个日志。但我注意到每次泄漏都是从不同的线程发生的。因此，这很可能意味着 boost log 正在为每个使用它的线程进行初始化，并且当该线程退出时，就会发生这种泄漏。另一个线索可能是 Valgrind 报告在堆栈跟踪中包含与 tls 相关的调用。
在应用运行期间不断创建/终止/销毁线程很少有任何好处。使用线程池或应用程序生命周期线程。通过队列传达消息/作业/任务。不要使用创建/加入。不要收取 200 美元。

标签： c++ logging boost memory-leaks boost-log

【解决方案1】：

Boost Log - 与许多其他日志库一样 - 在内部使用 tls。当线程终止时，日志系统很难（有时似乎不可能）清理 tls 变量。 Boost面临同样的困难。

对于包含日志记录代码的长时间运行的应用程序，分离许多线程并在它们的任务完成时终止它们并不是一个好的用途。在大量多任务系统中，更好的方法是使用线程池，而不是每次都启动新线程。

我将应用程序转换为使用线程池，问题中的泄漏已经消失。 tls 变量仍然存在，但由于现在线程被重用 tls 变量也被它们相应的线程重用。

【讨论】：

【解决方案2】：

我真的不明白这个问题。您出示泄漏的证据，并询问“是否泄漏”。嗯，是。这不足为奇。记录器使用线程本地“单例”。根据您组织线程的方式，有可能/几乎不可能正确拆除这些线程。

是时候制作 SSCCE 并点击有关正确关机顺序的文档了。

注意

众所周知，关闭记录器非常困难。您需要处理关闭期间需要记录某些内容的可能性（设计气味）；更糟糕的是，不同的接收器可能相互依赖并阻止以任何特定顺序关闭）。

相当多的框架只是将其留给操作系统进行清理。

PS没有任何迹象表明重复泄漏，因为它看起来像每个线程的泄漏。

【讨论】：

问题是：“那么我们使用boost log有问题吗？或者boost log真的有这样的问题”。我没有问“它会泄漏吗？”。您仔细阅读问题了吗？
@Mert 我做到了。很难弄清楚你到底想知道什么。我主要回答这个问题：i.imgur.com/wVTv9kN.png 不管怎样，我的 comment 太长，无法发表评论
我想知道如何修复我看到的明显泄漏。我想知道，如果我在使用中犯了一个明显的错误，在我看来这是非常微不足道的。 “Does boost log leak in trivial usage”这句话将我的想法放在了适合主题领域的几句话中。
@Mert 一个想法：如果您使用std::thread，您可以尝试将其替换为boost::thread 用法。功能几乎相同，但我想我已经看到boost::thread 提供了对thread_specific_ptr 的适当清理。另外，永远不要忘记join 线程。
我在某处读过同样的想法并检查了它。我也看到来自 boost 线程的相同泄漏。以下是来自类似泄漏的一行：==18126== by 0x80099D9: thread_proxy（在 /opt/sesteksdk/lib/libboost_thread.so.1.56.0 中）。代码总是立即分离线程，同步总是通过条件变量完成（实际上它是基于任务的，但每个任务都很重要并且在自己的线程中运行）。在这里放置一个线程池很容易，所以我现在正在这样做。

【解决方案3】：

泄露的对象是 C++ 运行时的内部部分，它不是由 Boost.Log 显式创建的。据我所知，这个对象是按线程创建的，因此应该在线程终止时销毁。您对 Boost.Log 的使用对我来说似乎很好。

【讨论】：