Re: [boost] [logging] Interest check on logging library.

-------Original Message------- From: Emil Dotchevski <emildotchevski@gmail.com> Subject: Re: [boost] [logging] Interest check on logging library. Sent: 27 Dec '08 15:25
On Fri, Dec 26, 2008 at 9:48 AM, Jason Wagner <jason@nialscorva.net> wrote:
Hello all,
I know there are two proposed logging libraries out there for Boost, already, but I had a different itch to scratch on a project. I think I saw that Andrey Semashev was going to submit his far more mature version soon, but I thought I'd throw my technique out there for an interest check and hopefully commentary. This is very much a prototype-- there's a lot of work yet to be done but the basic outline and functionality is implemented.
Getting the code ---------------- http://www.nialscorva.net/boost_logging-0_1.tar.bz2
What is the motivation for using boost::mpl in the logging library? I didn't look too deeply into your code, but wouldn't something like this work just as well:
struct logging_debug; struct logging_release;
template <class> struct logging_traits;
template <> logging_traits<logging_debug> { .... };
In other words, let the user provide an explicit specialization to configure the logger; once that's done, they just do:
logger<logging_debug> log;
This handles severity, but not necessarily other conditions. The library handles a more general case of this. In the use cases I'm working on, there are multiple independant tags on a record, severity being only one: severity := trace | debug | info | notice | warn | error | fatal // syslog levels, may be missing one build_type := release | debug The logger defines what, if any, conditions of these attributes a record must meet before being logged: logger< mpl::vector< condition::greater_equal<severity::info>, condition::in<build_target::debug>
log;
The logger<logging_debug> log; is equivalent to logger<mpl::vector<condition::greater_equal<severity::debug> > > log; A simple use case would be when you want to put more information into a debug build target than a release build target for the same level of severity: log << severity::info() << "An event that you should be informed of occurred" << build_target::debug() << " debugging information: " << dump_lots_of_info() << end_record(); User defined tag types are extremely easy to make and integrate seamlessly. In the application I'll be using this for, I'll have tags for build_target (client, server, possibly one of several types of server). This could be done via severity levels, but it would be fitting orthogonal concerns into a single enumeration.
My reasoning is that a logging library should be lightweight in terms of source code; when I need logging, I'd rather not get boost::mpl too.
Understandable. Everything's a matter of tradeoffs. The project I'm working on has a slightly more involved logging use case. One concern I have is how much compile times will be affected by MPL and the templates I'm using and whether the flexibility is worth the cost.
A few more comments:
In general I don't like using macros or #ifdefs, but one place where I think they are OK is in a logging library interface, partially because they make it much lighter, and partially because automatically logging __FILE__, __LINE__, etc. is desirable IMO.
I'm differentiating macros from simple defines. #define LOG_LINE filename(__FILE__) << line(__LINE__) << function(__FUNCTION__) will be in the library in some form in the future.
Finally, I think that all the machinery a typical logging lib uses to kill logging expressions when they're not needed is an overkill. I've found that using something as simple as the code below works just fine:
namespace logging { static bool const warnings=false; static bool const errors=true; }
and then:
if( logging::warnings ) log << "Warning";
where log simply implements std::ostream.
You could put the if in a macro but frankly, I personally don't mind typing it every time; compared to the rest of the junk I have to type to format a meaningful logging message, the if is not an issue. As a bonus, you don't have to worry about functions referenced by a logging expression being executed when logging is not enabled.
I'm not a fan of the macros, either. What's really the difference between what you wrote and: LOG_DEBUG(log) << "Warning"; other than the latter being ugly. One of the needs I have is sending output to multiple sinks and reconfiguring filter conditions on the fly (runtime conditions, nt compile time conditions). The if() becomes more complicated and there's visual overhead in having code to change the condition and the potential for typos in non-trivial checks. Hiding that complexity makes the real code more readable and maintainable. That being said, my approach may be overkill for situations of writing to a single file based upon simple variables. I don't think the implementation complexity for the end-user is too high, but it's all about what your needs are.
-- Emil Dotchevski Reverge Studios, Inc. http://www.revergestudios.com/reblog/index.php?n=ReCode _______________________________________________ Unsubscribe & other changes: http://lists.boost.org/mailman/listinfo.cgi/boost
--- Jason Wagner jason@nialscorva.net

on Sat Dec 27 2008, "Jason Wagner" <jason-AT-nialscorva.net> wrote:
My reasoning is that a logging library should be lightweight in terms of source code; when I need logging, I'd rather not get boost::mpl too.
Understandable. Everything's a matter of tradeoffs. The project I'm working on has a slightly more involved logging use case. One concern I have is how much compile times will be affected by MPL and the templates I'm using and whether the flexibility is worth the cost.
One should keep in mind that MPL is specifically designed to avoid needless compile-time costs. Drawing in a few MPL headers may not be a measurable expense. -- Dave Abrahams BoostPro Computing http://www.boostpro.com

On Sat, Dec 27, 2008 at 3:13 PM, David Abrahams <dave@boostpro.com> wrote:
on Sat Dec 27 2008, "Jason Wagner" <jason-AT-nialscorva.net> wrote:
My reasoning is that a logging library should be lightweight in terms of source code; when I need logging, I'd rather not get boost::mpl too.
Understandable. Everything's a matter of tradeoffs. The project I'm working on has a slightly more involved logging use case. One concern I have is how much compile times will be affected by MPL and the templates I'm using and whether the flexibility is worth the cost.
One should keep in mind that MPL is specifically designed to avoid needless compile-time costs. Drawing in a few MPL headers may not be a measurable expense.
I am not against using MPL together with the logging library, but ideally I'd like that to be a user decision. Why not have the logging library use something like logging_traits::flag, where "flag" is user-specified and might use MPL, but might also be simply "true" or "false". I understand the logging library interface is more complex than this but the general approach I'm describing is applicable, is it not? -- Emil Dotchevski Reverge Studios, Inc. http://www.revergestudios.com/reblog/index.php?n=ReCode

On Sat, Dec 27, 2008 at 12:18 PM, Jason Wagner <jason@nialscorva.net> wrote:
-------Original Message------- I'm differentiating macros from simple defines.
#define LOG_LINE filename(__FILE__) << line(__LINE__) << function(__FUNCTION__)
will be in the library in some form in the future.
That would work when the user explicitly wants to log __FILE__ or __LINE__ but I meant that it's desirable to log them implicitly, automatically. To make this work, you need the logging itself to use macros, which I think is quite fine.
if( logging::warnings ) log << "Warning";
where log simply implements std::ostream.
You could put the if in a macro but frankly, I personally don't mind typing it every time; compared to the rest of the junk I have to type to format a meaningful logging message, the if is not an issue. As a bonus, you don't have to worry about functions referenced by a logging expression being executed when logging is not enabled.
I'm not a fan of the macros, either. What's really the difference between what you wrote and:
LOG_DEBUG(log) << "Warning";
other than the latter being ugly.
I don't find LOG_DEBUG(log)<<"Warning" ugly at all, my point was that the reason you'd use something like LOG_DEBUG(log)<<"foo" or log<<severity::info()<<"foo" is so that the logging expression could compile to nothing depending on how the logging is configured. My point was that I think it's better to leave it up to the user to deal with the condition "manually", as in if( logging::warnings ) log << "Warning"; or if( logging::warnings && logging::severity>10 ) log << "Severe warning"; or even if( logging::warnings ) { log << "Warning"; if( logging::severity>10 ) log << "Severe warning"; } That way the logging library only needs to expose two independent interfaces, one that provides the "log" object (which is just a std::ostream &) and another that provides convenient compile-time or run-time flags for users to type in if statements as above. Emil Dotchevski Reverge Studios, Inc. http://www.revergestudios.com/reblog/index.php?n=ReCode

On Sat, 27 Dec 2008 21:02:51 -0500, Emil Dotchevski <emildotchevski@gmail.com> wrote:
[snip] My point was that I think it's better to leave it up to the user to deal with the condition "manually", as in if( logging::warnings ) log << "Warning"; or if( logging::warnings && logging::severity>10 ) log << "Severe warning"; or even if( logging::warnings ) { log << "Warning"; if( logging::severity>10 ) log << "Severe warning"; } That way the logging library only needs to expose two independent interfaces, one that provides the "log" object (which is just a std::ostream &) and another that provides convenient compile-time or run-time flags for users to type in if statements as above.
One of the projects I deal with can generate several hundred MB of logs over the course of a day if we have logging cranked up. We log both as an light audit trail and a debugging tool. Dealing with that much information can become rather difficult. There are a few things that come to mind that I would change in it: 1) When reading the code, logging should scan like a comments-- they should be readable and informative but ignorable. A lot of logic, conditionals, or even excessive formatting distracts from figuring out what a function actually does. Severity (debug, warning, error, etc) is only one dimension, though the most common. If I add new dimensions, how much does that affect complexity of the conditionals? What are the chances of mistyping one of the conditionals and not getting a logging message? 2) The logging output needs to be well formatted, readable, and broken up into manageable pieces. Imagine getting a packet or request in, then having to dump it. Does it show up as one or two records? Does it end up on a 500 character wide line? How much overhead should one add to the site of the logging call to format this? If I split my files into an log file that contains everything and an audit file that only contains some, should the formatting be the same? What if I want to merge them at a later time, do I need to edit everything and recompile? What if I want to change output and direction at runtime? Do I think of all of that in the function, or do I configure the logging and just let it fly? The former implies that there should be an abstraction around the logic of whether a record gets logged. The latter implies an abstraction around formatting and how to determine the destination of the record. That and a few extra bows is the extent of what I'm trying to do. -- Jason Wagner jason@nialscorva.net

Jason Wagner wrote:
One of the projects I deal with can generate several hundred MB of logs over the course of a day if we have logging cranked up. We log both as an light audit trail and a debugging tool. Dealing with that much information can become rather difficult. There are a few things that come to mind that I would change in it:
1) When reading the code, logging should scan like a comments-- they should be readable and informative but ignorable. A lot of logic, conditionals, or even excessive formatting distracts from figuring out what a function actually does. Severity (debug, warning, error, etc) is only one dimension, though the most common. If I add new dimensions, how much does that affect complexity of the conditionals? What are the chances of mistyping one of the conditionals and not getting a logging message?
2) The logging output needs to be well formatted, readable, and broken up into manageable pieces. Imagine getting a packet or request in, then having to dump it. Does it show up as one or two records? Does it end up on a 500 character wide line? How much overhead should one add to the site of the logging call to format this? If I split my files into an log file that contains everything and an audit file that only contains some, should the formatting be the same? What if I want to merge them at a later time, do I need to edit everything and recompile? What if I want to change output and direction at runtime? Do I think of all of that in the function, or do I configure the logging and just let it fly?
The former implies that there should be an abstraction around the logic of whether a record gets logged. The latter implies an abstraction around formatting and how to determine the destination of the record. That and a few extra bows is the extent of what I'm trying to do.
Sorry, couldn't resist. I think, my library fits these requirements quite well. Why would you start your own implementation from scratch? Is there something that doesn't suit you in my implementation?

Andrey Semashev wrote:
Jason Wagner wrote: [...]
Sorry, couldn't resist. I think, my library fits these requirements quite well. Why would you start your own implementation from scratch? Is there something that doesn't suit you in my implementation?
If I recall your library requires a lib to be linked in. That's a deal breaker for me. This library seems to move away from that. What I really need is captured in my review of John Torjo's second library <http://lists.boost.org/Archives/boost/2008/02/133462.php> I'd be interested if either library can support this minimal use case. Jamie

Jamie Allsop wrote:
If I recall your library requires a lib to be linked in. That's a deal breaker for me.
That is true, the library has to be compiled. If it is to support multi-module configuration with centralized logging control, I don't see how it could be done the other way.
This library seems to move away from that. What I really need is captured in my review of John Torjo's second library <http://lists.boost.org/Archives/boost/2008/02/133462.php>
I'd be interested if either library can support this minimal use case.
From what I read there, I'm pretty close to that, aside this part: "users of the library must be able to use the libraries without logging enabled and pay no cost". The cost will always be there since there will be a run time check whether to write logs or not. My lib does filtering for that matter.

On Thu, Jan 1, 2009 at 7:01 AM, Andrey Semashev <andrey.semashev@gmail.com> wrote:
Jamie Allsop wrote:
If I recall your library requires a lib to be linked in. That's a deal breaker for me.
That is true, the library has to be compiled. If it is to support multi-module configuration with centralized logging control, I don't see how it could be done the other way.
This is slightly off-topic but I think that Boost would have been much better collection of libs if from the beginning it had adopted a policy of placing as much code as possible in cpp files. Besides the simple fact that this approach would have drastically reduced the amount of code visible to users, it would have also affected the way libraries are designed. If anyone cares whether a library is header-only or not, they need a better build system. :) Emil Dotchevski Reverge Studios, Inc. http://www.revergestudios.com/reblog/index.php?n=ReCode

on Thu Jan 01 2009, Andrey Semashev <andrey.semashev-AT-gmail.com> wrote:
Jamie Allsop wrote:
If I recall your library requires a lib to be linked in. That's a deal breaker for me.
That is true, the library has to be compiled. If it is to support multi-module configuration with centralized logging control, I don't see how it could be done the other way.
It's possible to build libraries so they can support both separately-compiled and header-only (possibly with reduced functionality) models. You can find threads about that in the message history for this list. -- Dave Abrahams BoostPro Computing http://www.boostpro.com

On Wed, 31 Dec 2008 21:43:22 -0500, Jamie Allsop <ja11sop@yahoo.co.uk> wrote:
Andrey Semashev wrote:
Jason Wagner wrote: [...] Sorry, couldn't resist. I think, my library fits these requirements quite well. Why would you start your own implementation from scratch? Is there something that doesn't suit you in my implementation?
If I recall your library requires a lib to be linked in. That's a deal breaker for me. This library seems to move away from that. What I really need is captured in my review of John Torjo's second library <http://lists.boost.org/Archives/boost/2008/02/133462.php>
I'd be interested if either library can support this minimal use case.
Jamie
The design on my version is for the core to be a hierarchical configuration utility. There is a root logger config that everything descends from. It's actually the area I'm trying to work on now and looks like: bl::core core; core.action("test_action") .set_filter(bl::severity() > bl::severity::warning()) .on_success(core.file_sink("warnings.txt")); core.channel("") .set_filter(bl::severity() > bl::var("LOGGING_THRESHOLD")) .on_success(core.file_logger("my_log.txt")) .on_failure(core.file_logger("my_failure.txt")) .value("LOGGING_THRESHOLD", bl::severity::info::value) ; core.channel("server") .value("LOGGING_THRESHOLD", bl::severity::debug::value); core.channel("server.network") .on_success(core.action("test_action")); bl::logger<> logger(core.channel("server.network")); This code is not in the tarball I threw up and shouldn't be considered final, btw. Each channel has a variable set and a filter chain associated with it. Channels can share filter chains. Channels are created on the fly when referenced, defaulting to their closest defined ancestor. Variables sets are inherited, so in this example "server.network" inherits the value of "LOGGING_THRESHOLD". Filter actions are not defaulted but not inherited. That means that: bl::logger<> log2(core.channel("server.network.foo")); will use the filter actions of "server.network", but "server.network" does not use the actions of "server" because it has a definition and is constructable anywhere. The core is mutable, so at any time you can call core.channel("server").value("LOGGING_THRESHOLD",bl::severity::warning::value); and change the value for everything that defaults to that value. If I understand what you wrote in the review, I belive I have a similar use-case. Formatters are not finalized, but would be attached to the sink (core.file_logger("") in the example). That's how you'd do it at runtime, which has a cost to evaluate. At compile time, you could use tags similar to my server example: // in some header typedef boost::mpl::vector< bl::condition::not_in<build_type::server>
conditions;
typedef bl::logger<conditions> my_logger_type; // in impl my_logger_type log; log << build_type::server() << "some logging"; This still has non-zero cost, but as near as I can determine it's on the same order as an empty function call. -- Jason Wagner jason@nialscorva.net
participants (5)
-
Andrey Semashev
-
David Abrahams
-
Emil Dotchevski
-
Jamie Allsop
-
Jason Wagner