Logging conventions

[Fabian Christ <ch...@googlemail.com>]

Hi,

I have a question about the used logging conventions in Stanbol. I see
log message for method entries and exits with log level INFO.
Furthermore, there seems to be no common standard how to write log
messages to make them easily readable and to find the position in the
code where the message came from.

My proposal would be to use the following conventions that I
personally use for my applications and that I have adopted from other
industrial projects.

- The default log level for messages is DEBUG (especially for logging
method entries/exits)
- Only use INFO if the message is important to follow the main flow of
the application. So if something happens that would be useful to note
if not in debug mode to see what is basically going on in the
application.
- Start log messages with the name of the method where the message was
created, e.g. log.debug("getSiteX() called with parameter {}",
parameter); - This makes it easy to find the log message in the code
and gives developers an immediate hint where the action took place
(beside the class).

WDYT?

Best,
-- 
Fabian

Re: Logging conventions

[Bertrand Delacretaz <bd...@apache.org>]

Hi,

On Thu, Apr 14, 2011 at 10:57 AM, Olivier Grisel
<ol...@ensta.org> wrote:
> 2011/4/14 Fabian Christ <ch...@googlemail.com>:
>> - The default log level for messages is DEBUG (especially for logging
>> method entries/exits)
>
> +1

Same here.

>>... - Only use INFO if the message is important to follow the main flow of
>> the application. So if something happens that would be useful to note
>> if not in debug mode to see what is basically going on in the
>> application....

Pretty much agree, use common sense here. What I often do is look at
the INFO logs once a component is working, and check if those tell a
useful story without too much noise.

>> - Start log messages with the name of the method where the message was
>> created, e.g. log.debug("getSiteX() called with parameter {}",
>> parameter); - This makes it easy to find the log message in the code
>> and gives developers an immediate hint where the action took place
>> (beside the class).
>
> I don't like that much. We already have the name of the class. If the
> message is informative enough, we should not have to display method
> names.

I also disagree - just make log messages explicit enough or unique
enough to make it easy to find where they point to.

> By the way, instead of polluting the source code with statements such as:
>
>  log.debug("getSiteX() called with parameter {}", parameter);
>
> developers should use the eclipse debugger...

or any other debugger, agree with that in the general case.

-Bertrand

Re: Logging conventions

[Olivier Grisel <ol...@ensta.org>]

2011/4/14 Fabian Christ <ch...@googlemail.com>:
> Hi,
>
> I have a question about the used logging conventions in Stanbol. I see
> log message for method entries and exits with log level INFO.
> Furthermore, there seems to be no common standard how to write log
> messages to make them easily readable and to find the position in the
> code where the message came from.
>
> My proposal would be to use the following conventions that I
> personally use for my applications and that I have adopted from other
> industrial projects.
>
> - The default log level for messages is DEBUG (especially for logging
> method entries/exits)

+1

> - Only use INFO if the message is important to follow the main flow of
> the application. So if something happens that would be useful to note
> if not in debug mode to see what is basically going on in the
> application.

As a rule of thumb we should use INFO to log administrative change of
the application (new bundle / component activation for instance) but
never for user induced events that can be numerous (handling a HTTP
requests on one of the endpoints, applying a rule or executing and
enhancer engine for instance).

> - Start log messages with the name of the method where the message was
> created, e.g. log.debug("getSiteX() called with parameter {}",
> parameter); - This makes it easy to find the log message in the code
> and gives developers an immediate hint where the action took place
> (beside the class).

I don't like that much. We already have the name of the class. If the
message is informative enough, we should not have to display method
names.

By the way, instead of polluting the source code with statements such as:

 log.debug("getSiteX() called with parameter {}", parameter);

developers should use the eclipse debugger such as explained towards
the end of the README file:

  http://svn.apache.org/repos/asf/incubator/stanbol/trunk/README.md

-- 
Olivier
http://twitter.com/ogrisel - http://github.com/ogrisel