Since I'm D n00b I'll just post a couple of observations:

* I agree that it is a good idea just to use few log levels.

* I think is it is a misstake not to let formatting of the whole
log message be pluggable (i.e. not the free text message the
programmer writes). If I have created a special RFC5424 formatter
(with MSGID and STRUCTURED-DATA fields set according to the will
of my corporate masters) I want to resuse it in both the
FileLogger and a future TcpLogger without having to use
inheritance. Your "line format" formatter in FileLogger is a good
default formatter though.

    ///Kalle

When logging the severity level should convey a certain insight that the developer has about the code. This can be done with a 3 bit field. These are: known-cause, known-effect and breaks-flow.

This creates the following matrix:

KC KE BF Severity
=================
1  1  0  Trace
0  1  0  Info
1  0  0  Notice
0  0  0  Warning
1  1  1  Error
0  1  1  Critical
1  0  1  Severe
0  0  1  Fatal

A known cause is when the developer knows why a log event is made. e.g.: if you cannot open a file, you do not know why.
A known effect is when he/she knows what happens after. Basically, you can tell if it is a catch-all by this flag.

When a severity should only be handled by a debugger, the normal debug statement should be used. This is in essence a 4th bit.

I hope this helpful in the search for a good level system.

On Monday, 27 February 2012 at 18:10:15 UTC, Kalle Svensson wrote:
> * I agree that it is a good idea just to use few log levels.
>
> * I think is it is a misstake not to let formatting of the whole
> log message be pluggable (i.e. not the free text message the
> programmer writes). If I have created a special RFC5424 formatter
> (with MSGID and STRUCTURED-DATA fields set according to the will
> of my corporate masters) I want to resuse it in both the
> FileLogger and a future TcpLogger without having to use
> inheritance. Your "line format" formatter in FileLogger is a good
> default formatter though.

I second what Kalle Svensson is saying.

My belief is that when there are many log levels, people don't use them as intended or only use a subset of them, often a combination.


/ Mikael

On Thu, Mar 01, 2012 at 10:09:28AM +0100, Mikael Lindsten wrote:
> On Monday, 27 February 2012 at 18:10:15 UTC, Kalle Svensson wrote:
> >* I agree that it is a good idea just to use few log levels.
[...]
> I second what Kalle Svensson is saying.
> 
> My belief is that when there are many log levels, people don't use them as intended or only use a subset of them, often a combination.
[...]

I used to think that the more log levels, the better. But later, based on what I observe in real-life projects, I see that most people don't bother trying to figure out what each log level means (they are too lazy / busy to read the docs) so they just randomly pick one that "sounds right" (which usually is equal to "totally wrong"). Let this happen for a few iterations of the software, and you end up with so many wrong level messages that the whole log level system basically becomes useless. This problem gets worse proportionally to the number of people on the project.


T

-- 
What's a "hot crossed bun"? An angry rabbit.

On Feb 29, 2012, at 4:13 PM, Richard van Scheijen wrote:

> When logging the severity level should convey a certain insight that the developer has about the code. This can be done with a 3 bit field. These are: known-cause, known-effect and breaks-flow.
> 
> This creates the following matrix:
> 
> KC KE BF Severity
> =================
> 1  1  0  Trace
> 0  1  0  Info
> 1  0  0  Notice
> 0  0  0  Warning
> 1  1  1  Error
> 0  1  1  Critical
> 1  0  1  Severe
> 0  0  1  Fatal
> 
> A known cause is when the developer knows why a log event is made. e.g.: if you cannot open a file, you do not know why. A known effect is when he/she knows what happens after. Basically, you can tell if it is a catch-all by this flag.
> 
> When a severity should only be handled by a debugger, the normal debug statement should be used. This is in essence a 4th bit.

This is a really great breakdown of the log levels.  I've never seen it explained so clearly.  As a counterpoint, the important distinction I've found is primarily regarding what person should see a particular log line, and then only differentiated between INFO and ERROR messages.  Roughly:

* Developer-Trace
* Developer-Info
* Developer-Error
* Admin-Info
* Admin-Error
* All-Fatal

Typically, the Developer and Admin logs go to different locations, in which case the Admin log lines may be duplicated in the Developer logs to provide added context.  In any case, what I've found is that with more than a few log levels, people typically don't know how to classify things, severity becomes arbitrary, and log-levels are rendered largely useless.  So from the above, we have four severities: Trace, Info, Error, and Fatal, with flags to indicate what type of message is being logged: Developer or Admin (aka. User).

On Wed, 29 Feb 2012 18:13:30 -0600, Richard van Scheijen <dlang@mesadu.net> wrote:

> When logging the severity level should convey a certain insight
> that the developer has about the code. This can be done with a 3
> bit field. These are: known-cause, known-effect and breaks-flow.
>
> This creates the following matrix:
>
> KC KE BF Severity
> =================
> 1  1  0  Trace
> 0  1  0  Info
> 1  0  0  Notice
> 0  0  0  Warning
> 1  1  1  Error
> 0  1  1  Critical
> 1  0  1  Severe
> 0  0  1  Fatal
>
> A known cause is when the developer knows why a log event is
> made. e.g.: if you cannot open a file, you do not know why.
> A known effect is when he/she knows what happens after.
> Basically, you can tell if it is a catch-all by this flag.
>
> When a severity should only be handled by a debugger, the normal
> debug statement should be used. This is in essence a 4th bit.
>
> I hope this helpful in the search for a good level system.
>

vote++

I think establishing a good guideline as to log usage should be part of std.log's documentation. Making the bitflags a part of Severity might help cement this concept. It would also allow self documenting code, like:

log!(knownCause|unknownEffect|breaksFlow)("This is a severe message.");

On Thu, Mar 01, 2012 at 08:24:31PM -0600, Robert Jacques wrote:
> On Wed, 29 Feb 2012 18:13:30 -0600, Richard van Scheijen <dlang@mesadu.net> wrote:
> 
> >When logging the severity level should convey a certain insight that the developer has about the code. This can be done with a 3 bit field. These are: known-cause, known-effect and breaks-flow.
> >
> >This creates the following matrix:
> >
> >KC KE BF Severity
> >=================
> >1  1  0  Trace
> >0  1  0  Info
> >1  0  0  Notice
> >0  0  0  Warning
> >1  1  1  Error
> >0  1  1  Critical
> >1  0  1  Severe
> >0  0  1  Fatal
> >
> >A known cause is when the developer knows why a log event is made. e.g.: if you cannot open a file, you do not know why. A known effect is when he/she knows what happens after. Basically, you can tell if it is a catch-all by this flag.
> >
> >When a severity should only be handled by a debugger, the normal debug statement should be used. This is in essence a 4th bit.
> >
> >I hope this helpful in the search for a good level system.
> >
> 
> vote++
> 
> I think establishing a good guideline as to log usage should be part of std.log's documentation. Making the bitflags a part of Severity might help cement this concept. It would also allow self documenting code, like:
> 
> log!(knownCause|unknownEffect|breaksFlow)("This is a severe message.");

+1. I like this *much* better than "info", "notice", ... etc.


T

-- 
"I'm not childish; I'm just in touch with the child within!" - RL

On 2/13/2012 7:50 AM, David Nadlinger wrote:
> There are several modules in the review queue right now, and to get things going, I have volunteered to manage the review of Jose's std.log proposal. Barring any objections, the review period starts now and ends in three weeks, on March 6th, followed by a week of voting.
> 
> ---
> Code: https://github.com/jsancio/phobos/commit/d114420e0791c704f6899d81a0293cbd3cc8e6f5 Docs: http://jsancio.github.com/phobos/phobos/std_log.html
> 
> Known remaining issues:
>  - Proof-reading of the docs is required.
>  - Not yet fully tested on Windows.
> 
> Depends on: https://github.com/D-Programming-Language/druntime/pull/141 (will be part of 2.058)
> ---
> 
> Earlier drafts of this library were discussed last year, just search the NG and ML archives for "std.log".
> 
> I think getting this right is vitally important so that we can avoid an abundance of partly incompatible logging libraries like in Java. Thus, I'd warmly encourage everyone to actively try out the module or compare it with any logging solution you might already be using in your project.
> 
> Please post all feedback in this thread, and remember: Although comprehensive reviews are obviously appreciated, short comments are very welcome as well!
> 
> David

My 2 cents from a fairly quick scan of the docs:

1) I'm of the opinion that it should be possible to strip all log code from an app without changing it's behavior. Having log levels that change execution flow is evil.  It's it the same class of bad practices as assert expressions having side effects, imho.

2) Apps over a certain size (that tends to not be all that big, a few 10's of thousands of lines) tend to start to need module based logging.  This proposal includes a set of log levels that have no concept of modularity and another separate set that do.  The distinction seems arbitrary and limiting.

3) The conditional stuff seems cute, but I can't recall ever wanting it in anything I've done before.

4) I don't see an obvious facility for changing log parameters at runtime, unless the intent is to build a paramstring array as if it came from command line parameters and calling parseCommandLine again.  use case: long running application that has a configuration api or notices a config file has been updated or whatever.  Fairly common behavior.

5) The logger severity symbols part should allow more than single character tokens.  IMHO, the default should be the full name of the severity, not just the first character.

6) Is the log system thread safe?  I see that it's at least thread aware, but what guarantees are about log entry atomicity?

7) The logger setter docs says it's an error to change the logger after a log message has been emitted.  That's going to hurt.  It's not at all uncommon for an app to want to log some set of errors before it's potentially had enough time to execute the code that configures the logger.  use case: reading a config file to get the logger configuration, but can't process the config file properly.

Later,
Brad

Am 17.02.2012 21:48, schrieb Andrei Alexandrescu:
> On 2/17/12 12:06 PM, Jose Armando Garcia wrote:
>> info("%s message", Severity.info);
>
> I think defaulting to formatted stuff may be confusing.
>
> Andrei

Do you often log static messages? In my experience the majority of logging calls contains dynamic information and using a format string is the most convenient and readable form (compared to concatenating using multiple arguments).

An additional infof(), warnf() etc. would be an acceptable alternative, although not very pretty. But if you'd always have to write info.format() or something similar, then this would be a real turn-off, at least for me.

> log!(knownCause|unknownEffect|breaksFlow)("This is a severe message.");

Simply defining log level enum in terms of this bit field would help a lot.
Like, what is the first thing I do when getting a new log lib? Checking all
pre-defined log levels and deciding when to use them. And, woah, here it is, subtle but formal guide for use cases!