[boost.log] Using stream manipulators to influence record formatting per sink
So I've been using the previously reviewed log library by Andrey Semashev with some degree of success. One thing however has caused me a great deal of trouble and I'm sure with a couple of changes would become a lot easier. Basically I have an application that outputs tabular data in the logs. I have objects that know how to stream themselves either as an ascii table or as an html table. I have a custom defined manipulator that can be set for a stream that the objects can check the value of, and stream themselves either as text or html as appropriate. In using the log library I face two major challenges. The first is how can I set the manipulator to the desired value so that the log record will be aware of the manipulator while building its message? It is not possible to do this by calling set_formatter() on the sink since the this receives *an already composed* record.message() string. My work-around for this is a lot more complex than I'd like it to be and I'll detail it here in the hope that it provides some insight to Andrey so that he might be able to offer a nicer alternative more in-keeping with his library. So starting at the beginning I have objects that implement streaming something like this: ---- template< class CharT, class Traits> friend std::basic_ostream< CharT, Traits>& operator<<( std::basic_ostream<CharT, Traits>& Ostream, const my_class& Value ) { if( log::output_format::value_in( Ostream ) == log::output_format::text ) { write_text( Ostream, Value ); } else if( log::output_format::value_in( Ostream ) == log::output_format::html ) { write_html( Ostream, Value ); } return Ostream; } ---- where 'value_in()' simply retrieves the value from the stream. Now during logging a temporary stream object is created that must have this manipulator applied. What I'd like to do is be able to specify if I want this manipulator applied on a per-sink basis. In much the same way as I can define a specific formatter for a sink, or a specific filtering rule for a sink. Currently there is no way to do that (at least not without a *lot* of effort) so I'll address this later. Instead I'll consider how we can deal with this be setting this desire globally by using a global attribute. We could write something like this: ---- log::output_format::type OutputFormat = log::output_format::html; std::pair< boost::log::core::attribute_set_type::iterator, bool > OutputFormatAttribute = boost::log::core::get()->add_global_attribute ( "OutputFormat", boost::make_shared< boost::log::attributes::constant<log::output_format::type> >( OutputFormat ) ); ---- Later we can extract this value to decide if we need the manipulator applied to the stream that is used to compose the log record message. We can use a helper object that is aware of all the manipulators that are to be applied and have it the log record stream based on attributes that represent them. For example, given a class called 'manipulators' we can define this insertion operator as: ---- template< class CharT, class TraitsT > inline std::basic_ostream<CharT,TraitsT>& operator<< ( std::basic_ostream<CharT,TraitsT>& Ostream, const manipulators& Manipulators ) { Manipulators.apply( Ostream ); return Ostream; } ---- where apply could be implemented (in our case) as this: --- template< class CharT, class TraitsT > void apply( std::basic_ostream<CharT,TraitsT>& Ostream ) const { boost::log::basic_record<CharT> Record( RecordHandle_ ); apply_output_format( Ostream, Record ); } private: ---- template< class CharT, class TraitsT > void apply_output_format( std::basic_ostream<CharT,TraitsT>& Ostream, const boost::log::basic_record<CharT>& Record ) const { log::output_format::type OutputFormat = log::output_format::text; boost::log::extract<log::output_format::type> ( "OutputFormat", Record.attribute_values(), boost::lambda::var( OutputFormat ) = boost::lambda::_1 ); if( OutputFormat == log::output_format::text ) { Ostream << log::set_output_format( log::output_format::text ); } else if( OutputFormat == log::output_format::html ) { Ostream << log::set_output_format( log::output_format::html ); } } ---- This then requires that the insertion operator is called as part of the streaming for any log record. In order to achieve this I need to write my own logging macros that do essentially what the severity logging macros do already but with the addition of streaming a 'manipulator' object at the same time so that the manipulators I want added can be applied to the stream that is constructed during that process. Here is the key macro that I need to write which gets substituted in a chanin of macros: ---- #define MY_LOG_STREAM_WITH_PARAMS_INTERNAL(logger, rec_var, params_seq)\ for (::boost::log::record_handle rec_var = (logger).open_record((BOOST_PP_SEQ_ENUM(params_seq))).handle(); !!rec_var; rec_var.reset())\ ::boost::log::aux::make_pump_stream((logger), rec_var).stream() << log::manipulators(rec_var) ---- The important part is this: ---- log::manipulators(rec_var) ---- The stream object is created and immediately passed an instance log::manipulators passing the RecordHandle to the constructor. Finally then I can have manipulators passed down to the stream that is used to create the log record message, and in my case allow the logged objects to either stream themselves as text or as html. A downside of this is that this only works with global attributes. So either all log sinks would one format or the other. Given that it is generally desirable to treat different sinks differently (and often the reason they exist) it would be much nice if there was the concept of sink-level attributes. These could be added to the record's attribute set along with the source and global attributes. Currently there is no way (it seems) to associate any state with a sink or make any decision during logging that relates to a sink. We can set a custom formatter that applies to the log message created but that has no effect on the record message itself. (Decorators only seem to be for post-processing of the record message). We can also set a custom filter to determine whether a log record gets logged by a given sink. It seems odd then that we have no way to to be able to say (for example) that a given sink will have an attribute that indicates that all messages through that sink should be in a certain format (for those objects that support the formatting). From looking at the code this does not appear to be a major issue so hopefully it could be supported. It would also be highly desirable to be able to specify manipulators directly that could then be applied to the record message stream itself. Supporting this at the global and sink level should be possible. If we had sink-level attributes the technique I described could be used to simulate this, even though it is somewhat kludgey. Most directed to Andrey, but I'd welcome comments and suggestions from others familiar with the log library. Jamie
On 11/09/2010 12:26 AM, Jamie Allsop wrote:
So I've been using the previously reviewed log library by Andrey Semashev with some degree of success. One thing however has caused me a great deal of trouble and I'm sure with a couple of changes would become a lot easier.
Basically I have an application that outputs tabular data in the logs. I have objects that know how to stream themselves either as an ascii table or as an html table. I have a custom defined manipulator that can be set for a stream that the objects can check the value of, and stream themselves either as text or html as appropriate.
In using the log library I face two major challenges. The first is how can I set the manipulator to the desired value so that the log record will be aware of the manipulator while building its message? It is not possible to do this by calling set_formatter() on the sink since the this receives *an already composed* record.message() string.
That's right, record message is composed only once, for all sinks. It is intended to be used for informational purposes, if you need a per-sink formatting logic then you should use sink formatters and attributes. This is a fundamental limitation, I don't think I'll be able to change it without severely compromising usability. I'd suggest attaching your objects as attributes to the log record and then put them into the stream either way in the sink formatter. I'd even decouple the object you have from the formatting logic but that's not strictly necessary. You'll have text_sink->set_formatter(fmt::stream << as_text("MyAttr")); and xml_sink->set_formatter(fmt::stream << as_xml("MyAttr")); where as_text and as_xml will both extract your objects from the "MyAttr" attribute in the log record and then apply the appropriate formatting. No need to imbue the stream with anything.
So starting at the beginning I have objects that implement streaming something like this:
[snip]
Given that it is generally desirable to treat different sinks differently (and often the reason they exist) it would be much nice if there was the concept of sink-level attributes. These could be added to the record's attribute set along with the source and global attributes.
Currently there is no way (it seems) to associate any state with a sink or make any decision during logging that relates to a sink. We can set a custom formatter that applies to the log message created but that has no effect on the record message itself. (Decorators only seem to be for post-processing of the record message). We can also set a custom filter to determine whether a log record gets logged by a given sink. It seems odd then that we have no way to to be able to say (for example) that a given sink will have an attribute that indicates that all messages through that sink should be in a certain format (for those objects that support the formatting). From looking at the code this does not appear to be a major issue so hopefully it could be supported.
I think you misunderstood the relations between sinks, filters and attributes. There can not be a sink-related attribute because it is attributes (or, more precisely, their values attached to the given record) decide which sinks will get the record. This decision is made by filters. Therefore each sink gets the same set of attribute values and at that point the set is fixed. It is the sink's nature, formatter included, what makes the same log record look different in files from different sinks. So you could maintain some kind of attributes in sinks but they wouldn't be able to participate in filtering and be injected into the record somehow, so they would be functionally equivalent to different sink formatters.
It would also be highly desirable to be able to specify manipulators directly that could then be applied to the record message stream itself. Supporting this at the global and sink level should be possible. If we had sink-level attributes the technique I described could be used to simulate this, even though it is somewhat kludgey.
One of the key ideas behind the library was to isolate the level of emitting log records and the library configuration level. Any given log record may potentially be processed by any set of sinks and the code that emits the record has no idea about which sinks and how will process it. So any processing nuances should be described in the library configuration code (in your case, I believe, sink formatters is the right place). I'd like not to expose any sink-related interaction to the user that wants to simply write something into log.
Andrey Semashev wrote:
On 11/09/2010 12:26 AM, Jamie Allsop wrote:
So I've been using the previously reviewed log library by Andrey Semashev with some degree of success. One thing however has caused me a great deal of trouble and I'm sure with a couple of changes would become a lot easier.
Basically I have an application that outputs tabular data in the logs. I have objects that know how to stream themselves either as an ascii table or as an html table. I have a custom defined manipulator that can be set for a stream that the objects can check the value of, and stream themselves either as text or html as appropriate.
In using the log library I face two major challenges. The first is how can I set the manipulator to the desired value so that the log record will be aware of the manipulator while building its message? It is not possible to do this by calling set_formatter() on the sink since the this receives *an already composed* record.message() string.
That's right, record message is composed only once, for all sinks. It is intended to be used for informational purposes, if you need a per-sink formatting logic then you should use sink formatters and attributes. This is a fundamental limitation, I don't think I'll be able to change it without severely compromising usability.
I guess that's my point. There is no ability to format the actual record message itself and I'm suggesting there should be. From the current design this is made impossible but I'm suggesting that perhaps it can be accommodated. Perhaps if I don't overload the meaning of attributes and focus only on manipulators I might make myself clearer. What I am suggesting is really two things: 1 - Allow for the possibility of passing manipulators down to the temporary stream object that is used to create the record message. Perhaps this might mean you need to add some sort of manipulator facility much like your attribute facility. This would then allow you to write your formatters in such a way so as the record message could be composed using a stream with the appropriate manipulators present. In my example that would mean 'output_format' would be set appropriately so streamed objects would know how to stream themselves as the record message is composed. Initially with the current design only global manipulators would be supported since, as you say, the record message is composed only once. 2 - The second thing I am suggesting is that manipulators also be supported per-sink. This seems to be a natural extension of what sinks do, they decide if a record should be written or not and what format the overall message should be written in. In order to support that you would of course have to compose the log record message lazily once for each sink with different manipulators, but only once, as we do now, if all sinks had either no manipulators or the same manipulators. Not trivial but not too complex either.
I'd suggest attaching your objects as attributes to the log record and then put them into the stream either way in the sink formatter. I'd even decouple the object you have from the formatting logic but that's not strictly necessary. You'll have
text_sink->set_formatter(fmt::stream << as_text("MyAttr"));
and
xml_sink->set_formatter(fmt::stream << as_xml("MyAttr"));
where as_text and as_xml will both extract your objects from the "MyAttr" attribute in the log record and then apply the appropriate formatting. No need to imbue the stream with anything.
Hmm.. this is an interesting idea. Can you give me an example of what an actual log statement might look? I'm not visualising this. Currently I have a log statement something like this: LOG_DEBUG(logger) << table_object; If I set a the global_attribute to "OutputFormat" to html then the table outputs itself as html, otherwise it outputs itself as text. How would I do that using attributes as you suggest?
So starting at the beginning I have objects that implement streaming something like this:
[snip]
Given that it is generally desirable to treat different sinks differently (and often the reason they exist) it would be much nice if there was the concept of sink-level attributes. These could be added to the record's attribute set along with the source and global attributes.
Currently there is no way (it seems) to associate any state with a sink or make any decision during logging that relates to a sink. We can set a custom formatter that applies to the log message created but that has no effect on the record message itself. (Decorators only seem to be for post-processing of the record message). We can also set a custom filter to determine whether a log record gets logged by a given sink. It seems odd then that we have no way to to be able to say (for example) that a given sink will have an attribute that indicates that all messages through that sink should be in a certain format (for those objects that support the formatting). From looking at the code this does not appear to be a major issue so hopefully it could be supported.
I think you misunderstood the relations between sinks, filters and attributes. There can not be a sink-related attribute because it is attributes (or, more precisely, their values attached to the given record) decide which sinks will get the record. This decision is made by filters. Therefore each sink gets the same set of attribute values and at that point the set is fixed. It is the sink's nature, formatter included, what makes the same log record look different in files from different sinks. So you could maintain some kind of attributes in sinks but they wouldn't be able to participate in filtering and be injected into the record somehow, so they would be functionally equivalent to different sink formatters.
I guess my point was that the sink has no way to make the record.message() look any differently and that is where the real information is. Yes you can provide different formatting around the record message but not the message itself. Everything else is mostly window dressing, like timestamps etc. It certainly all has value of course. I'm just looking for a way to control formatting of the log record message itself.
It would also be highly desirable to be able to specify manipulators directly that could then be applied to the record message stream itself. Supporting this at the global and sink level should be possible. If we had sink-level attributes the technique I described could be used to simulate this, even though it is somewhat kludgey.
One of the key ideas behind the library was to isolate the level of emitting log records and the library configuration level. Any given log record may potentially be processed by any set of sinks and the code that emits the record has no idea about which sinks and how will process it. So any processing nuances should be described in the library configuration code (in your case, I believe, sink formatters is the right place). I'd like not to expose any sink-related interaction to the user that wants to simply write something into log.
I can see where you are coming from here. Bear in mind this all started from trying something very simple. I have objects that can represent their state as either plain ascii or as html. You *cannot* post-process that information. Originally I was directly streaming this information out and simply set the manipulator state to either text or html to get the appropriate output. I then decided to use your logging library as it seemed to support this. My first naive attempt to do this was to simply add the call to set_output_format( log::output_format::html ) to the custom formatter for a sink. Of course I found that it had no effect on the record message itself. After a little thought it was clear why it did not work, but that did not mean it was not a reasonable expectation. There should be a simple way to achieve this. Thanks for your considered reply.
On 11/10/2010 01:39 AM, Jamie Allsop wrote:
Andrey Semashev wrote:
On 11/09/2010 12:26 AM, Jamie Allsop wrote:
That's right, record message is composed only once, for all sinks. It is intended to be used for informational purposes, if you need a per-sink formatting logic then you should use sink formatters and attributes. This is a fundamental limitation, I don't think I'll be able to change it without severely compromising usability.
I guess that's my point. There is no ability to format the actual record message itself and I'm suggesting there should be. From the current design this is made impossible but I'm suggesting that perhaps it can be accommodated. Perhaps if I don't overload the meaning of attributes and focus only on manipulators I might make myself clearer. What I am suggesting is really two things:
1 - Allow for the possibility of passing manipulators down to the temporary stream object that is used to create the record message. Perhaps this might mean you need to add some sort of manipulator facility much like your attribute facility. This would then allow you to write your formatters in such a way so as the record message could be composed using a stream with the appropriate manipulators present.
2 - The second thing I am suggesting is that manipulators also be supported per-sink. This seems to be a natural extension of what sinks do, they decide if a record should be written or not and what format the overall message should be written in. In order to support that you would of course have to compose the log record message lazily once for each sink with different manipulators, but only once, as we do now, if all sinks had either no manipulators or the same manipulators. Not trivial but not too complex either.
I'd say that it is #2 that is necessary to achieve your goal, since the necessary manipulators or whatever can be applied in the formatter, which is sink-specific already. Regarding lazy formatting, I considered this approach when I started the library. The main drawback of this approach (which led to its rejection) is that lazy expressions complicate logging in non-obvious ways. Consider this expression, for instance: BOOST_LOG(lg) << my_obj; Normally you would expect that my_obj is inserted into a stream here, using a possibly user-defined operator<<. However, would that be a lazy expression, my_obj would have been copied here, possibly several times (proportionally to the number of streaming operators in the expression). There are other issues, such as compilation times and code bloat. I understand and share your reasoning, but I believe that for the most cases the current solution is optimal. The need to customize the record message is quite rare. However, I think the solution is possible, either by providing an alternative logging facilities (macros, loggers, stream placeholder, etc.) to implement lazy formatting, or by using some hybrid solution (e.g. by inserting some placeholder into the stream and later replacing it with the post-formatted objects). Either way, this would require modifying the library (mostly the log record class) and it's not completely clear to me what it would look like afterward. Meanwhile you can use attributes to achieve your goal.
I'd suggest attaching your objects as attributes to the log record and then put them into the stream either way in the sink formatter. I'd even decouple the object you have from the formatting logic but that's not strictly necessary. You'll have
text_sink->set_formatter(fmt::stream << as_text("MyAttr"));
and
xml_sink->set_formatter(fmt::stream << as_xml("MyAttr"));
where as_text and as_xml will both extract your objects from the "MyAttr" attribute in the log record and then apply the appropriate formatting. No need to imbue the stream with anything.
Hmm.. this is an interesting idea. Can you give me an example of what an actual log statement might look? I'm not visualising this.
The attribute can be set in a scope guard manner like this: BOOST_LOG_SCOPED_THREAD_TAG( "MyAttr", typeof(table_object), table_object); That way you'll put your table_object as a thread-specific constant attribute. There is a similar macro for the logger-specific attribute. Now the log statement is not crucial and can be as simple as that: BOOST_LOG(lg); Of course, if you want a message accompanying the record, you can add one. These two macros can be wrapped in a more concise macro like that #define MY_LOG(lg, table_object)\ {\ BOOST_LOG_SCOPED_THREAD_TAG(\ "MyAttr", typeof(table_object), table_object);\ BOOST_LOG(lg);\ }
participants (2)
-
Andrey Semashev -
Jamie Allsop