setting boost::posix_time::time_facet has no effect on boost::log sinks

[Georg Sauthoff <mail@…>]

How to reproduce:

#include <boost/date_time/posix_time/posix_time.hpp>

#include <boost/log/trivial.hpp>
#include <boost/log/core.hpp>
#include <boost/log/expressions.hpp>

#include <boost/log/utility/setup/console.hpp>
#include <boost/log/attributes.hpp>

#include <locale>

int main(int argc, char **argv)
{
  auto clog = boost::log::add_console_log();
  clog->set_formatter(
        boost::log::expressions::stream
          << "[" << boost::log::trivial::severity << "] "
          << boost::log::expressions::smessage
      );

  const char date_format[] = "%Y-%m-%d %H:%M:%S";
  // does not work
  clog->imbue(std::locale(clog->getloc(),
    new boost::posix_time::time_facet(date_format)
        ));

  boost::posix_time::ptime dt(
      boost::gregorian::date(2015, 1, 1),
      boost::posix_time::time_duration(8, 48, 0)
      );
  BOOST_LOG_TRIVIAL(info) << dt;
  BOOST_LOG_TRIVIAL(info) << dt;

  return 0;
}

Expected output:

$ ./test_log_datetime
[info] 2015-01-01 08:48:00
[info] 2015-01-01 08:48:00

Actual output:

$ ./test_log_datetime
[info] 2015-Jan-01 08:48:00
[info] 2015-Jan-01 08:48:00

When stepping through the code I observe that the output operator in boost/posix_time/posix_time_io.hpp

  operator<<(std::basic_ostream<CharT, TraitsT>& os,
             const boost::posix_time::time_period& p) {
    boost::io::ios_flags_saver iflags(os);
    typedef boost::date_time::time_facet<ptime, CharT> custom_ptime_facet;
    std::ostreambuf_iterator<CharT> oitr(os);
    if (std::has_facet<custom_ptime_facet>(os.getloc())) {
      std::use_facet<custom_ptime_facet>(os.getloc()).put(oitr, os, os.fill(), p);
    }
    else {
      //instantiate a custom facet for dealing with periods since the user
      //has not put one in the stream so far.  This is for efficiency 
      //since we would always need to reconstruct for every time period
      //if the local did not already exist.  Of course this will be overridden
      //if the user imbues as some later point.
      custom_ptime_facet* f = new custom_ptime_facet();
      std::locale l = std::locale(os.getloc(), f);
      os.imbue(l);
      f->put(oitr, os, os.fill(), p);
    }
    return os;

is executed 2 times - as expected - but the condition is both times false. Expected behaviour: both times true, or at least: first time false and 2nd time true.

Even when not trying to set a custom facet:

#include <boost/date_time/posix_time/posix_time.hpp>

#include <boost/log/trivial.hpp>


int main(int argc, char **argv)
{
  boost::posix_time::ptime dt(
      boost::gregorian::date(2015, 1, 1),
      boost::posix_time::time_duration(8, 48, 0)
      );
  BOOST_LOG_TRIVIAL(info) << dt;
  BOOST_LOG_TRIVIAL(info) << dt;

  return 0;
}

the debugger shows that the default facet is instantiated 2 times in boost/posix_time/posix_time_io.hpp (i.e. condition is both times false).

When not using Boost Log, setting the facet works as expected:

#include <boost/date_time/posix_time/posix_time.hpp>

#include <iostream>
#include <locale>

int main(int argc, char **argv)
{
  const char date_format[] = "%Y-%m-%d %H:%M:%S";
  std::clog.imbue(std::locale(std::clog.getloc(),
      new boost::posix_time::time_facet(date_format)
          ));

  boost::posix_time::ptime dt(
      boost::gregorian::date(2015, 1, 1),
      boost::posix_time::time_duration(8, 48, 0)
      );
  std::clog << dt << '\n';
  std::clog << dt << '\n';

  return 0;
}

Output:

2015-01-01 08:48:00
2015-01-01 08:48:00

The debugger shows that the condition in the output operator in boost/posix_time/posix_time_io.hpp is both times true, as expected.

Also as expected, when commenting out the clog.imbue() call, the condition is the first time false, and the second time true.

[Andrey Semashev]

The locale you imbue into the sink is used by the formatter (the function object you pass to set_formatter). It has no effect on the log message formatting. In fact, the message comes to the formatter as a string already.

The message text is formatted by a separate stream with its own locale. That stream is not publicly accessible, except though the logging macros. The locale it uses is the default constructed and does not contain Boost.DateTime facets. This is so because the message text is formatted only once while there can be multiple sinks with different formatters and different locales.

If you want the message formatting stream to use Boost.DateTime facets you can add the facet to the global locale before you start using Boost.Log. This should typically be done somewhere in the application startup code.