geronimo-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Jason Dillon <ja...@coredevelopers.net>
Subject Re: Logging code and Garbage Collection
Date Wed, 13 Aug 2003 07:04:29 GMT
I would depend on how it was cached.  If you mean if a method traces or 
debugs more than once, it should definitely create a local variable to 
cache if the level is enabled, but if you mean for a larger scoped 
cache, this could make it hard to debug a running server, as you can 
always tweak the active levels at runtime.

--jason


On Wednesday, August 13, 2003, at 06:32  AM, Jeremy Boynes wrote:

> It is still worth it - I was being lazy here (fixed now) :-)
>
> I would recommend caching the log level somewhere rather than calling
> isDebugEnabled() for every request - I've seen some profiles where the 
> time
> in isTraceEnabled() was significant.
>
> --
> Jeremy
>
>
> -----Original Message-----
> From: Adam Jenkins [mailto:ajenkins@infocomp.com]
> Sent: Tuesday, August 12, 2003 4:05 PM
> To: 'geronimo-dev@incubator.apache.org'
> Subject: RE: Logging code and Garbage Collection
>
>
> I understand the motivation for large scale stuff like that...but your
> thoughts on simple concats?
> e.g. log.debug("Here is some stuff that happened" + someStuff);
> Just out of interests, did your profiling pick up less or more time 
> spent in
> that than wrapping it in a debug?
>
> -----Original Message-----
> From: Mark Mahieu [mailto:mark@twistedbanana.demon.co.uk]
> Sent: Wednesday, 13 August 2003 9:02 AM
> To: geronimo-dev
> Subject: Logging code and Garbage Collection
>
>
> All,
> I know this is a tad early to comment on the code in CVS, but I've just
> noticed code like this (in
> org.apache.geronimo.deployment.scanner.DeploymentScanner)
> log.debug("Finished scan of " + url + ", " + result.size() + "
> deployment(s) found");
> Could everyone make sure that log statements are wrapped (eg.):
> if (log.isDebugEnabled()) {
>     log.debug("Finished scan of " + url + ", " + result.size() + "
> deployment(s) found");
> }
> The reason being that while profiling a J2EE application a while back 
> we
> found that well over 50% of the processors' time was spent executing 
> log
> statements just like the above - most of that with the VM messing 
> around
> creating StringBuffer objects and then garbage collecting them.  In the
> case above, this will happen regardless of the logging level in use 
> i.e.
> *even if* debug messages aren't actually being output.
> A couple of cavaeats:
> 1) The code above is only executed periodically, so it's not really a
> great example of a performance killer ;-)
> 2) Sun's 1.4.2 VM may be better at mitigating this problem than the one
> I was profiling (1.3.1). Still, not everyone will use Sun's VM.
> I know this sounds incredibly picky at this stage but I think it'd be 
> an
> idea to get into good habits now rather than later.  If others agree
> with the above, I'll add it to the coding standards in the Wiki.
> Mark
>


Mime
View raw message