Boost Log 运行时优化答案

【问题标题】：Boost Log run-time optimizationBoost Log 运行时优化
【发布时间】：2014-08-07 05:42:28
【问题描述】：

我正在为我的应用程序的日志记录平台使用 Boost-Log 和全局严重性记录器。分析显示boost::log::v2s_mt_posix::core::open_record 最多可以占用总执行时间的 25%。

我确实有很多日志消息，但我不希望它们如此昂贵，因为 它们是严重性较低，它们会被过滤。

有没有办法让这些消息在运行时不那么昂贵？（再次说明：我希望即使在过滤时也会有少量开销，当然在未过滤时会有更大的开销）。

编译时通过创建一些包装宏相对容易“修复”这个问题。

已更新示例工作代码：

#include <cmath>
#include <iostream>
#include <string>
#include <boost/lexical_cast.hpp>
#include <boost/log/sources/global_logger_storage.hpp>
#include <boost/log/sources/severity_logger.hpp>
#include <boost/log/trivial.hpp>
#include <boost/log/sources/severity_channel_logger.hpp>
#include <boost/log/common.hpp>
#include <boost/log/expressions.hpp>
#include <boost/log/sinks.hpp>
#include <boost/log/utility/setup/common_attributes.hpp>
#include <boost/log/utility/setup/console.hpp>
#include <boost/log/support/date_time.hpp>
#include <boost/utility/empty_deleter.hpp>
#include <boost/shared_ptr.hpp>
#include <boost/make_shared.hpp>

// severity levels
enum severity_level {INFO};

// Logging macro
#define LOG(level) BOOST_LOG_SEV(global_logger::get(), level)

// Initializing global boost::log logger
typedef boost::log::sources::severity_channel_logger_mt<
    severity_level, std::string> global_logger_type;

BOOST_LOG_INLINE_GLOBAL_LOGGER_INIT(global_logger, global_logger_type)
{
    return global_logger_type(boost::log::keywords::channel = "global_logger");
}

// Initialize terminal logger
void init_logger(int verbosity)
{
    namespace bl = boost::log;
    typedef bl::sinks::synchronous_sink<bl::sinks::text_ostream_backend>
      text_sink;

    boost::shared_ptr<text_sink> sink = boost::make_shared<text_sink>();
    sink->locked_backend()->add_stream(
        boost::shared_ptr<std::ostream>(&std::cout, boost::empty_deleter()));

    sink->locked_backend()->auto_flush(true);

    sink->set_formatter(bl::expressions::stream << bl::expressions::message);

    sink->set_filter(bl::expressions::attr<severity_level>("Severity")
                     < (severity_level) verbosity);

    bl::core::get()->add_sink(sink);
    bl::add_common_attributes();
}

int main(int argc, char* argv[])
{
    init_logger(boost::lexical_cast<int>(argv[1]));
    for(int i = 0; i < 200; ++i)
    {
        std::sin(std::sin(17.2)); // dummy processing
        LOG(INFO) << "A message!";
    }
    return 0;
}

使用参数0 运行不会打印任何日志消息，但需要两次（！）比注释掉 LOG 消息的时间。

【问题讨论】：

向我们展示一些示例代码。如果可以的话，一个最小的工作程序。
自从它首次被接受为 Boost 库以来，似乎出现了这种 2 倍的减速（当大多数消息被过滤时）。 lists.boost.org/boost-announce/2010/03/0256.php
您可能想要评估异步日志库，例如 g2log 或至少 google-glog 缓冲写入

标签： c++ logging boost boost-log

【解决方案1】：

通常，在记录时，必须评估正在记录的内容，并且该评估发生在实际决定是否记录之前。例如：

log.debug("The current state of the system is: " + system.expensiveFunctionToGatherState());

我们有一个自制的日志系统，可以将当前时间添加到日志中，这是对gettimeofday() 的调用。结果表明，程序中 20% 的 CPU 消耗是调用 gettimeofday() 以获得从未去任何地方的日志函数。

【讨论】：

我 Boost 的情况，我几乎可以肯定没有评估发生。正如我在示例中显示的那样，在记录一个简单字符串的情况下，执行时间会显着增加。
@DimitrisDakopoulos，我想它们是，因为输出流运算符将使用链接的各个参数调用，我不知道如何实现 boost log，但即使在被忽略的情况下，它可能必须返回一些支持流操作符的东西——这反过来又会被所有流入的值调用...

【解决方案2】：

一种解决方法（顺便说一句，这是一个 marmite 解决方案。）是使用宏来包装日志记录，例如：

#define LOG_INFO(x) \
  if (<test if log level is INFO>) { \
    LOG(INFO) << x;  \
  }

然后：

LOG_INFO("Foo" << "Bar" << someExpensiveFunction());

您可以确定someExpensiveFunction() 只会在支持INFO 的级别上执行。

哎呀，你甚至可以完全编译出来，

#ifndef _NINFO_
#define LOG_INFO(x) \
  if (<test if log level is INFO>) { \
    LOG(INFO) << x;  \
  }
#else
#define LOG_INFO(x)
#endif

这样做的另一个好处是您可以通过修改宏来更改日志记录实现，而不是到处更改所有代码..

【讨论】：