Logging - Best Practices

[Rhino]

I'm trying to figure out the best way to set up logging for my
development shop. In a nutshell, I'd like the advice of experienced
developers/designers to figure out how many logs I should have and where
I should set each one up. To clarify what I mean, please allow me to
sketch a hypothetical situation which would illustrate my concerns.

Let's say that my company is called Foo Inc. My Java development is done
using Eclipse. Various projects are on the go, including Baz and Fuzz.
There is also a body of existing code that does various useful things,
like general utilities.

The Baz project has its own package, com.foo.baz, and includes all the
classes used exclusively by Baz, including:
- Supremo (the main class that invokes the other Baz classes)
- Alpha
- Beta
- Gamma
There is also a com.foo.baz.Resources package within the Baz project
containing resource bundles used by Baz.

The Fuzz project has its own package, com.foo.fuzz, and includes all the
classes used by Fuzz, including:
- Boss (the main class that invokes the other Fuzz classes)
- Grunt1
- Grunt2
- Grunt3
There is also a com.foo.fuzz.Resources package within the Fuzz project
containing resource bundles used by Fuzz.

The more general code is in its own project, Common, and is organized
into various specialized packages, including:
- com.foo.common (miscellaneous common code)
- com.foo.common.Resources (resource bundles for com.foo.common)
- com.foo.common.error (common code used for error handling)
- com.foo.common.error.Resources (resource bundles for
com.foo.common.error)
- com.foo.common.utilities (commonly used utilties of one kind or
another)
- com.foo.common.utilities.Resources (resource bundles for
com.foo.common.utilities)

Okay, now that I've set the scene, let me ask some specific questions
that will help me figure out the best ways to organize my logging.

1. Should I make use of levels of Loggers here? For example, should I
have a master Logger that contains all important messages written to any
package whose name starts with com.foo, i.e. any message written by any
of my classes that is of appropriate severity? And then have separate
project-level Logger for com.foo.baz and com.foo.fuzz? Or should I not
bother with the "master" log and just create separate logs for
com.foo.baz and com.foo.fuzz? I can see some advantages to having a
master log: it could contain only records indicating relatively severe
situations so that management could exercise oversight (and verify that a
given problem was being addressed) while all messages, serious and minor,
could be written to the project-level log for detailed monitoring by
developers.

2. Should there be a separate log for log records written by common code,
i.e. everything that has a package name starting with com.foo.common? Or
should log records generated by the common classes be written to the logs
of common.foo.baz or common.foo.fuzz, depending on which project invoked
the common code? For example, let's say that com.foo.Fuzz.Grunt1
instantiation com.foo.common.utilities.StringUtils and StringUtils wants
to log something. Should StringUtils write to a log that is associated
with com.foo.Fuzz or one that is associated with com.foo.common?

I think I'll have some followup questions once I've heard the answers to
these so I'll hold off for now.

 

[Lew]

I'm trying to figure out the best way to set up logging for my
development shop. In a nutshell, I'd like the advice of experienced

Logging isn't for development, it's for production.

Not that developers won't find it useful, but the focus on your
logging strategy should be to support maintenance in the field. That
will make it the most useful for other project phases as well.

Consider: A successful project should spend lots more time in
production than in development. In production, problems are always
urgent and tend to be expensive. The ability to troubleshoot and fix
problems in the field is commensurately important.

Design your logging strategy, including a *standardized* log-file
format, to support maintenance and troubleshooting in the field.

developers/designers to figure out how many logs I should have and where
I should set each one up. To clarify what I mean, please allow me to

Set up logging wherever it makes sense for each deployment
environment. There should be, generally, one log or set of logs per
deployed application.

sketch a hypothetical situation which would illustrate my concerns.

Let's say that my company is called Foo Inc. My Java development is done
using Eclipse. Various projects are on the go, including Baz and Fuzz.
There is also a body of existing code that does various useful things,
like general utilities.

... blah, blah, ...

The more general code is in its own project, Common, and is organized
into various specialized packages, including:
... blah, blah, ...

1. Should I make use of levels of Loggers here? For example, should I
Yes.

have a master Logger that contains all important messages written to any
package whose name starts with com.foo, i.e. any message written by any
of my classes that is of appropriate severity? And then have separate

Severity is adjusted in the field as problems or concerns arise, and
not fixed at design time.

... blah, blah, ...

2. Should there be a separate log for log records written by common code,

That depends. Consider if you were the sysadmin for the project in
production. Where would you look for logs? How many logs would you
want to wade through to find the important information? What
information should be presented, and in what layout to make relevant
data accessible?

Don't think so much in terms of packages as applications. You will
adjust logging levels in the field, i.e., long after development is
done, and then you will likely do so on a package-by-package basis
depending on whence the trouble emanates. Typically one logs at ERROR
or WARN level (thinking in log4j here) until there's trouble, then
drops to INFO or DEBUG for selected packages to narrow down where the
problem lies.

There is no static answer; logging is a dynamic beast. Don't design
logging like a programmer - we programmers are stupid about making
software actually work in real life. Think like a sysadmin - those
are the folks with the real brains.

 

[Rhino]

Logging isn't for development, it's for production.

Not that developers won't find it useful, but the focus on your
logging strategy should be to support maintenance in the field.  That
will make it the most useful for other project phases as well.

Consider:  A successful project should spend lots more time in
production than in development.  In production, problems are always
urgent and tend to be expensive.  The ability to troubleshoot and fix
problems in the field is commensurately important.

Design your logging strategy, including a *standardized* log-file
format, to support maintenance and troubleshooting in the field.

Fair enough. I can't fault your logic . Of course, in an ideal
world we, as developers, release brilliant bug-free/trouble-free
programs and the field never sees a problem ;-)

Set up logging wherever it makes sense for each deployment
environment.  There should be, generally, one log or set of logs per
deployed application.
Okay....

Severity is adjusted in the field as problems or concerns arise, and
not fixed at design time.

I'm not sure I'd agree with that. Certainly, the severity of the
event, whatever it is, may be ASSESSED differently in the field than
it was by the developers. For instance, something thought minor by
developers may be thought a big deal in the field or vice versa. But
the developer still has to assign a severity to each log record that
may be generated and set the levels captured by the logs at
development time. Those choices may be changed later in the life of
the system as developers interact with folks in the field but the
developer is surely going to make the initial decision, hopefully in
consultation with folks in the field.

That depends.  Consider if you were the sysadmin for the project in
production.  Where would you look for logs?  

I'm really not sure where a sysadmin in a large (or even small)
organization would look. I haven't deployed a lot of Java applications
that used logging. Also, I'd expect that each organization would be
different in terms of where a sysadmin would expect to look. That, of
course, makes my question very difficult to answer. I don't expect a
simple, definitive answer that would fit every organization. I'm
mostly just trying to get a feel for where a typical sysadmin in a
typical organization would expect to look.

So, for example, if the Baz system calls a class from a common module
to display a date in a particular obscure format and that common class
generates a relatively severe log record, should that record be
written only to a log set up for the common code alone? Or would it be
better to write it to a log associated with the application? I'm
strongly inclined to favour the latter. Of course, since that common
code might be called from several different applications, which might
well be in very packages, I'm assuming that a reference to the logger
would need to be passed to the common code so that it knew which log
to write to. On the other hand, if the log records from the common
classes was always written to its own log, then the log reference
could be generated within the class and not passed from outside.

How many logs would you
want to wade through to find the important information?  What
information should be presented, and in what layout to make relevant
data accessible?

Don't think so much in terms of packages as applications.  You will
adjust logging levels in the field, i.e., long after development is
done, and then you will likely do so on a package-by-package basis
depending on whence the trouble emanates.  Typically one logs at ERROR
or WARN level (thinking in log4j here) until there's trouble, then
drops to INFO or DEBUG for selected packages to narrow down where the
problem lies.

There is no static answer; logging is a dynamic beast.  Don't design
logging like a programmer - we programmers are stupid about making
software actually work in real life.  Think like a sysadmin - those
are the folks with the real brains.

Fair enough. I appreciate the advice. I agree that it is probably best
to answer these questions by thinking from the sysadmin point of view.
I may just talk to a sysadmin friend to see what what his take is....

Thanks for your advice!

 

[Lew]

I'm not sure I'd agree with that. Certainly, the severity of the
event, whatever it is, may be ASSESSED differently in the field than
it was by the developers. For instance, something thought minor by

Logging packages such as java.util.logging and log4j are explicitly designed
and documented to be adjusted in the field. Regardless of your agreement,
people are trained to adjust logging in the field as circumstances dictate.
That's a best practice, and the reality.

developers may be thought a big deal in the field or vice versa. But

The "big deal" in the field is when something stops working correctly.

Until then, DEBUG gives far too much detail for usefulness. After then, it's
mandatory.

Logging levels are not up to the programmer.

the developer still has to assign a severity to each log record that
may be generated and set the levels captured by the logs at
development time. Those choices may be changed later in the life of

That is set by the sysadmin, not the developers.

the system as developers interact with folks in the field but the
developer is surely going to make the initial decision, hopefully in
consultation with folks in the field.
Nope.


I'm really not sure where a sysadmin in a large (or even small)
organization would look. I haven't deployed a lot of Java applications
that used logging. Also, I'd expect that each organization would be
different in terms of where a sysadmin would expect to look. That, of
course, makes my question very difficult to answer. I don't expect a
simple, definitive answer that would fit every organization. I'm
mostly just trying to get a feel for where a typical sysadmin in a
typical organization would expect to look.

How about the "logs" directory?

So, for example, if the Baz system calls a class from a common module
to display a date in a particular obscure format and that common class
generates a relatively severe log record, should that record be
written only to a log set up for the common code alone? Or would it be
No.

better to write it to a log associated with the application? I'm
Yes.

strongly inclined to favour the latter. Of course, since that common
code might be called from several different applications, which might
well be in very packages, I'm assuming that a reference to the logger
would need to be passed to the common code so that it knew which log
to write to. On the other hand, if the log records from the common

That's not how log configuration works. You set up a log configuration for
the application that encompasses everything, not just the code you wrote but
the Java API, third-party libraries and so on.

classes was always written to its own log, then the log reference
could be generated within the class and not passed from outside.

Huh?

What do you mean by "the log reference"?

What do you mean by "generated within the class"?

What do you mean by "passed from outside"?

Those phrases don't correlate to my experience with logging frameworks,
writing log statements or perusing logs to attempt to solve a problem. Tha
experience is robust.

Fair enough. I appreciate the advice. I agree that it is probably best
to answer these questions by thinking from the sysadmin point of view.
I may just talk to a sysadmin friend to see what what his take is....

Well, good. How else would you expect to get the user's perspective other
than by talking to the user?

Four dots?

 

[Martin Gregorie]

I'm not sure I'd agree with that. Certainly, the severity of the event,
whatever it is, may be ASSESSED differently in the field than it was by
the developers.

Here's a practical example.

Quite a while ago I designed a music broadcast management system. As you
may guess, the system navigation was complex (identifying a part of a
serious music composition is non-trivial because most works don't have
names) and the users were bright (usually with musicology degrees) and it
was implemented on a mainframe with page-mode green screens.

Consequently an unexpected result might be a bug or simply finger trouble.
Debugging code was left in the production system and exposed to users via
a debug control page. If something unexpected happened that we couldn't
sort out on the phone, the user simply turned on debugging, did it again
and turned debugging off. We looked at the log, which now showed details
of user input, program tracing, DB accesses and what was displayed to the
user, and were able to either declare it a bug or talk through the
dialogue with the user and either explain what had happened to the users'
satisfaction or define a system change request.

This was a non-trivial system dealing with complex data: without this
user-controlled logging set-up we would have had much more difficult
problem resolution and much less happy users.

I should add that there were two potentially very complex UI areas
(abbreviating performer and composer names, abbreviating music works
names) in this system and that we'd isolated these in replaceable modules
and agreed with the users that, as nobody really knew what would work
best for them, that we'd implement the simplest solutions we thought
would meet their requirements and change them as needed. The initial
performer/composer matcher was fine. The music work matcher was rewritten
twice before it did the necessary.

We evidently did something right. The user population grew by 500% by
popular demand for access. The system lifetime was about twice what I
ever anticipated, only being killed off when its hardware became
unsupported.