On Thu, 19 Jul 2001, Mark Abbott wrote:
> [snip]
> These are specifically the sort of problems the new java.util.logging
> package in
> JDK 1.4 is addressing. I believe the philosophy there is to always leave the
> code in place, be liberal in writing tracing log calls and assume that
> integer comparisons
> to decide whether to execute a particular logging call are so cheap that
> there is essentially
> no performance penalty at runtime. I am not as familiar with log4j.
At least in this respect, the JSR047 API is similar in spirit to Log4J --
I'm not going to touch on the places where the philosphies differ! :-)
However, there are some subtleties that are kind of important here:
- The typical approach with the JSR47 API or with Log4J is to let the
logger decide whether to really output the message or not. So, you
would instrument your code with things like (conceptual, not real API):
logger.log("The object is " + myObject, Logger.DEBUG);
and let the logger configuration decide whether you care about debug
messages or not.
- However, there is a performance problem with leaving this code in --
you will be doing the string concatenation (and the method call)
whether or not you want debug messages printed! If you are liberal
about debug messages, especially inside frequently executed methods,
this can have adverse impacts on performance (and increased garbage
collection).
- Log4J (and I imagine JSR047 does too, but haven't looked) has a way
to ask the logger whether debug mode is enabled or not. But it's
pretty verbose, and a developer isn't going to want to think about
it when in the middle of diagnosing a problem. It also requires a
method call, so it's still more expensive than the "integer compare"
mechanism described below.
- As others have pointed out, you often want to enable/disable debug
messages on a module-by-module level. Therefore, if I were using
Pier's proposed method, I'd put the static final global in each
module independently.
- However, Pier's proposed approach doesn't deal with a need that I've
experienced regularly -- the need to turn on debugging messages
dynamically on an existing component, *without* recompiling it. This
is NOT simply aesthetics; either you can or you cannot change the level
of debugging output at runtime.
An example of this is the following scenario: I'm developing an app
in an environment that relies on webapp reloading when classes are
changed (sound familiar, Jon? :-), and the ability to save and restore
session attributes across the reload. I'm probably running a *binary*
distribution of Tomcat, not the source. If I have a problem with my
attributes being saved and restored, it is crucially important to be
able to just do this:
<Context path="..." ...>
<Manager debug="99"/>
</Context>
in my server.xml file and restart, so I can see the verbose debugging
info in the log files. Not everybody will have the ability (or the
inclination) to rebuild Tomcat from source to do this.
- My general approach has been to embed debugging output in an idiom
like this:
if (debug >= 2)
log("The object is " + myObject);
which has a small runtime cost (evaluating the conditional), but
avoids the most expensive computations (string concatenation, method
call, and subsequent garbage collection) in the usual case of debugging
being turned off.
- Ideally, the compiler would be able to optimize this code out if
debug were really set to zero. However, because it's not "final static"
(so that it can be changed at runtime), that wouldn't be legal.
Therefore, I've tended to comment out the debug stuff in the most
frequently executed parts of the code, to avoid even the minimal
runtime overhead of the integer comparison and jump. Commenting out
instead of removing is my habit, and lets me easily re-introduce the
debug stuff if I'm investigating a problem later.
- As you can see, there's a conflict between my primary goals (dynamically
turn debugging on and off, and zero runtime overhead). The compromise
I'm currently using seems to be a fair balance between the two, but I'm
certainly interested in how others deal with it.
On the general topic of using Log4J (or the JSR 47 API) inside Tomcat 4,
there is something of an "impedance mismatch" between the Tomcat approach
to hierarchical loggers and the logger approach to handling multiple log
output streams. Ceki has posted some thoughts about how this might be
done (see the TOMCAT-DEV archives). Maybe, now that we're almost done
with beta 6 (to be released tonight), we can start thinking about it some
more.
>
> Cheers - Mark
Craig
