I'm currently updating Boost from 1.61 to 1.82 in a project. The floats formatting does not operate the same way with the new boost version. While with Boost 1.61 formatting was constant between each log entry. With Boost 1.82 the formatting is reset to std::default for each entry.
Is-there any method to keep the same formatting between the differentes logs entries ?
Example
I've built this code with Boost 1.61 and with Boost 1.82.
#include <boost/log/trivial.hpp>
#include <iomanip>
int main(int, char* [])
{
double foo(10), bar(123.4567890123), baz(100000000.123456789);
BOOST_LOG_TRIVIAL(info) << "Tests log & double";
BOOST_LOG_TRIVIAL(info) << "-------------------------------";
BOOST_LOG_TRIVIAL(info) << "Raw doubles";
BOOST_LOG_TRIVIAL(info) << "foo = " << foo;
BOOST_LOG_TRIVIAL(info) << "bar = " << bar;
BOOST_LOG_TRIVIAL(info) << "baz = " << baz;
BOOST_LOG_TRIVIAL(info) << "-------------------------------";
BOOST_LOG_TRIVIAL(info) << "foo fixed";
BOOST_LOG_TRIVIAL(info) << std::fixed << "foo = " << foo;
BOOST_LOG_TRIVIAL(info) << "bar = " << bar;
BOOST_LOG_TRIVIAL(info) << "baz = " << baz;
BOOST_LOG_TRIVIAL(info) << "-------------------------------";
BOOST_LOG_TRIVIAL(info) << "foo fixed & precision = 5";
BOOST_LOG_TRIVIAL(info) << std::fixed << std::setprecision(5) << "foo = " << foo;
BOOST_LOG_TRIVIAL(info) << "bar = " << bar;
BOOST_LOG_TRIVIAL(info) << "baz = " << baz;
return 0;
}
With Boost 1.82 I get the following output :
[2023-07-12 09:01:46.857043] [0x00015950] [info] Tests log & double
[2023-07-12 09:01:46.861060] [0x00015950] [info] -------------------------------
[2023-07-12 09:01:46.863038] [0x00015950] [info] Raw doubles
[2023-07-12 09:01:46.864081] [0x00015950] [info] foo = 10
[2023-07-12 09:01:46.865037] [0x00015950] [info] bar = 123.457
[2023-07-12 09:01:46.865037] [0x00015950] [info] baz = 1e+08
[2023-07-12 09:01:46.865037] [0x00015950] [info] -------------------------------
[2023-07-12 09:01:46.866036] [0x00015950] [info] foo fixed
[2023-07-12 09:01:46.867037] [0x00015950] [info] foo = 10.000000
[2023-07-12 09:01:46.868035] [0x00015950] [info] bar = 123.457
[2023-07-12 09:01:46.868035] [0x00015950] [info] baz = 1e+08
[2023-07-12 09:01:46.869034] [0x00015950] [info] -------------------------------
[2023-07-12 09:01:46.869034] [0x00015950] [info] foo fixed & precision = 5
[2023-07-12 09:01:46.870034] [0x00015950] [info] foo = 10.00000
[2023-07-12 09:01:46.870034] [0x00015950] [info] bar = 123.457
[2023-07-12 09:01:46.870034] [0x00015950] [info] baz = 1e+08
And with Boost 1.61 I get the following output :
[2023-07-12 09:00:34.417916] [0x0000f4d8] [info] Tests log & double
[2023-07-12 09:00:34.421915] [0x0000f4d8] [info] -------------------------------
[2023-07-12 09:00:34.421915] [0x0000f4d8] [info] Raw doubles
[2023-07-12 09:00:34.421915] [0x0000f4d8] [info] foo = 10
[2023-07-12 09:00:34.421915] [0x0000f4d8] [info] bar = 123.457
[2023-07-12 09:00:34.421915] [0x0000f4d8] [info] baz = 1e+08
[2023-07-12 09:00:34.421915] [0x0000f4d8] [info] -------------------------------
[2023-07-12 09:00:34.421915] [0x0000f4d8] [info] foo fixed
[2023-07-12 09:00:34.421915] [0x0000f4d8] [info] foo = 10.000000
[2023-07-12 09:00:34.421915] [0x0000f4d8] [info] bar = 123.456789
[2023-07-12 09:00:34.421915] [0x0000f4d8] [info] baz = 100000000.123457
[2023-07-12 09:00:34.421915] [0x0000f4d8] [info] -------------------------------
[2023-07-12 09:00:34.425914] [0x0000f4d8] [info] foo fixed & precision = 5
[2023-07-12 09:00:34.425914] [0x0000f4d8] [info] foo = 10.00000
[2023-07-12 09:00:34.425914] [0x0000f4d8] [info] bar = 123.45679
[2023-07-12 09:00:34.425914] [0x0000f4d8] [info] baz = 100000000.12346
This seems like a desirable feature. You want logging to be idempotent (except for explicit things like e.g. scoped attributes).
Note that the formatting doesn't happen in the sink, so manipulating the sink's formatter will only help with explicit typed record attributes, not with the general-purpose message field.
The message field, instead, is formatted in the source. The local flags are part of the "record pump" stream. It's created by the internal stream_provider<CharT> class. It's internal (so it's not intended for end-users) and it implements pooling - which gives another reason why the flags shouldn't be persistent: otherwise flags set via one source might impact things logged through another source later.
The end result builds a compound stream around an formatting_ostream instance which has the following defaults in its init_stream():
void init_stream()
{
m_stream.exceptions(ostream_type::goodbit);
m_stream.clear(m_streambuf.storage() ? ostream_type::goodbit : ostream_type::badbit);
m_stream.flags
(
ostream_type::dec |
ostream_type::skipws |
ostream_type::boolalpha // this differs from the default stream flags but makes logs look better
);
m_stream.width(0);
m_stream.precision(6);
m_stream.fill(static_cast< char_type >(' '));
}
This explains what you're seeing.
Don't confuse logging with IO streaming. Logging is not streaming. The reason that things appeared to work as expected before indicate a bug in the older library version, and potentially just sheer luck (it might have been non-deterministic e.g. with threading and multiple sources/sinks).
The log formatting falls roughly in two categories:
sink-specific record formatters
These are the responsibility of the sink and the library has very comprehensive control for customizing and extending this.
These make sense to differ between log targets (e.g. syslog will already have PID and timestamp information and would usually not receive low-severity messages). E.g. some sinks might be support structured logging (e.g. JSON/XML)
General message formatting. This is the part where the confusion crept in, as the user-interface for this mimicks (and re-uses third-party) IO stream support.
Once you realize this, you will realize that the convenience of formatting a log record using operator<< does NOT mean you are writing to a persistent stream. It is merely a convenience that makes it so you don't have to think about buffering the message. It comes with a lot of smarts (preventing unneeded allocations and re-using needed allocations), but you're still responsible for all of the formatting.
The IO stream interface might not be best for the purpose. Consider something else, like boost::format, or create your own log macro(s) that set the required stream flags if you elect to keep using IO stream functionality.
It's usually good to be explicit about your serialization conversions. See e.g. Boost Lexicalcast, or more appropriately, Boost Convert to support this.
Demonstrating what is explained before:
#include <boost/log/expressions.hpp>
#include <boost/log/trivial.hpp>
#include <boost/log/utility/setup.hpp>
#include <iomanip>
#include <iostream>
namespace expr = boost::log::expressions;
namespace kw = boost::log::keywords;
void do_it() {
static constexpr double foo(10), bar(123.4567890123), baz(100000000.123456789);
BOOST_LOG_TRIVIAL(info) << "foo = " << foo;
BOOST_LOG_TRIVIAL(info) << "bar = " << bar;
BOOST_LOG_TRIVIAL(info) << "baz = " << baz;
}
int main() {
auto l = boost::log::add_console_log(std::cout, kw::format = (expr::stream << expr::smessage));
l->set_formatter(expr::stream << std::scientific << "(raw)\t" << expr::smessage);
do_it();
l->set_formatter(expr::stream << std::fixed << "(fixed)\t" << expr::smessage);
do_it();
l->set_formatter(expr::stream << std::fixed << std::setprecision(5) << "(prec:5)\t" << expr::smessage);
do_it();
}
Prints
(raw) foo = 10
(raw) bar = 123.457
(raw) baz = 1e+08
(fixed) foo = 10
(fixed) bar = 123.457
(fixed) baz = 1e+08
(prec:5) foo = 10
(prec:5) bar = 123.457
(prec:5) baz = 1e+08
You can create a format-state manipulator to inject your preferred formatting:
#include <boost/log/trivial.hpp>
#include <iomanip>
#include <iostream>
template <typename... Manip> struct InjectManip {
InjectManip(Manip... injectables) : _f(std::move(injectables)...) { }
private:
std::tuple<Manip...> _f;
template <size_t... Idx> void inject(std::ostream& os, std::index_sequence<Idx...>) const {
(os << ... << std::get<Idx>(_f));
}
friend std::ostream& operator<<(std::ostream& os, InjectManip const& m) {
m.inject(os, std::make_index_sequence<sizeof...(Manip)>{});
return os;
}
};
void do_it(auto ...opts) {
InjectManip fmt{opts...};
static constexpr double foo(10), bar(123.4567890123), baz(100000000.123456789);
BOOST_LOG_TRIVIAL(info) << fmt << "foo = " << foo;
BOOST_LOG_TRIVIAL(info) << fmt << "bar = " << bar;
BOOST_LOG_TRIVIAL(info) << fmt << "baz = " << baz;
}
int main() {
do_it(std::scientific, "(raw)\t");
do_it(std::fixed, "(fixed)\t");
do_it(std::setprecision(5), std::fixed, "(prec:5)\t");
}
Prints
[2023-07-12 20:24:55.333288] [0x00007f195b720180] [info] (raw) foo = 1.000000e+01
[2023-07-12 20:24:55.333320] [0x00007f195b720180] [info] (raw) bar = 1.234568e+02
[2023-07-12 20:24:55.333328] [0x00007f195b720180] [info] (raw) baz = 1.000000e+08
[2023-07-12 20:24:55.333334] [0x00007f195b720180] [info] (fixed) foo = 10.000000
[2023-07-12 20:24:55.333340] [0x00007f195b720180] [info] (fixed) bar = 123.456789
[2023-07-12 20:24:55.333356] [0x00007f195b720180] [info] (fixed) baz = 100000000.123457
[2023-07-12 20:24:55.333363] [0x00007f195b720180] [info] (prec:5) foo = 10.00000
[2023-07-12 20:24:55.333369] [0x00007f195b720180] [info] (prec:5) bar = 123.45679
[2023-07-12 20:24:55.333375] [0x00007f195b720180] [info] (prec:5) baz = 100000000.12346
Combining that with some clever use of (scoped) attributes should enable you to automatically inject the format settings into log records.
I will not go there currently as I think you will likely find that you needed to take explicit control of the message formatting OR go the way of typed log attributes anyways.