geronimo-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Jeremy Boynes" <jer...@coredevelopers.net>
Subject RE: Logging code and Garbage Collection
Date Tue, 12 Aug 2003 23:32:10 GMT
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