RE: [TC4.0] Disabling debug output...
There's work done to remove code from Java class files at load time to support the new assert feature in JDK1.4. IIRC the class loader is doing most if not all of the work. So it may be possible to make it work in earlier JDKs. Could something similiar be done for logging? Jin Yu -Original Message- From: Craig R. McClanahan [mailto:[EMAIL PROTECTED]] Sent: Thursday, July 19, 2001 7:09 PM To: [EMAIL PROTECTED] Subject: Re: [TC4.0] Disabling debug output... On Thu, 19 Jul 2001, Jonathan Reichhold wrote: This hack definitely works. As long as you're willing to pay the overhead for the method call, it's essentially equivalent to asking Log4J whether or not debugging output is enabled, which does something similar (but asks the instantiated logger object, instead of being a static method). I'm not sure if Log4j has an accesible boolean like this (maybe it does, haven't used it yet), It's accessible, but via a method call. That's still a *lot* cheaper than doing useless string concatenations, but not quite as cheap as an integer comparison. I don't have the Log4J APIs available right at the moment, but there's a call on the logger object that can be used to check for enabled levels (or at least for debug). Craig McClanahan Enterprise Channel Management Software for Manufacturers Visit us at http://www.ultryx.com
Re: [TC4.0] Disabling debug output...
On Wed, 18 Jul 2001, Justin Erenkrantz wrote: On Thu, Jul 19, 2001 at 12:16:27AM +0100, Pier P. Fumagalli wrote: Checking out the source code, I see a lot of // (commented out lines) when debug() is supposed to be called... Can't we have a global constant boolean called DEBUG and replace the // with if (DEBUG), so that we can simply compile in and out the debugging information without touching the sources? Check out org.apache.catalina.connector.warp.Constants and WarpLogger... Old trick we used in JServ. :) I *believe* most Java compilers do not have constant conditional optimizations (they certainly could, but I don't think they did last time I checked). Without that optimization, you must check that value each time you execute the statement. That might hurt. -- justin In trivial experiments a long while back, I seem to recall that this trick worked if your constant was static final. But I haven't looked lately. There are also some cases where you want to be able to set the debug level at runtime, without having to recompile. In such cases, I typically am real liberal about debug statements when first creating a module, and then comment them out (versus removing them) in high-frequency-of-use portions of the code. That way, you've got ready-made debug code to uncomment if you run into problems later. Craig
Re: [TC4.0] Disabling debug output...
Craig R. McClanahan at [EMAIL PROTECTED] wrote: In trivial experiments a long while back, I seem to recall that this trick worked if your constant was static final. But I haven't looked lately. Yep... Setting a public static final boolean DEBUG = true/false; will behave like an ifdef in C for something like: If(DEBUG) logger.debug(...); If DEBUG is set to true, logger.debug() will be compiled in, otherwise it'll be left out. There are also some cases where you want to be able to set the debug level at runtime, without having to recompile. In such cases, I typically am real liberal about debug statements when first creating a module, and then comment them out (versus removing them) in high-frequency-of-use portions of the code. That way, you've got ready-made debug code to uncomment if you run into problems later. I'm not arguing about le debug level, but, instead of commenting out pieces of code (and then, when you want to do a debug build, you have to remove all comments) it would be nicer to set a public static final boolean, and instead of using comments, using the if boolean. Aesthetics, but I had to do that while checking the WARP connector to behave like HTTP, and the source was full of comments. Using the static final boolean I would have had to change just one line :) As I said, it's just aesthetics... Pier
Re: [TC4.0] Disabling debug output...
I believe the Java Language Spec makes specific requirements on the order of evaluation of static finals to facilitate this kind of usage. In the past I have gone so far as to compile test programs and disassemble the byte code and on every JVM I have ever tried, code wrapped in if statements that evaluate a static final boolean doesn't even generate byte code for the contents of the block if the boolean is false. So there is no performance or size penalty. The real problem with this sort of thing is more subtle. How do you control the value of the boolean? Should there be a single public static final in a class that is referred to everywhere? More likely one wants to turn on and off debugging in a single class, or package, or globally, depending on what is being tested. Having to do search and replace on scattered variables is annoying at best. How is the make system coerced into doing debug builds vs production builds in a simple manner, in the absence of a preprocessor? 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. Cheers - Mark At 08:56 AM 7/19/2001, Craig R. McClanahan wrote: On Wed, 18 Jul 2001, Justin Erenkrantz wrote: On Thu, Jul 19, 2001 at 12:16:27AM +0100, Pier P. Fumagalli wrote: Checking out the source code, I see a lot of // (commented out lines) when debug() is supposed to be called... Can't we have a global constant boolean called DEBUG and replace the // with if (DEBUG), so that we can simply compile in and out the debugging information without touching the sources? Check out org.apache.catalina.connector.warp.Constants and WarpLogger... Old trick we used in JServ. :) I *believe* most Java compilers do not have constant conditional optimizations (they certainly could, but I don't think they did last time I checked). Without that optimization, you must check that value each time you execute the statement. That might hurt. -- justin In trivial experiments a long while back, I seem to recall that this trick worked if your constant was static final. But I haven't looked lately. There are also some cases where you want to be able to set the debug level at runtime, without having to recompile. In such cases, I typically am real liberal about debug statements when first creating a module, and then comment them out (versus removing them) in high-frequency-of-use portions of the code. That way, you've got ready-made debug code to uncomment if you run into problems later. Craig
Re: [TC4.0] Disabling debug output...
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
Re: [TC4.0] Disabling debug output...
Craig R. McClanahan at [EMAIL PROTECTED] wrote: - 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. You didn't get it Craig... I'm simply proposing to use the if (DEBUG) approach _instead_ of commenting out logs in the source file... Go and look at HttpConnector.java... There are TONS of // (comments) that could be replaced with an if (DEBUG). If you remove the comments, you too have to recompile the sources... Pier
Re: [TC4.0] Disabling debug output...
Actually I've got a thought on how to add in debug messages without recompiling. For
a horrible hack say I've got a java class
like:
//Constants.java
public class Constants{
public static boolean isDebug(){return true;}
}
And in my main code I call:
if(Constants.isDebug()) log(someNastyFunction());
Now I could keep to versions of a class file generated from Constants.java (one which
returns true, one with returns false)
Replacing the class file Constants.class based upon my needs would effectively turn
debugging on/off. There is an overhead of this
approach for the lookup of the boolean, but it avoids the need to recompile to turn on
debugging. It isn't as nice as having a
debug flag passed in, but it would be a quick hack for most classes. It could even be
used to debug code in production by
replacing the class file and restarting. I prefer flags/config files to turn stuff
like this on/off, but it is a relatively quick
hack...
Jonathan
- Original Message -
From: Pier P. Fumagalli [EMAIL PROTECTED]
To: [EMAIL PROTECTED]
Sent: Thursday, July 19, 2001 1:24 PM
Subject: Re: [TC4.0] Disabling debug output...
Craig R. McClanahan at [EMAIL PROTECTED] wrote:
- 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.
You didn't get it Craig... I'm simply proposing to use the if (DEBUG)
approach _instead_ of commenting out logs in the source file...
Go and look at HttpConnector.java... There are TONS of // (comments) that
could be replaced with an if (DEBUG).
If you remove the comments, you too have to recompile the sources...
Pier
Re: [TC4.0] Disabling debug output...
On Thu, 19 Jul 2001, Jonathan Reichhold wrote:
Actually I've got a thought on how to add in debug messages without recompiling.
For a horrible hack say I've got a java class
like:
//Constants.java
public class Constants{
public static boolean isDebug(){return true;}
}
And in my main code I call:
if(Constants.isDebug()) log(someNastyFunction());
Now I could keep to versions of a class file generated from
Constants.java (one which returns true, one with returns false)
Replacing the class file Constants.class based upon my needs would
effectively turn debugging on/off. There is an overhead of this
approach for the lookup of the boolean, but it avoids the need to
recompile to turn on debugging. It isn't as nice as having a debug
flag passed in, but it would be a quick hack for most classes. It
could even be used to debug code in production by replacing the
class file and restarting. I prefer flags/config files to turn stuff
like this on/off, but it is a relatively quick hack...
This hack definitely works. As long as you're willing to pay the overhead
for the method call, it's essentially equivalent to asking Log4J whether
or not debugging output is enabled, which does something similar (but asks
the instantiated logger object, instead of being a static method).
Jonathan
Craig
- Original Message -
From: Pier P. Fumagalli [EMAIL PROTECTED]
To: [EMAIL PROTECTED]
Sent: Thursday, July 19, 2001 1:24 PM
Subject: Re: [TC4.0] Disabling debug output...
Craig R. McClanahan at [EMAIL PROTECTED] wrote:
- 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.
You didn't get it Craig... I'm simply proposing to use the if (DEBUG)
approach _instead_ of commenting out logs in the source file...
Go and look at HttpConnector.java... There are TONS of // (comments) that
could be replaced with an if (DEBUG).
If you remove the comments, you too have to recompile the sources...
Pier
Re: [TC4.0] Disabling debug output...
This hack definitely works. As long as you're willing to pay the overhead for the method call, it's essentially equivalent to asking Log4J whether or not debugging output is enabled, which does something similar (but asks the instantiated logger object, instead of being a static method). I'm not sure if Log4j has an accesible boolean like this (maybe it does, haven't used it yet), and if it was accessible it would reduce the gc load at the expense of some readibility of the source. The boolean check is relatively efficient in comparison to the function calls typically used in log messages (usually concat a string with some computed value after unkown work). I've run into problems with gc before and I tend to limit creation of extra objects. Ever run most log packages under a profiler and seen how many strings are created/destroyed on a regular basis? The code log(my message that I think is import + myVar.computeValue()); does unknown for myVar.computeValue() and then there is the creation of a StringBuffer, the concat, and the toString on the StringBuffer. All this for a line that may not be used except in high debug levels. Try doing that in a critical peice of code and watch performance go to hell quickly. On time critical code this gc time hurts. Don't even start me talking about fun in the gc with largs Maps. Can we say 90 second gc pauses every 2 minutes? Does anyone know if Log4j has a boolean method to check whether debugging is on/off? Jonathan
Re: [TC4.0] Disabling debug output...
On Thu, 19 Jul 2001, Jonathan Reichhold wrote: This hack definitely works. As long as you're willing to pay the overhead for the method call, it's essentially equivalent to asking Log4J whether or not debugging output is enabled, which does something similar (but asks the instantiated logger object, instead of being a static method). I'm not sure if Log4j has an accesible boolean like this (maybe it does, haven't used it yet), It's accessible, but via a method call. That's still a *lot* cheaper than doing useless string concatenations, but not quite as cheap as an integer comparison. I don't have the Log4J APIs available right at the moment, but there's a call on the logger object that can be used to check for enabled levels (or at least for debug). Craig McClanahan
Re: [TC4.0] Disabling debug output...
Craig wrote:
- 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).
Often the toString() are much worse than the concatenations. After we realized
what a HUGE impact this had on performance, we added a bunch of overloadings
so that you could convert the above to the equivalent of:
logger.log(Logger.DEBUG, The object is {0}, myObject);
where the formatting is only done once it's known that the category is enabled
(we used named categories instead of levels, but that's another discussion). I just
went and looked at log4j and java.util.logging and it looks like both would require
going through a wrapper class to get this feature.
The number of overloadings is a bit of a pain for the implementer once you
consider that you would often want to log boolean, int, and in some applications
float parameters, but not for the caller.
Louis Tribble
Re: [TC4.0] Disabling debug output...
On Thu, Jul 19, 2001 at 01:43:32PM -0700, Jonathan Reichhold wrote:
Actually I've got a thought on how to add in debug messages without recompiling.
For a horrible hack say I've got a java class
like:
//Constants.java
public class Constants{
public static boolean isDebug(){return true;}
}
And in my main code I call:
if(Constants.isDebug()) log(someNastyFunction());
But why don't you have two Constants.java of this type:
public class Constants {
publict static final boolean DEBUG = true; // or false
}
and:
if( Constants.DEBUG ) {
log( ... );
}
incze
[TC4.0] Disabling debug output...
Checking out the source code, I see a lot of // (commented out lines) when debug() is supposed to be called... Can't we have a global constant boolean called DEBUG and replace the // with if (DEBUG), so that we can simply compile in and out the debugging information without touching the sources? Check out org.apache.catalina.connector.warp.Constants and WarpLogger... Old trick we used in JServ. :) Pier
RE: [TC4.0] Disabling debug output...
Check out org.apache.catalina.connector.warp.Constants and WarpLogger... Old trick we used in JServ. :) Is Log4j not a good idea? I've used it for a couple of months, seems pretty cool =) Too much for TC? - r
Re: [TC4.0] Disabling debug output...
Rob S. at [EMAIL PROTECTED] wrote: Check out org.apache.catalina.connector.warp.Constants and WarpLogger... Old trick we used in JServ. :) Is Log4j not a good idea? I've used it for a couple of months, seems pretty cool =) Too much for TC? I believe the integration with Log4J is planned for TC4.1, as it involves an extensive rewrite of the Tomcat code... I wouldn't want to screw up it all _now_ :) :) :) Pier
