Boost 使用单调时钟作为日志时间戳

Question

我使用这个函数通过 boost 初始化日志记录并且效果很好

void initBoostLog(std::string logfile)
{
  boost::log::add_file_log
    (
        boost::log::keywords::file_name = logfile,
        boost::log::keywords::auto_flush = true,
        boost::log::keywords::format =
        (
            boost::log::expressions::stream 
                << "[" << boost::log::expressions::format_date_time< boost::posix_time::ptime >("TimeStamp", "%Y-%m-%d %H:%M:%S.%f")
                << "] <" << boost::log::trivial::severity
                << "> " << boost::log::expressions::smessage
        )
    );
    boost::log::add_common_attributes();
    boost::log::core::get()->set_filter(boost::log::trivial::severity >= boost::log::trivial::info);
}

输出这样的日志

[2020-07-29 16:07:20.726137] <info> My log starts
[2020-07-29 16:07:20.726619] <info> Next log line

但我希望时钟是类似于标准 C 中的单调时钟（我正确或错误地称系统正常运行时间）

struct timespec monotime;
clock_gettime(CLOCK_MONOTONIC, &monotime);
return (float)(monotime.tv_sec + monotime.tv_nsec/1.0e9);

所以日志会记录这样的内容

[1130.726137] <info> My log starts
[1130.726619] <info> Next log line

Boost 提供单调时钟 boost::log::detail::get_timestamp()

但我现在不知道如何在boost日志的初始化中使用它？ 如何使用或以其他方式解决？

我的系统是Ubuntu16.04 arm64

@sehe回答后更新 sehes 的回答就像发条一样（双关语！）我唯一需要添加的是设置流中的精度。否则我只会得到 2 或 3 位小数（相同的代码不同 Ubuntu 16.04 安装）像这样

boost::log::expressions::stream 
<< "[" << std::fixed << std::setprecision(6) << boost::log::expressions::attr<double>("monoclock")
<< "] <" << boost::log::trivial::severity
<< "> " << boost::log::expressions::smessage

Answer 1

Boost offers a monotonic clock boost::log::detail::get_timestamp()

说它“提供”了这一点有点误导。它明确位于 detail 命名空间中，因此您不能依赖它。

是否单调？

事实证明，在 POSIX 上，实现无论如何都被切换了：

#   if defined(_POSIX_MONOTONIC_CLOCK)

//! \c get_timestamp implementation based on POSIX monotonic clock
timestamp get_timestamp_monotonic_clock() {
    // ...
}

#       define BOOST_LOG_DEFAULT_GET_TIMESTAMP get_timestamp_monotonic_clock

#   else // if defined(_POSIX_MONOTONIC_CLOCK)
#       define BOOST_LOG_DEFAULT_GET_TIMESTAMP get_timestamp_realtime_clock
#   endif // if defined(_POSIX_MONOTONIC_CLOCK)

开关只依赖于在unistd.hhttps://linux.die.net/man/3/clock_gettime

中定义的_POSIX_MONOTONIC_CLOCK

Availability

On POSIX systems on which these functions are available, the symbol _POSIX_TIMERS is defined in <unistd.h> to a value greater than 0. The symbols _POSIX_MONOTONIC_CLOCK, _POSIX_CPUTIME, _POSIX_THREAD_CPUTIME indicate that CLOCK_MONOTONIC, CLOCK_PROCESS_CPUTIME_ID, CLOCK_THREAD_CPUTIME_ID are available. (See also sysconf(3).)

所以，是的，它确实使用单调时钟（如果可用）。 （如果单调在运行时失败，它 确实 回退到实时，这对移植的二进制文件有意义）。

使用了吗

是的。它用于排队的接收器，根据“排序 window”使新消息出队：不过，这不是您的格式属性。

如何让它发挥作用

定义你自己的属性！我们可以使用临时格式化表达式：

auto adhoc =
    expr::wrap_formatter([](boost::log::record_view const&, boost::log::formatting_ostream& strm) {
        struct ::timespec monotime;
        ::clock_gettime(CLOCK_MONOTONIC, &monotime);
        strm << std::fixed << std::setprecision(6) << (monotime.tv_sec + monotime.tv_nsec/1.0e9);
    });

使用时间：

boost::log::keywords::format = (boost::log::expressions::stream
     << "[" << adhoc << "] "
     << "<" << boost::log::trivial::severity << "> "
     << boost::log::expressions::smessage));

我们得到：

[768386.969232] <info> An informational severity message
[768386.969656] <warning> A warning severity message
[768386.969793] <error> An error severity message
[768386.969887] <fatal> A fatal severity message

看到了Live On Coliru

改进建议

我称之为临时的，因为实际上它不记录消息的时间戳，而是格式化的时间戳，这可能会有很大不同。在这方面，您可能想要实际定义一个自定义属性，该属性将存储在 record 中，因此您可以对其进行格式化。

自定义属性：monoclock

原来很简单：function objects as attributes。

static inline double get_monoclock() {
    struct ::timespec monotime;
    ::clock_gettime(CLOCK_MONOTONIC, &monotime);
    return monotime.tv_sec + monotime.tv_nsec/1.0e9;
}

将属性添加到所有记录所需的一切：

boost::log::core::get()->add_global_attribute("monoclock", attrs::make_function(&get_monoclock));

然后您就可以在格式化程序中自由使用它了：

    boost::log::keywords::format = (boost::log::expressions::stream
         << "[" << expr::attr<double>("monoclock") << "] "
         << "<" << boost::log::trivial::severity << "> "
         << boost::log::expressions::smessage));

同样，Live On Coliru

[504214.461181] <info> An informational severity message
[504214.462371] <warning> A warning severity message
[504214.462405] <error> An error severity message
[504214.462433] <fatal> A fatal severity message

完整列表

同样，Live On Coliru

#include <boost/date_time/posix_time/posix_time_types.hpp>
#include <boost/log/core.hpp>
#include <boost/log/expressions.hpp>
#include <boost/log/attributes.hpp>
#include <boost/log/sinks.hpp>
#include <boost/log/sources/record_ostream.hpp>
#include <boost/log/sources/severity_logger.hpp>
#include <boost/log/support/date_time.hpp>
#include <boost/log/trivial.hpp>
#include <boost/log/utility/setup/file.hpp>
#include <boost/log/utility/setup/common_attributes.hpp>

static inline double get_monoclock() {
    struct ::timespec monotime;
    ::clock_gettime(CLOCK_MONOTONIC, &monotime);
    return monotime.tv_sec + monotime.tv_nsec/1.0e9;
}

void initBoostLog(std::string logfile) {
    namespace attrs = boost::log::attributes;
    namespace expr = boost::log::expressions;

    boost::log::add_file_log(
        boost::log::keywords::file_name = logfile,
        boost::log::keywords::auto_flush = true,
        boost::log::keywords::format = (boost::log::expressions::stream
             << "[" << std::fixed << expr::attr<double>("monoclock") << "] "
             << "<" << boost::log::trivial::severity << "> "
             << boost::log::expressions::smessage));
    boost::log::add_common_attributes();
    boost::log::core::get()->add_global_attribute("monoclock", attrs::make_function(&get_monoclock));
    boost::log::core::get()->set_filter(boost::log::trivial::severity >=
                                        boost::log::trivial::info);
}

int main() {
    initBoostLog("test.log");
    using namespace boost::log::trivial;
    boost::log::sources::severity_logger< severity_level > lg;

    BOOST_LOG_SEV(lg, trace)   << "A trace severity message";
    BOOST_LOG_SEV(lg, debug)   << "A debug severity message";
    BOOST_LOG_SEV(lg, info)    << "An informational severity message";
    BOOST_LOG_SEV(lg, warning) << "A warning severity message";
    BOOST_LOG_SEV(lg, error)   << "An error severity message";
    BOOST_LOG_SEV(lg, fatal)   << "A fatal severity message";
}