How to use Boost.Log formatting expressions in custom formatting function

Question

I am trying to use a custom formatter with Boost.Log. The way I know how to do this is to call the set_formatter method of a sink giving it the address of a local function where the signature of the local function needs to be:

void my_formatter(boost::log::record_view const& rec, boost::log::formatting_ostream& strm)

In my_formatter I can use the Boost.Log extraction api to get the attribute values that I need. Once I get the values, I can output them to the strm. I want to do this so I can easily format some custom attributes stored in the record. But for other, more conventional Boost.Log attributes, I would like to continue to use the simple formatting expressions that are documented as keyword arguments to the set_formatter method. Is there a way to also use the keyword expressions in my_formatter custom function?

For example:

void my_formatter(boost::log::record_view const& rec, boost::log::formatting_ostream& strm)
{
    // here I can get the timestamp attribute and format its ticks value to the stream
    boost::log::value_ref<boost::posix_time::ptime> tstamp_ref =
        boost::log::extract<boost::posix_time::ptime>("TimeStamp", rec);
    const boost::posix_time::ptime& timestamp = tstamp_ref.get();

    strm << timestamp.time_of_day().ticks();
}

Then given a sink, I can call

sink->set_formatter(&my_formatter)

But Boost.Log gives me an elegant (almost magical) expression that I can use to set the formatter:

boost::log::formatter formatter =
    expr::stream
    << expr::format_date_time<boost::posix_time::ptime>(
        "TimeStamp", "%Y/%m/%d, %H:%M:%S.%f, ");

sink->set_formatter(formatter)

My question is: is there a way to use the formatter expression in my custom my_formatter function?

Thanks!

score 3 · Answer 1 · answered Jul 28 '16 at 23:40

After some work, I found some Boost.Log test code, form_date_time.cpp, that shows how to do this. Below is how to use the expression formatter programmatically in a custom format function.

void my_formatter(boost::log::record_view const& rec,
                  boost::log::formatting_ostream& strm)
{
    typedef boost::log::formatter formatter;
    formatter f = expr::stream << expr::format_date_time<boost::posix_time::ptime>(
                      "TimeStamp", "%Y/%m/%d, %H:%M:%S.%f, ");
    f(rec, strm);
}

While I have given the answer, one should careful on using it. In my benchmarking tests, a properly implemented custom formatter function will outperform the expression formatter. But for complex expressions that you do not want to write code for (e.g., the specialized Named scope formatter), this approach allows one to take advantage of an expression formatter in a custom formatter function.

score 2 · Accepted Answer · edited May 23 '17 at 12:14

2

What you might want to do is to inject your custom parts of the formatter into the formatting expression created with Boost.Log instead of the other way around. This answer describes a way to achieve that by using phoenix::bind.

edited May 23 '17 at 12:14

Community

1
1

answered Jul 30 '16 at 00:57

Andrey Semashev

10,046
1
17
27

Thanks! That is a long answer, so I will have to study it a little, but that seems like a good approach too. Can you discuss a little more the performance slowdowns when using the formatting expressions? You mention in the docs that the formatting expressions in code will perform faster than ones created from a config file. My observation is that my non-expression formatter performs faster than the expression based one. (Granted, in my ad-hoc benchmark the only work being done is logging, so I am being hyper-critical regarding the slowdown, but sometimes performance really does matter.) – Phil Jul 30 '16 at 02:11
One would have to examine the code and the generated assembly to discover the reason of performance regression. The formatting expressions (the ones involving `expr::stream` anyway) are more efficient than the parsed formatters because the compiler has more ways to optimize. In particular it can inline functions more aggressively. A hand written formatter can potentially outperform the formatting expression because it can be more specialized. It's usually a flat function, so it doesn't depend on inlining that much, while the compiler may fail to optimize template expressions for some reason. – Andrey Semashev Jul 30 '16 at 08:37
Also, if your formatter involves date/time then make sure you use `expr::format_date_time` and not the `operator<<` from Boost.DateTime as the latter is known to be slower. – Andrey Semashev Jul 30 '16 at 08:42

How to use Boost.Log formatting expressions in custom formatting function

2 Answers2