avalon-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Stefano Mazzocchi <stef...@apache.org>
Subject Re: Final Release of LogKit?
Date Thu, 25 Oct 2001 20:29:38 GMT
Carsten Ziegeler wrote:
> Hi,
> are there any plans for a final release of the LogKit?
> (I'm asking this, because of the upcoming release
> candidate of Cocoon 2).

Thanks for bringing this up, Carsten.

I was going thru the Cocoon code in order to identify possible
bottlenecks and patch it to make it faster and I think that logging is
responsible for something like 20% to 30% of the entire operation time.

Here is why.

Java uses the C syntax.

Everyone knows that C and strings don't match that much, but Java
created a bunch of syntax to make it easier to deal with strings.
Unfortunately, this hides some of the magic behind the programmer
because very few crazy people (yes, me being one of them) use javap to
disassemble java bytecode and see what the compiler does.

So, when you do something like

 String message = "Today is " + (new Date()).toString();

You are actually doing

 final static String today_is = "Today is ";
 StringBuffer buffer = new StringBuffer();
 String date = (new Date()).toString();
 String message = buffer.toString();

where those simple toString() methods perform String creation which is
one of the heaviest calls in almost all JVM implementations (even if
this is not necessarely slow by design) because each Char must be
checked and converted with the current local remapping table.

I hear you saying: so?

Look at this:

 getLogger().debug("I've been called " + times + " times!");

which is compiled exactly like

 final static String str1 = "I've been called ";
 final static String str2 = " times!";

 StringBuffer buffer = new StringBuffer();
 buffer.append((new Integer(times)).toString());

So, assuming the debug channel is turned off, this call (apparently very
efficient) creates:

 one StringBuffer object
 two String objects 
for nothing!

Cocoon2 is able to generate as much as 100K of logs for a single
request!!! and this is very likely to be turned off at processing time.

There are two solutions:

1) compile-time

    public final static boolean DEBUG = false;

    if (DEBUG) getLogger().debug(...);

where almost all java compiler are able to optimize the code by entirely
removing the line since there the final behavior of the variable make it
possible to know the future of this call (never called, that is).

2) run-time

    Logger logger = getLogger();
    if (logger.debugOn()) logger.debug(...);

which is, admittedly, makes the code less readable but, hey, it's much
better than loosing 30% performance for having placed debug logging code
(now disabled) for nothing.

IMO, the Avalon LogKit should force (or at least *highly* incouradge)
people to use this approach.

FYI, by patching JServ with the compile-time solution a couple of years
ago, I was able to increase its performance by 15% and after removing
all String object generation another 15%, all without having to rewrite
anything but carefully programming knowing what was going on behind my
shoulder by the java compiler.


Stefano Mazzocchi      One must still have chaos in oneself to be
                          able to give birth to a dancing star.
<stefano@apache.org>                             Friedrich Nietzsche

To unsubscribe, e-mail: avalon-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: avalon-dev-help@jakarta.apache.org

View raw message