You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@avalon.apache.org by Carsten Ziegeler <cz...@sundn.de> on 2001/10/25 08:31:09 UTC
Final Release of LogKit?
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,
Carsten
---------------------------------------------------------------------
To unsubscribe, e-mail: avalon-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: avalon-dev-help@jakarta.apache.org
Re: Final Release of LogKit?
Posted by Peter Donald <do...@apache.org>.
On Thu, 25 Oct 2001 16:31, Carsten Ziegeler wrote:
> are there any plans for a final release of the LogKit?
> (I'm asking this, because of the upcoming release
> candidate of Cocoon 2).
Should be good to go.
--
Cheers,
Pete
---------------------------------------------------
"Marriage, Friends, Religon -- these are the demons
you must slay in order to suceed in business.."
-- Mr. Burns, The Simpsons
---------------------------------------------------
---------------------------------------------------------------------
To unsubscribe, e-mail: avalon-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: avalon-dev-help@jakarta.apache.org
Re: Final Release of LogKit?
Posted by Berin Loritsch <bl...@apache.org>.
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).
I am +1
Peter, is there anything on your plate with this one?
---------------------------------------------------------------------
To unsubscribe, e-mail: avalon-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: avalon-dev-help@jakarta.apache.org
Re: Final Release of LogKit?
Posted by Stefano Mazzocchi <st...@apache.org>.
Berin Loritsch wrote:
> OK, how do you get javap to output the code? The best I've ever been
> able to acomplish is the signatures (no actual code).
javap -c [classname]
--
Stefano Mazzocchi One must still have chaos in oneself to be
able to give birth to a dancing star.
<st...@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
Re: Final Release of LogKit?
Posted by Berin Loritsch <bl...@apache.org>.
Stefano Mazzocchi wrote:
>
> 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.
OK, how do you get javap to output the code? The best I've ever been
able to acomplish is the signatures (no actual code).
>
> 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();
> buffer.append(today_is);
> String date = (new Date()).toString();
> buffer.append(date);
> 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(str1);
> buffer.append((new Integer(times)).toString());
> buffer.append(str2);
> getLogger().debug(buffer.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.
>
> Thanks.
>
> --
> Stefano Mazzocchi One must still have chaos in oneself to be
> able to give birth to a dancing star.
> <st...@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
---------------------------------------------------------------------
To unsubscribe, e-mail: avalon-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: avalon-dev-help@jakarta.apache.org
Re: Final Release of LogKit?
Posted by Berin Loritsch <bl...@apache.org>.
Stefano Mazzocchi wrote:
>
> 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();
> buffer.append(today_is);
> String date = (new Date()).toString();
> buffer.append(date);
> 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(str1);
> buffer.append((new Integer(times)).toString());
> buffer.append(str2);
> getLogger().debug(buffer.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(...);
This is not only possible, but done in many places in Cocoon already. We
should do it everywhere.
In the Excalibur ComponentManager, it is also present.
the check is
if (logger.isDebugEnabled()) logger.debug(...);
if (logger.isInfoEnabled()) logger.info(...);
and so on.
>
> 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.
>
> Thanks.
>
> --
> Stefano Mazzocchi One must still have chaos in oneself to be
> able to give birth to a dancing star.
> <st...@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
---------------------------------------------------------------------
To unsubscribe, e-mail: avalon-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: avalon-dev-help@jakarta.apache.org
Re: Final Release of LogKit?
Posted by Peter Donald <do...@apache.org>.
On Mon, 29 Oct 2001 22:34, Stefano Mazzocchi wrote:
> > > Ah, as a side note: why are you guys always suggesting doing
> > > getLogger()? couldn't we make the logger variable of AbstractLoggable
> > > protected so that extending classes already have access to it and avoid
> > > making method calls to retrieve it? it's both easier and faster, but
> > > maybe you guys thought of something I'm forgetting, thus my questions.
> >
> > It is final so it will be inlined. Basically it is to avoid choosing the
> > variable name between m_logger and logger. Some people hate m_ ;)
>
> Ok, good enough.
>
> Please, if possible, make this evident in the documentation or people
> will percieve it as a speed problem.
okay - added a bit more of a blurb.
--
Cheers,
Pete
*--------------------------------------------------*
| Wise men don't need advice. Fools don't take it. |
| -Benjamin Franklin |
*--------------------------------------------------*
--
To unsubscribe, e-mail: <ma...@jakarta.apache.org>
For additional commands, e-mail: <ma...@jakarta.apache.org>
Re: Final Release of LogKit?
Posted by Stefano Mazzocchi <st...@apache.org>.
Peter Donald wrote:
>
> On Sun, 28 Oct 2001 21:35, Stefano Mazzocchi wrote:
> > > It is much easier to just go
> > >
> > > getLogger().debug( .... )
> > >
> > > Far more user/developer friendly.
> >
> > Totally.
> >
> > Ah, as a side note: why are you guys always suggesting doing
> > getLogger()? couldn't we make the logger variable of AbstractLoggable
> > protected so that extending classes already have access to it and avoid
> > making method calls to retrieve it? it's both easier and faster, but
> > maybe you guys thought of something I'm forgetting, thus my questions.
>
> It is final so it will be inlined. Basically it is to avoid choosing the
> variable name between m_logger and logger. Some people hate m_ ;)
Ok, good enough.
Please, if possible, make this evident in the documentation or people
will percieve it as a speed problem.
--
Stefano Mazzocchi One must still have chaos in oneself to be
able to give birth to a dancing star.
<st...@apache.org> Friedrich Nietzsche
--------------------------------------------------------------------
--
To unsubscribe, e-mail: <ma...@jakarta.apache.org>
For additional commands, e-mail: <ma...@jakarta.apache.org>
Re: Final Release of LogKit?
Posted by Peter Donald <do...@apache.org>.
On Sun, 28 Oct 2001 21:35, Stefano Mazzocchi wrote:
> > It is much easier to just go
> >
> > getLogger().debug( .... )
> >
> > Far more user/developer friendly.
>
> Totally.
>
> Ah, as a side note: why are you guys always suggesting doing
> getLogger()? couldn't we make the logger variable of AbstractLoggable
> protected so that extending classes already have access to it and avoid
> making method calls to retrieve it? it's both easier and faster, but
> maybe you guys thought of something I'm forgetting, thus my questions.
It is final so it will be inlined. Basically it is to avoid choosing the
variable name between m_logger and logger. Some people hate m_ ;)
--
Cheers,
Pete
*-----------------------------------------------------*
* "Faced with the choice between changing one's mind, *
* and proving that there is no need to do so - almost *
* everyone gets busy on the proof." *
* - John Kenneth Galbraith *
*-----------------------------------------------------*
--
To unsubscribe, e-mail: <ma...@jakarta.apache.org>
For additional commands, e-mail: <ma...@jakarta.apache.org>
Re: Final Release of LogKit?
Posted by Stefano Mazzocchi <st...@apache.org>.
Peter Donald wrote:
>
> On Sat, 27 Oct 2001 23:48, Stefano Mazzocchi wrote:
> > > > IMO, the Avalon LogKit should force (or at least *highly* incouradge)
> > > > people to use this approach.
> > >
> > > (1) is useful in the 1.2 JVMs because they don't optimize aswell as 1.3+.
> > > (2) will still cause 5-8 operations/comparisons before opting out in
> > > jdk1.2 but in later JVMs this will be optimized down to one comparison
> > > and a jump.
> > >
> > > I am not sure how it can be "forced" other than via recomendation ;)
> >
> > Good point.
> >
> > A possible solution is to require the logging channel instance to be
> > obtained only after checking if available... we can use some polymorphic
> > code like
> >
> > LogChannel debug = (LogChannel) getLogger().debug();
> > if (debug != null) debug.log(...);
> >
> > which is sort of inverted over the normal use but rightly forces the
> > logging code to obtain a reference to the log channel *before* doing
> > anything (pain NPE all over the place!).
> >
> > Not sure I like this much, but it's a way to do it.
> >
> > What do you think?
>
> Too painful to use.
Yes, I share your perception.
> It is much easier to just go
>
> getLogger().debug( .... )
>
> Far more user/developer friendly.
Totally.
Ah, as a side note: why are you guys always suggesting doing
getLogger()? couldn't we make the logger variable of AbstractLoggable
protected so that extending classes already have access to it and avoid
making method calls to retrieve it? it's both easier and faster, but
maybe you guys thought of something I'm forgetting, thus my questions.
> In 80% of cases performance is a non-issue
> and thus the painful API would drive people away from using it. For those 20%
> of cases where performance is still an issue I cant see much difference in
> above and following. Actually I would still say the following is better ;)
>
> if( getLogger().isDebugEnabled() ) getLogger().debug(...);
Oh, I agree.
I was just proposing a way of forcing people, but you're right:
suggesting, in this case, is easier. One thing only: make sure the
logkit documentation lists best practices along with their reasons.
--
Stefano Mazzocchi One must still have chaos in oneself to be
able to give birth to a dancing star.
<st...@apache.org> Friedrich Nietzsche
--------------------------------------------------------------------
--
To unsubscribe, e-mail: <ma...@jakarta.apache.org>
For additional commands, e-mail: <ma...@jakarta.apache.org>
Re: Final Release of LogKit?
Posted by Peter Donald <do...@apache.org>.
On Sat, 27 Oct 2001 23:48, Stefano Mazzocchi wrote:
> > > IMO, the Avalon LogKit should force (or at least *highly* incouradge)
> > > people to use this approach.
> >
> > (1) is useful in the 1.2 JVMs because they don't optimize aswell as 1.3+.
> > (2) will still cause 5-8 operations/comparisons before opting out in
> > jdk1.2 but in later JVMs this will be optimized down to one comparison
> > and a jump.
> >
> > I am not sure how it can be "forced" other than via recomendation ;)
>
> Good point.
>
> A possible solution is to require the logging channel instance to be
> obtained only after checking if available... we can use some polymorphic
> code like
>
> LogChannel debug = (LogChannel) getLogger().debug();
> if (debug != null) debug.log(...);
>
> which is sort of inverted over the normal use but rightly forces the
> logging code to obtain a reference to the log channel *before* doing
> anything (pain NPE all over the place!).
>
> Not sure I like this much, but it's a way to do it.
>
> What do you think?
Too painful to use. It is much easier to just go
getLogger().debug( .... )
Far more user/developer friendly. In 80% of cases performance is a non-issue
and thus the painful API would drive people away from using it. For those 20%
of cases where performance is still an issue I cant see much difference in
above and following. Actually I would still say the following is better ;)
if( getLogger().isDebugEnabled() ) getLogger().debug(...);
--
Cheers,
Pete
-------------------------------------------------------
"I would like to take you seriously but to do so would
affront your intelligence" -William F. Buckley, JR
-------------------------------------------------------
--
To unsubscribe, e-mail: <ma...@jakarta.apache.org>
For additional commands, e-mail: <ma...@jakarta.apache.org>
Re: Final Release of LogKit?
Posted by Stefano Mazzocchi <st...@apache.org>.
Peter Donald wrote:
>
> On Fri, 26 Oct 2001 06:29, Stefano Mazzocchi wrote:
> > 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.
>
> (1) is useful in the 1.2 JVMs because they don't optimize aswell as 1.3+. (2)
> will still cause 5-8 operations/comparisons before opting out in jdk1.2 but
> in later JVMs this will be optimized down to one comparison and a jump.
>
> I am not sure how it can be "forced" other than via recomendation ;)
Good point.
A possible solution is to require the logging channel instance to be
obtained only after checking if available... we can use some polymorphic
code like
LogChannel debug = (LogChannel) getLogger().debug();
if (debug != null) debug.log(...);
which is sort of inverted over the normal use but rightly forces the
logging code to obtain a reference to the log channel *before* doing
anything (pain NPE all over the place!).
Not sure I like this much, but it's a way to do it.
What do you think?
--
Stefano Mazzocchi One must still have chaos in oneself to be
able to give birth to a dancing star.
<st...@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
Re: Final Release of LogKit?
Posted by Peter Donald <do...@apache.org>.
On Fri, 26 Oct 2001 06:29, Stefano Mazzocchi wrote:
> 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.
(1) is useful in the 1.2 JVMs because they don't optimize aswell as 1.3+. (2)
will still cause 5-8 operations/comparisons before opting out in jdk1.2 but
in later JVMs this will be optimized down to one comparison and a jump.
I am not sure how it can be "forced" other than via recomendation ;)
--
Cheers,
Pete
*------------------------------------------------------*
| Despite your efforts to be a romantic hero, you will |
| gradually evolve into a postmodern plot device. |
*------------------------------------------------------*
---------------------------------------------------------------------
To unsubscribe, e-mail: avalon-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: avalon-dev-help@jakarta.apache.org
RE: Final Release of LogKit?
Posted by Carsten Ziegeler <cz...@sundn.de>.
Stefano Mazzocchi wrote:
>
> 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();
> buffer.append(today_is);
> String date = (new Date()).toString();
> buffer.append(date);
> 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(str1);
> buffer.append((new Integer(times)).toString());
> buffer.append(str2);
> getLogger().debug(buffer.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.
>
Thanks Stefano,
I think I tried twice to convince the Cocooners to use this approach
(run-time),
but as you can see without any luck. So perhaps this time...
Carsten
> 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.
>
> Thanks.
>
> --
> Stefano Mazzocchi One must still have chaos in oneself to be
> able to give birth to a dancing star.
> <st...@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
>
---------------------------------------------------------------------
To unsubscribe, e-mail: avalon-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: avalon-dev-help@jakarta.apache.org
Re: Final Release of LogKit?
Posted by Stefano Mazzocchi <st...@apache.org>.
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();
buffer.append(today_is);
String date = (new Date()).toString();
buffer.append(date);
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(str1);
buffer.append((new Integer(times)).toString());
buffer.append(str2);
getLogger().debug(buffer.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.
Thanks.
--
Stefano Mazzocchi One must still have chaos in oneself to be
able to give birth to a dancing star.
<st...@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